search

ekutner / home-connect-hass

Alternative (and improved) Home Connect integration for Home Assistant
MIT License
511 stars 53 forks source link

Call to home_connect_alt.start_program with options no longer allowed? #281

Closed dennypage closed 8 months ago

dennypage commented 8 months ago

Between 0.7 and 1.0.0-b2, the following code has ceased working:

            - variables:
                venting_stage: >
                  {% if percentage == 25 %}
                    {{ 'Cooking.Hood.EnumType.Stage.FanStage01' }}
                  {% elif percentage == 50 %}
                    {{ 'Cooking.Hood.EnumType.Stage.FanStage02' }}
                  {% elif percentage == 75 %}
                    {{ 'Cooking.Hood.EnumType.Stage.FanStage03' }}
                  {% elif percentage == 100 %}
                    {{ 'Cooking.Hood.EnumType.Stage.FanStage04' }}
                  {% endif %}
            - if:
                condition: state
                entity_id: sensor.thermador_vcin48gws_xxxxxxxxxxxx_active_program
                state: 'Cooking.Common.Program.Hood.Venting'
              then:
                service: home_connect_alt.set_program_option
                data:
                  device_id: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
                  key: 'Cooking.Common.Option.Hood.VentingLevel'
                  value: "{{ venting_stage }}"
              else:
                service: home_connect_alt.start_program
                data:
                  device_id: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
                  program_key: 'Cooking.Common.Program.Hood.Venting'
                  options: [ { 'key': 'Cooking.Common.Option.Hood.VentingLevel', 'value': '{{ venting_stage }}' } ]

In particular, the call to start_program fails, with "Failed to call service fan/set_percentage. The specified program is not one of the available programs (not supported by the API). The call to set_program_option continues to function as expected.

ekutner commented 8 months ago

please follow the bug reporting instructions.

dennypage commented 8 months ago

Describe the bug

Calling home_connect_alt.start_program with options no longer functions in 1.0.0-b2

Version of the custom_component

1.0.0-b2

Configuration

home_connect_alt:
  client_id: REDACTED
  client_secret: REDACTED

Debug log

Here is the log from 1.0.0-b2:

The first exception is from a call to home_connect_alt.start_program with a program key of 'Cooking.Common.Program.Hood.DelayedShutOff'.

The second exception is from a call to home_connect_alt.start_program with a program key of 'Cooking.Common.Program.Hood.Venting' and an option key of 'Cooking.Common.Option.Hood.VentingLevel'.

2023-11-07 12:27:15.080 WARNING (MainThread) [home_connect_async.appliance] The selected program in not one of the available programs (not supported by the API)
2023-11-07 12:27:15.080 ERROR (MainThread) [homeassistant.helpers.script.range_hood_delayed_shutoff] Range Hood Delayed Shutoff: Error executing script. Error for call_service at pos 1: The specified program in not one of the available programs (not supported by the API)
2023-11-07 12:27:15.080 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [139731869920704] The specified program in not one of the available programs (not supported by the API)
Traceback (most recent call last):
  File "/config/custom_components/home_connect_alt/services.py", line 37, in async_start_program
    await appliance.async_start_program(program_key, options, validate)
  File "/usr/local/lib/python3.11/site-packages/home_connect_async/appliance.py", line 328, in async_start_program
    raise HomeConnectError("The specified program in not one of the available programs (not supported by the API)")
home_connect_async.common.HomeConnectError: ('The specified program in not one of the available programs (not supported by the API)', None, None, None, None)

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 230, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 2035, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2072, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 876, in entity_service_call
    response_data = await _handle_entity_call(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 948, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/template/switch.py", line 161, in async_turn_on
    await self.async_run_script(self._on_script, context=self._context)
  File "/usr/src/homeassistant/homeassistant/components/template/template_entity.py", line 554, in async_run_script
    await script.async_run(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1578, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 420, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 470, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 493, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 704, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 666, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2035, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2072, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/home_connect_alt/services.py", line 39, in async_start_program
    raise HomeAssistantError(ex.error_description if ex.error_description else ex.msg) from ex
homeassistant.exceptions.HomeAssistantError: The specified program in not one of the available programs (not supported by the API)
2023-11-07 12:27:30.434 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='KEEP-ALIVE', message='KEEP-ALIVE', data='', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:27:33.022 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='KEEP-ALIVE', message='KEEP-ALIVE', data='', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:27:48.740 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='KEEP-ALIVE', message='KEEP-ALIVE', data='', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:28:04.109 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active (try=1 count=22)

2023-11-07 12:28:04.841 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active (try=1 count=22) [404]
2023-11-07 12:28:04.841 DEBUG (MainThread) [home_connect_async.api] API call failed with code=404 error=SDK.Error.NoProgramActive
2023-11-07 12:28:04.841 DEBUG (MainThread) [home_connect_async.appliance] Failed to load active programs with error code=404 key=SDK.Error.NoProgramActive
2023-11-07 12:28:10.822 WARNING (MainThread) [home_connect_async.appliance] The selected program in not one of the available programs (not supported by the API)
2023-11-07 12:28:10.822 ERROR (MainThread) [homeassistant.helpers.script.range_hood_fan] Range Hood Fan: If at step 1: If at step 2: Error executing script. Error for call_service at pos 1: The specified program in not one of the available programs (not supported by the API)
2023-11-07 12:28:10.822 ERROR (MainThread) [homeassistant.helpers.script.range_hood_fan] Range Hood Fan: If at step 1: Error executing script. Error for if at pos 2: The specified program in not one of the available programs (not supported by the API)
2023-11-07 12:28:10.823 ERROR (MainThread) [homeassistant.helpers.script.range_hood_fan] Range Hood Fan: Error executing script. Error for if at pos 1: The specified program in not one of the available programs (not supported by the API)
2023-11-07 12:28:10.823 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [139731840197568] The specified program in not one of the available programs (not supported by the API)
Traceback (most recent call last):
  File "/config/custom_components/home_connect_alt/services.py", line 37, in async_start_program
    await appliance.async_start_program(program_key, options, validate)
  File "/usr/local/lib/python3.11/site-packages/home_connect_async/appliance.py", line 328, in async_start_program
    raise HomeConnectError("The specified program in not one of the available programs (not supported by the API)")
home_connect_async.common.HomeConnectError: ('The specified program in not one of the available programs (not supported by the API)', None, None, None, None)

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 230, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 2035, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2072, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 876, in entity_service_call
    response_data = await _handle_entity_call(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 948, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/template/fan.py", line 273, in async_set_percentage
    await self.async_run_script(
  File "/usr/src/homeassistant/homeassistant/components/template/template_entity.py", line 554, in async_run_script
    await script.async_run(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1578, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 420, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 470, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 493, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 957, in _async_if_step
    await self._async_run_script(if_data["if_else"])
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1069, in _async_run_script
    await self._async_run_long_action(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 666, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1578, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 420, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 470, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 493, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 957, in _async_if_step
    await self._async_run_script(if_data["if_else"])
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1069, in _async_run_script
    await self._async_run_long_action(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 666, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1578, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 420, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 470, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 493, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 704, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 666, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2035, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2072, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/home_connect_alt/services.py", line 39, in async_start_program
    raise HomeAssistantError(ex.error_description if ex.error_description else ex.msg) from ex
homeassistant.exceptions.HomeAssistantError: The specified program in not one of the available programs (not supported by the API)
2023-11-07 12:28:28.023 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='KEEP-ALIVE', message='KEEP-ALIVE', data='', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')

For comparison, here is the corresponding log from 0.7:

2023-11-07 12:45:19.283 DEBUG (MainThread) [home_connect_async.api] 
HTTP PUT /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active (try=1 count=14)
{
  "data": {
    "key": "Cooking.Common.Program.Hood.DelayedShutOff",
    "options": []
  }
}

2023-11-07 12:45:20.282 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Setting.PowerState","level":"hint","timestamp":1699389920,"uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/settings/BSH.Common.Setting.PowerState","value":"BSH.Common.EnumType.PowerState.On"},{"handling":"none","key":"BSH.Common.Root.ActiveProgram","level":"hint","timestamp":1699389920,"uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active","value":"Cooking.Common.Program.Hood.DelayedShutOff"},{"handling":"none","key":"BSH.Common.Option.Duration","level":"hint","timestamp":1699389920,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.Duration","value":300},{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","timestamp":1699389920,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ElapsedProgramTime","value":0},{"handling":"none","key":"Cooking.Common.Option.Hood.VentingLevel","level":"hint","timestamp":1699389920,"uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/Cooking.Common.Option.Hood.VentingLevel","value":"Cooking.Hood.EnumType.Stage.FanStage01"},{"handling":"none","key":"BSH.Common.Option.RemainingProgramTime","level":"hint","timestamp":1699389920,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.RemainingProgramTime","value":300},{"handling":"none","key":"BSH.Common.Option.ProgramProgress","level":"hint","timestamp":1699389920,"unit":"%","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ProgramProgress","value":0}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:20.282 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Setting.PowerState = BSH.Common.EnumType.PowerState.On
2023-11-07 12:45:20.283 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Root.ActiveProgram = Cooking.Common.Program.Hood.DelayedShutOff
2023-11-07 12:45:20.283 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.Duration = 300
2023-11-07 12:45:20.283 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ElapsedProgramTime = 0
2023-11-07 12:45:20.283 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: Cooking.Common.Option.Hood.VentingLevel = Cooking.Hood.EnumType.Stage.FanStage01
2023-11-07 12:45:20.284 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active (try=1 count=15)

2023-11-07 12:45:20.464 DEBUG (MainThread) [home_connect_async.api] HTTP PUT /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active (try=1 count=15) [204]
2023-11-07 12:45:20.954 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active (try=1 count=15) [200]
2023-11-07 12:45:20.956 DEBUG (MainThread) [home_connect_async.appliance] Loaded 5 Options for active/Cooking.Common.Program.Hood.DelayedShutOff
2023-11-07 12:45:20.956 DEBUG (MainThread) [home_connect_async.appliance] Loaded data for active Program
2023-11-07 12:45:20.956 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/available (try=1 count=16)

2023-11-07 12:45:21.144 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/available (try=1 count=16) [200]
2023-11-07 12:45:21.145 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/available/Cooking.Common.Program.Hood.Venting (try=1 count=17)

2023-11-07 12:45:21.333 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/available/Cooking.Common.Program.Hood.Venting (try=1 count=17) [200]
2023-11-07 12:45:21.333 DEBUG (MainThread) [home_connect_async.appliance] Loaded 1 Options for available/Cooking.Common.Program.Hood.Venting
2023-11-07 12:45:21.333 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/available/Cooking.Common.Program.Hood.Automatic (try=1 count=18)

2023-11-07 12:45:21.512 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/available/Cooking.Common.Program.Hood.Automatic (try=1 count=18) [200]
2023-11-07 12:45:21.512 DEBUG (MainThread) [home_connect_async.appliance] Loaded 0 Options for available/Cooking.Common.Program.Hood.Automatic
2023-11-07 12:45:21.512 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/available/Cooking.Common.Program.Hood.DelayedShutOff (try=1 count=19)

2023-11-07 12:45:21.696 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/available/Cooking.Common.Program.Hood.DelayedShutOff (try=1 count=19) [200]
2023-11-07 12:45:21.697 DEBUG (MainThread) [home_connect_async.appliance] Loaded 0 Options for available/Cooking.Common.Program.Hood.DelayedShutOff
2023-11-07 12:45:21.697 DEBUG (MainThread) [home_connect_async.appliance] Loaded 3 available Programs
2023-11-07 12:45:21.698 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/commands (try=1 count=20)

2023-11-07 12:45:21.885 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/commands (try=1 count=20) [200]
2023-11-07 12:45:21.886 DEBUG (MainThread) [home_connect_async.appliance] Loaded 1 Commands
2023-11-07 12:45:21.886 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: Events.PROGRAM_STARTED = Cooking.Common.Program.Hood.DelayedShutOff
2023-11-07 12:45:21.886 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.888 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.888 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.888 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: {'thermador_vcin48gws_68a40e1d7e4a_bsh_common_option_programprogress', 'thermador_vcin48gws_68a40e1d7e4a_bsh_common_option_elapsedprogramtime', 'thermador_vcin48gws_68a40e1d7e4a_active_program', 'thermador_vcin48gws_68a40e1d7e4a_bsh_common_option_remainingprogramtime', 'thermador_vcin48gws_68a40e1d7e4a_bsh_common_option_duration', 'thermador_vcin48gws_68a40e1d7e4a_cooking_common_option_hood_ventinglevel'}
2023-11-07 12:45:21.889 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.889 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.889 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: Events.DATA_CHANGED = None
2023-11-07 12:45:21.890 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.890 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.890 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.890 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.890 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.891 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:21.894 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.RemainingProgramTime = 300
2023-11-07 12:45:21.894 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ProgramProgress = 0
2023-11-07 12:45:21.894 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='STATUS', message='STATUS', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Status.OperationState","level":"hint","timestamp":1699389920,"uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/status/BSH.Common.Status.OperationState","value":"BSH.Common.EnumType.OperationState.Run"}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:21.894 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Status.OperationState = BSH.Common.EnumType.OperationState.Run
2023-11-07 12:45:21.895 DEBUG (MainThread) [custom_components.home_connect_alt] Published event to Home Assistant event bus: BSH.Common.Status.OperationState = BSH.Common.EnumType.OperationState.Run
2023-11-07 12:45:22.597 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","timestamp":1699389922,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ElapsedProgramTime","value":2},{"handling":"none","key":"BSH.Common.Option.RemainingProgramTime","level":"hint","timestamp":1699389922,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.RemainingProgramTime","value":297}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:22.597 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ElapsedProgramTime = 2
2023-11-07 12:45:22.598 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.RemainingProgramTime = 297
2023-11-07 12:45:23.275 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","timestamp":1699389923,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ElapsedProgramTime","value":3},{"handling":"none","key":"BSH.Common.Option.ProgramProgress","level":"hint","timestamp":1699389923,"unit":"%","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ProgramProgress","value":1}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:23.275 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ElapsedProgramTime = 3
2023-11-07 12:45:23.275 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ProgramProgress = 1
2023-11-07 12:45:26.281 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","timestamp":1699389926,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ElapsedProgramTime","value":6},{"handling":"none","key":"BSH.Common.Option.RemainingProgramTime","level":"hint","timestamp":1699389926,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.RemainingProgramTime","value":294},{"handling":"none","key":"BSH.Common.Option.ProgramProgress","level":"hint","timestamp":1699389926,"unit":"%","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ProgramProgress","value":2}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:26.281 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ElapsedProgramTime = 6
2023-11-07 12:45:26.281 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.RemainingProgramTime = 294
2023-11-07 12:45:26.282 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ProgramProgress = 2
2023-11-07 12:45:29.286 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","timestamp":1699389929,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ElapsedProgramTime","value":9},{"handling":"none","key":"BSH.Common.Option.RemainingProgramTime","level":"hint","timestamp":1699389929,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.RemainingProgramTime","value":291},{"handling":"none","key":"BSH.Common.Option.ProgramProgress","level":"hint","timestamp":1699389929,"unit":"%","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ProgramProgress","value":3}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:29.287 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ElapsedProgramTime = 9
2023-11-07 12:45:29.287 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.RemainingProgramTime = 291
2023-11-07 12:45:29.287 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ProgramProgress = 3
2023-11-07 12:45:32.299 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","timestamp":1699389932,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ElapsedProgramTime","value":12},{"handling":"none","key":"BSH.Common.Option.RemainingProgramTime","level":"hint","timestamp":1699389932,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.RemainingProgramTime","value":288},{"handling":"none","key":"BSH.Common.Option.ProgramProgress","level":"hint","timestamp":1699389932,"unit":"%","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ProgramProgress","value":4}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:32.299 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ElapsedProgramTime = 12
2023-11-07 12:45:32.300 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.RemainingProgramTime = 288
2023-11-07 12:45:32.300 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ProgramProgress = 4
2023-11-07 12:45:34.310 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='KEEP-ALIVE', message='KEEP-ALIVE', data='', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:35.305 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","timestamp":1699389935,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ElapsedProgramTime","value":15},{"handling":"none","key":"BSH.Common.Option.RemainingProgramTime","level":"hint","timestamp":1699389935,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.RemainingProgramTime","value":285},{"handling":"none","key":"BSH.Common.Option.ProgramProgress","level":"hint","timestamp":1699389935,"unit":"%","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ProgramProgress","value":5}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:35.305 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ElapsedProgramTime = 15
2023-11-07 12:45:35.305 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.RemainingProgramTime = 285
2023-11-07 12:45:35.306 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ProgramProgress = 5
2023-11-07 12:45:38.308 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","timestamp":1699389938,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ElapsedProgramTime","value":18},{"handling":"none","key":"BSH.Common.Option.RemainingProgramTime","level":"hint","timestamp":1699389938,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.RemainingProgramTime","value":282},{"handling":"none","key":"BSH.Common.Option.ProgramProgress","level":"hint","timestamp":1699389938,"unit":"%","uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active/options/BSH.Common.Option.ProgramProgress","value":6}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:38.308 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ElapsedProgramTime = 18
2023-11-07 12:45:38.309 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.RemainingProgramTime = 282
2023-11-07 12:45:38.309 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Option.ProgramProgress = 6
2023-11-07 12:45:40.174 DEBUG (MainThread) [home_connect_async.api] 
HTTP DELETE /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active (try=1 count=21)

2023-11-07 12:45:41.158 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Setting.PowerState","level":"hint","timestamp":1699389941,"uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/settings/BSH.Common.Setting.PowerState","value":"BSH.Common.EnumType.PowerState.Off"},{"handling":"none","key":"BSH.Common.Root.ActiveProgram","level":"hint","timestamp":1699389941,"uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active","value":null}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:41.158 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Setting.PowerState = BSH.Common.EnumType.PowerState.Off
2023-11-07 12:45:41.159 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/commands (try=1 count=22)

2023-11-07 12:45:41.334 DEBUG (MainThread) [home_connect_async.api] HTTP DELETE /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/programs/active (try=1 count=22) [204]
2023-11-07 12:45:41.837 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/commands (try=1 count=22) [200]
2023-11-07 12:45:41.837 DEBUG (MainThread) [home_connect_async.appliance] Loaded 1 Commands
2023-11-07 12:45:41.837 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: Events.PROGRAM_FINISHED = Cooking.Common.Program.Hood.DelayedShutOff
2023-11-07 12:45:41.838 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: Events.DATA_CHANGED = None
2023-11-07 12:45:41.838 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.838 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.839 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.839 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.839 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.839 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.840 DEBUG (MainThread) [custom_components.home_connect_alt.sensor] Updating sensor thermador_vcin48gws_68a40e1d7e4a_active_program => None
2023-11-07 12:45:41.844 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Root.ActiveProgram = None
2023-11-07 12:45:41.845 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='STATUS', message='STATUS', data='{"haId":"THERMADOR-VCIN48GWS-REDACTED","items":[{"handling":"none","key":"BSH.Common.Status.OperationState","level":"hint","timestamp":1699389941,"uri":"/api/homeappliances/THERMADOR-VCIN48GWS-REDACTED/status/BSH.Common.Status.OperationState","value":"BSH.Common.EnumType.OperationState.Inactive"}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-VCIN48GWS-REDACTED')
2023-11-07 12:45:41.845 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: Events.DATA_CHANGED = None
2023-11-07 12:45:41.845 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.845 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.845 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.846 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.846 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.846 DEBUG (MainThread) [custom_components.home_connect_alt.common] Registering new entities: set()
2023-11-07 12:45:41.846 DEBUG (MainThread) [custom_components.home_connect_alt.sensor] Updating sensor thermador_vcin48gws_68a40e1d7e4a_active_program => None
2023-11-07 12:45:41.849 DEBUG (MainThread) [home_connect_async.callback_registery] Broadcasting event: BSH.Common.Status.OperationState = BSH.Common.EnumType.OperationState.Inactive
2023-11-07 12:45:41.849 DEBUG (MainThread) [custom_components.home_connect_alt] Published event to Home Assistant event bus: BSH.Common.Status.OperationState = BSH.Common.EnumType.OperationState.Inactive
ekutner commented 8 months ago

I'm going to need more information. Please press the "Home Connect Debug Info" button right before every call the start_program service (or right before running the automation that makes this call, then upload the COMPLETE log file, not just an excerpt.

dennypage commented 8 months ago

Full log with multiple presses attached. 1.0.0-b2.full.log

Please let me know if you need a corresponding 0.7 log.

ekutner commented 8 months ago

Version 1.0.0-b3 should fix it

dennypage commented 8 months ago

Version 1.0.0-b3 should fix it

Confirmed. Thank you for your patience, and for the quick fix. Much appreciated.