thoukydides / homebridge-homeconnect

Home Connect home appliances plugin for Homebridge
https://www.thouky.co.uk
ISC License
142 stars 15 forks source link

Power state not always updated on disconnect (Bosch Washer WAV28G43/04) #72

Closed smhex closed 2 years ago

smhex commented 2 years ago

Description of Issue

Hello, first of all I like the plugin very much! Nevertheless I have some issues which I want to solve. The most obvious one is my washer being shown as ON in the Home App constantly. Even if I switch it off after finishing the program it stays ON. When I restart Homebridge the OFF state is detected (The appliance is offline) but the corresponding state in HomeKit stays ON. What can I do here? The HomeConnect app works fine (using Wifi or direct connection to the device). I have LaMetric clock which also displays the HomeConnect notifications of my appliances. All events are shown here (ON/OFF/remaining time etc.).

Plugin Version

0.23.4

Home Connect Appliance(s)

See log

HomeKit App(s)

Apple Home

Log File

[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Trockner] Bosch Dryer (E-Nr: WTX87E40/03)
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Waschmaschine] Bosch Washer (E-Nr: WAV28G43/04)
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Bosch Dishwasher (E-Nr: SMV8YCX01E/17)
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Waschmaschine] Cannot be switched off
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Can be switched off
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support Functional Light
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support a child lock
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support Ambient Light
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Trockner] The appliance is offline
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Trockner] GET status
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Waschmaschine] The appliance is offline
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Waschmaschine] GET status
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Door closed
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Active (Run)
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 0 seconds remaining
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Connected
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 1 hour 28 minutes remaining
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] 8 of 9 programs are currently unavailable
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Finished reading available program options
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Adding services for 0 programs
[2/5/2022, 3:49:13 PM] [homebridge-homeconnect] [Geschirrspüler] Removing services for 0 programs
[2/5/2022, 3:49:19 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 1 hour 26 minutes remaining
[2/5/2022, 3:50:18 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 1 hour 25 minutes remaining
[2/5/2022, 3:51:18 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 1 hour 24 minutes remaining
thoukydides commented 2 years ago

As far as the Home Connect API is concerned, Washer appliances are always-on. If you look at https://api-docs.home-connect.com/settings?#power-state you will see that the BSH.Common.Setting.PowerState setting can only be set to BSH.Common.EnumType.PowerState.On.

This is confirmed by the log you provided; the entry [Waschmaschine] Cannot be switched off indicates the API returned that BSH.Common.EnumType.PowerState.On is the only supported value for your appliance.

However, this plugin does attempt to indicate communication problems with the appliance by setting the HomeKit power Switch state to off. It does this if the event stream connection to the Home Connect servers is terminated and cannot be re-established within 3 seconds, or if a DISCONNECTED event is explicitly reported.

I do not have a Washer supporting Home Connect so cannot test that. However, if I unplug one of my appliances the DISCONNECTED event is reported after about 30 seconds, and that results in the HomeKit power Switch state being set to off. This is the corresponding log (with debug enabled):

[16:53:41] [HomeConnect] [Dishwasher] Event DISCONNECTED (0 items)
[16:53:41] [HomeConnect] [Dishwasher] Appliance lost connection to Home Connect servers
[16:53:41] [HomeConnect] [Dishwasher] connected=false (3 listeners)
[16:53:41] [HomeConnect] [Dishwasher] Disconnected

And for plugging the appliance in again, resulting in the HomeKit power Switch state being returned to on:

[16:54:07] [HomeConnect] [Dishwasher] Event CONNECTED (0 items)
[16:54:07] [HomeConnect] [Dishwasher] Appliance is now connected to Home Connect servers
[16:54:07] [HomeConnect] [Dishwasher] Connected, so reading appliance state...
[16:54:07] [HomeConnect] Home Connect request #1581: GET https://api.home-connect.com/api/homeappliances/SIEMENS-SN678D06TG-xxxxxxxxxxxx
[16:54:07] [HomeConnect] Home Connect request #1581: OK +191ms
[16:54:07] [HomeConnect] Home Connect request #1582: GET https://api.home-connect.com/api/homeappliances/SIEMENS-SN678D06TG-xxxxxxxxxxxx/status
[16:54:08] [HomeConnect] Home Connect request #1582: OK +899ms
[16:54:08] [HomeConnect] [Dishwasher] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Open (1 listeners)
[16:54:08] [HomeConnect] [Dishwasher] Door open
[16:54:08] [HomeConnect] [Dishwasher] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Ready (3 listeners)
[16:54:08] [HomeConnect] [Dishwasher] Inactive (Ready)
[16:54:08] [HomeConnect] [Dishwasher] BSH.Common.Status.RemoteControlActive=true (1 listeners)
[16:54:08] [HomeConnect] [Dishwasher] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[16:54:08] [HomeConnect] Home Connect request #1583: GET https://api.home-connect.com/api/homeappliances/SIEMENS-SN678D06TG-xxxxxxxxxxxx/settings
[16:54:08] [HomeConnect] [Dishwasher] Remote operation NOT enabled (remote control activated, remote start disallowed)
[16:54:08] [HomeConnect] Home Connect request #1583: OK +172ms
[16:54:08] [HomeConnect] [Dishwasher] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[16:54:08] [HomeConnect] [Dishwasher] On

Hence, that functionality appears to be working - or at least it is as far as I am able to test it.

Please can you provide a log, with debug enabled (using the -D switch on the homebridge command line), starting with the Washer switched on and then switching it off.

smhex commented 2 years ago

That's interesting. Looking at the API documentation you mentioned the behaviour also applies to dryers. Interestingly my dryer is not shown as always ON in HomeKit. However I will create the logs and provide them here.

smhex commented 2 years ago

Not a good day for testing 😢

[2/6/2022, 3:51:54 PM] [homebridge-homeconnect] Home Connect API error: Home Connect subsystem not available. Please try it again. [503]
smhex commented 2 years ago

The API is working again. Here is the log:

[2/6/2022, 6:27:29 PM] [homebridge-homeconnect] [Waschmaschine] Remote operation NOT enabled (remote start disallowed)
[2/6/2022, 6:27:29 PM] [homebridge-homeconnect] [Waschmaschine] Door open
[2/6/2022, 6:27:29 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/6/2022, 6:27:29 PM] [homebridge-homeconnect] [Waschmaschine] Inactive (Ready)
[2/6/2022, 6:27:29 PM] [homebridge-homeconnect] [Waschmaschine] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/6/2022, 6:27:29 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/6/2022, 6:27:29 PM] [homebridge-homeconnect] [Waschmaschine] Connected
[2/6/2022, 6:27:29 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/6/2022, 6:27:30 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/6/2022, 6:27:30 PM] [homebridge-homeconnect] [Waschmaschine] Finished reading available program options
[2/6/2022, 6:27:30 PM] [homebridge-homeconnect] [Waschmaschine] Cannot be switched off
[2/6/2022, 6:27:30 PM] [homebridge-homeconnect] [Waschmaschine] Adding services for 0 programs
[2/6/2022, 6:27:30 PM] [homebridge-homeconnect] [Waschmaschine] Removing services for 0 programs
[2/6/2022, 6:27:30 PM] [homebridge-homeconnect] [Trockner] Remote operation NOT enabled (remote start disallowed)
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] Door open
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] On
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] Inactive (Ready)
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] On
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] Connected
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] On
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] On
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] Cannot be switched off
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] 1 of 12 programs are currently unavailable
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] Missing options for 1 programs
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] To update the program options for this appliance:
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner]   - Enable remote control on the appliance
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner]   - Avoid operating the appliance locally
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner]   - Ensure that no program is active
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner]   - Fill any consumables that may be required
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner]   - Either restart Homebridge or invoke the appliance's Identify routine
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] Adding services for 0 programs
[2/6/2022, 6:27:32 PM] [homebridge-homeconnect] [Trockner] Removing services for 0 programs
[2/6/2022, 6:27:57 PM] Loaded plugin: homebridge-homeconnect@0.23.4
[2/6/2022, 6:27:57 PM] Registering platform 'homebridge-homeconnect.HomeConnect'
[2/6/2022, 6:28:00 PM] [homebridge-homeconnect] Launched child bridge with PID 1583
[2/6/2022, 6:28:01 PM] Registering platform 'homebridge-homeconnect.HomeConnect'
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Loaded homebridge-homeconnect v0.23.4 child bridge successfully
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] new HomeConnectPlatform
[2/6/2022, 6:28:01 PM] Publishing bridge accessory (name: homebridge-homeconnect, publishInfo: {
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Restored 3 cached accessories
[2/6/2022, 6:28:01 PM] Homebridge v1.4.0 (HAP v0.10.0) (homebridge-homeconnect) is running on port 33278.
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Refreshing access token in 79287 seconds
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Starting events stream for all appliances
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #1: STREAM https://api.home-connect.com/api/homeappliances/events
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #2: GET https://api.home-connect.com/api/homeappliances
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #2: OK +121ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Found 3 appliances
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Scheduling configuration schema write
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Connecting accessory 'Trockner'
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Bosch Dryer (E-Nr: WTX87E40/03)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Connecting accessory 'Waschmaschine'
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Bosch Washer (E-Nr: WAV28G43/04)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Connecting accessory 'Geschirrspüler'
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Bosch Dishwasher (E-Nr: SMV8YCX01E/17)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Connected, so reading appliance state...
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Connected, so reading appliance state...
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Connected, so reading appliance state...
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Started events stream for all appliances
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Event START (0 items)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Event START (0 items)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #3: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #4: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #5: GET https://api.home-connect.com/api/homeappliances/012010517384000477
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Cache loaded (27 entries)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance power' [de-DE, updated 28 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance settings' [de-DE, updated 28 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Restored details of 12 programs
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Cannot be switched off
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Cache loaded (22 entries)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance power' [de-DE, updated 3509 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 3509 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 3509 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Restored details of 9 programs
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Can be switched off
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support Functional Light
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support a child lock
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 3509 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support Ambient Light
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Cache loaded (25 entries)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance power' [de-DE, updated 31 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance settings' [de-DE, updated 31 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Restored details of 10 programs
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Cannot be switched off
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #3: OK +73ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #6: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/status
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #4: OK +76ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #7: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/status
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #5: OK +104ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #8: GET https://api.home-connect.com/api/homeappliances/012010517384000477/status
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #7: OK +78ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Open (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Door open
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.LocalControlActive=false (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Ready (3 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Operation state implies power is on
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Inactive (Ready)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.RemoteControlActive=true (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #9: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/settings
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #6: OK +89ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Open (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Door open
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.LocalControlActive=false (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Ready (3 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Operation state implies power is on
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] On
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Inactive (Ready)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.RemoteControlActive=true (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #10: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/settings
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #9: OK +69ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.ChildLock=false (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Child lock disabled
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #11: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/programs/selected
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #11: OK +66ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Root.SelectedProgram=LaundryCare.Washer.Program.Cotton.Eco4060 (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Option.EnergyForecast=40 % (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Option.FinishInRelative=13200 seconds (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Option.WaterForecast=40 % (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] LaundryCare.Common.Option.LoadRecommendation=9000 gram (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] LaundryCare.Washer.Option.SpinSpeed=LaundryCare.Washer.EnumType.SpinSpeed.RPM1400 (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] LaundryCare.Washer.Option.Temperature=LaundryCare.Washer.EnumType.Temperature.Auto (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Ignoring GET active program in BSH.Common.EnumType.OperationState.Ready
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Successfully read all appliance state
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] connected=true (4 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Connected
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance programs' [de-DE, updated 31 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #12: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/programs/available
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #10: OK +211ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.ChildLock=false (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Child lock disabled
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] On
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #13: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/programs/selected
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #12: OK +227ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] 'Program details' written to cache
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Cache saved (25 entries)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Finished reading available program options
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Adding services for 0 programs
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Removing services for 0 programs
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance commands' [de-DE, updated 31 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #13: OK +213ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Root.SelectedProgram=LaundryCare.Dryer.Program.Cotton (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Option.FinishInRelative=13200 seconds (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.ConnectedDry.OriginalProgramTime=13200 seconds (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.DryingTarget=LaundryCare.Dryer.EnumType.DryingTarget.CupboardDry (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.DryingTargetAdjustment=LaundryCare.Dryer.EnumType.DryingTargetAdjustment.Off (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.Gentle=false (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.WrinkleGuard=LaundryCare.Dryer.EnumType.WrinkleGuard.Min60 (0 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Ignoring GET active program in BSH.Common.EnumType.OperationState.Ready
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Successfully read all appliance state
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] connected=true (4 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Connected
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance programs' [de-DE, updated 29 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #14: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/programs/available
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] Home Connect request #14: OK +66ms 
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] 'Program details' written to cache
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Cache saved (27 entries)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Adding services for 0 programs
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Removing services for 0 programs
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance commands' [de-DE, updated 29 seconds ago]
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] 1 of 12 programs are currently unavailable
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Missing options for 1 programs
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] To update the program options for this appliance:
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner]   - Enable remote control on the appliance
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner]   - Avoid operating the appliance locally
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner]   - Ensure that no program is active
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner]   - Fill any consumables that may be required
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner]   - Either restart Homebridge or invoke the appliance's Identify routine
[2/6/2022, 6:28:03 PM] [homebridge-homeconnect] Home Connect request #8: OK +2572ms 
[2/6/2022, 6:28:03 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[2/6/2022, 6:28:03 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.RemoteControlActive=true (1 listeners)
[2/6/2022, 6:28:03 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Open (1 listeners)
[2/6/2022, 6:28:03 PM] [homebridge-homeconnect] [Geschirrspüler] Door open
[2/6/2022, 6:28:03 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Inactive (3 listeners)
[2/6/2022, 6:28:03 PM] [homebridge-homeconnect] [Geschirrspüler] Inactive (Inactive)
[2/6/2022, 6:28:03 PM] [homebridge-homeconnect] Home Connect request #15: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] Home Connect request #15: OK +68ms 
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.Off (1 listeners)
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Off
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] Home Connect request #16: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs/selected
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] Home Connect request #16: OK +65ms 
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Root.SelectedProgram=Dishcare.Dishwasher.Program.Auto2 (0 listeners)
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Ignoring GET active program in BSH.Common.EnumType.OperationState.Inactive
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Successfully read all appliance state
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] connected=true (4 listeners)
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Connected
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance programs' [de-DE, updated 3512 seconds ago]
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] Home Connect request #17: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs/available
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] Scheduled configuration schema write complete
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] Home Connect request #17: OK +154ms 
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] Scheduling configuration schema write
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] 'Program details' written to cache
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Finished reading available program options
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Adding services for 0 programs
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Removing services for 0 programs
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance commands' [de-DE, updated 3512 seconds ago]
[2/6/2022, 6:28:07 PM] [homebridge-homeconnect] Scheduled configuration schema write complete
[2/6/2022, 6:28:41 PM] [homebridge-homeconnect] [Waschmaschine] Event DISCONNECTED (0 items)
[2/6/2022, 6:28:41 PM] [homebridge-homeconnect] [Waschmaschine] Appliance lost connection to Home Connect servers
[2/6/2022, 6:28:41 PM] [homebridge-homeconnect] [Waschmaschine] connected=false (3 listeners)
[2/6/2022, 6:28:41 PM] [homebridge-homeconnect] [Waschmaschine] Disconnected
[2/6/2022, 6:28:43 PM] [homebridge-homeconnect] [Trockner] Event DISCONNECTED (0 items)
[2/6/2022, 6:28:43 PM] [homebridge-homeconnect] [Trockner] Appliance lost connection to Home Connect servers
[2/6/2022, 6:28:43 PM] [homebridge-homeconnect] [Trockner] connected=false (3 listeners)
[2/6/2022, 6:28:43 PM] [homebridge-homeconnect] [Trockner] Disconnected

I did the following:

  1. I enabled Debug mode in Homebridge
  2. I switched ON washer and dryer
  3. I gestartet Homebridge
  4. I save the log with cat /homebridge/homebridge.log | grep homeconnect > homeconnect.log

However, the state in HomeKit is as expected. The switches are all off. I will leave Debug enabled and check for the erroneous situation again...

thoukydides commented 2 years ago

Looking at the portion of the log after homebridge was restarted...

The Home Connect API initially responds to the requests for the Washer and Dryer appliance settings/status. Since (as far as the API is concerned) these appliances cannot be switched off they are reported as being BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On which would result in the HomeKit power switch initially being set to On:

[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Ready (3 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Operation state implies power is on
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] On
...
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Ready (3 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Operation state implies power is on
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] On
...
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] On
...
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] On
...
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Successfully read all appliance state
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] connected=true (4 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Waschmaschine] Connected
...
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Successfully read all appliance state
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] connected=true (4 listeners)
[2/6/2022, 6:28:01 PM] [homebridge-homeconnect] [Trockner] Connected

The Dishwasher state is then returned. This does support being switched off, so the API returns BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.Off, and the HomeKit power switch will be set to Off:

[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.Off (1 listeners)
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Off
...
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] connected=true (4 listeners)
[2/6/2022, 6:28:04 PM] [homebridge-homeconnect] [Geschirrspüler] Connected

Finally, the event stream reports that the Washer and Dryer appliances are no longer connected to the Home Connect servers. This is when the plugin flips the HomeKit power switches to Off:

[2/6/2022, 6:28:41 PM] [homebridge-homeconnect] [Waschmaschine] Event DISCONNECTED (0 items)
[2/6/2022, 6:28:41 PM] [homebridge-homeconnect] [Waschmaschine] Appliance lost connection to Home Connect servers
[2/6/2022, 6:28:41 PM] [homebridge-homeconnect] [Waschmaschine] connected=false (3 listeners)
[2/6/2022, 6:28:41 PM] [homebridge-homeconnect] [Waschmaschine] Disconnected
[2/6/2022, 6:28:43 PM] [homebridge-homeconnect] [Trockner] Event DISCONNECTED (0 items)
[2/6/2022, 6:28:43 PM] [homebridge-homeconnect] [Trockner] Appliance lost connection to Home Connect servers
[2/6/2022, 6:28:43 PM] [homebridge-homeconnect] [Trockner] connected=false (3 listeners)
[2/6/2022, 6:28:43 PM] [homebridge-homeconnect] [Trockner] Disconnected

The problem is that the DISCONNECTED event and the results of reading BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On are returned by unrelated APIs, so could theoretically occur in either order. Whichever occurs last sets the HomeKit power Switch state. This could explain the problem that you are experiencing... although I would still like to see a log to confirm.

In my experience, the Home Connect event stream is very unreliable, so I which is why I don't gate other plugin functionality on the event stream indicating that the appliance is CONNECTED. Hence, if the other APIs return valid results then they are used in preference to the event stream information.

If this is the cause then a "fix" for it is quite likely to break or impair the operation of some other functionality that is more important. As you have seen today, the Home Connect servers can be rather unreliable, so thus plugin tries to be resilient and keep going with best effort when it receives errors or inconsistent API responses.

Perhaps a log showing the problem sequence will suggest a possible approach...

smhex commented 2 years ago

Thank you for your comprehensive answer. It sounds quite reasonable to me. I will try to catch the situation again and come back with a new log. Nevertheless, I do not understand the design choices that Bosch made to have Wifi enabled in Power Off state for the dishwasher and Wifi disabled for most of the other appliances.

thoukydides commented 2 years ago

It looks like the problem may be even harder to fix that I thought...

The log reveals that both the /api/homeappliances and /api/homeappliances/{haId} methods returned "connected": true for all three appliances. This should match the CONNECTED or DISCONNECTED state of the event stream, so the plugin treats both sources of information similarly.

If the /api/homeappliances API did return the correct "connected" status then I could use that since it is polled once each hour (to refresh the list of appliances associated with the account). However, if it always returns "connected": true then it would actually make things worse.

If that API does return incorrect "connected" status then it is a bug in the implementation. Is there any chance that you could try using the API Web Client - Physical home appliances from Your Applications to see what /api/homeappliances returns after your appliances have been switched off for at least a few minutes? The steps you need to follow are:

  1. On the Home Connect API web client page click on the green Authorize button.
  2. In the Available authorizations box that opens:
    • Tick the IdentifyAppliance box (and any others you like).
    • Scroll down and click on the green Authorize button.
  3. A new Home Connect Authorization web page will open:
    • On the first page enter your account credentials (as used in the app, not those for the developer account) and click the blue Log in button.
    • On the next page click the blue Approve button.
  4. Click the black Close button in the Available authorizations box.
  5. Back on the main Home Connect API web client page:
    • Under default click on GET /homeappliances to expand that box.
    • Click the black Try it out button, followed by the blue Execute button.
    • The result can be found in the Server response section as the Response body.

In my case the result looks like:

{
  "data": {
    "homeappliances": [
      {
        "name": "Oven",
        "brand": "Siemens",
        "vib": "HB678GBS6B",
        "connected": true,
        "type": "Oven",
        "enumber": "HB678GBS6B/50",
        "haId": "SIEMENS-HB678GBS6B-xxxxxxxxxxxx"
      },
      {
        "name": "Induction Hob",
        "brand": "Siemens",
        "vib": "EX677LYV1E",
        "connected": true,
        "type": "Hob",
        "enumber": "EX677LYV1E/06",
        "haId": "SIEMENS-EX677LYV1E-xxxxxxxxxxxx"
      },
      {
        "name": "Dishwasher",
        "brand": "Siemens",
        "vib": "SN678D06TG",
        "connected": true,
        "type": "Dishwasher",
        "enumber": "SN678D06TG/53",
        "haId": "SIEMENS-SN678D06TG-xxxxxxxxxxxx"
      }
    ]
  }
}

If that does report incorrect "connected" status then it can be reported at https://developer.home-connect.com/support/contact and might end up being fixed. Please either report the issue yourself, or paste the server response here and I will do so.

smhex commented 2 years ago

Sorry. I am stuck at step 3. If I enter my HomeConnect app credentials I get the following error (translated):

The user used is not assigned to this application in the Home Connect Developer Portal.

I did not use the credentials for the developer account. I double checked by logging out and in again using theHomeConnect app itself. The credentials are working. Do you have an idea what might be wrong here?

thoukydides commented 2 years ago

Open the Your Account - Profile page on the the Home Connect Developer Program site (accessed via the person icon in the top-right corner of the page). The Default Home Connect User Account for Testing should be set to the email address that you use to login to the app.

smhex commented 2 years ago

Many thanks, I already tried that. No luck. I will wait for tomorrow, maybe it needs some time to take over the account changes.

smhex commented 2 years ago

So, obviously it took some time reflect the account changes. Here is the result of the /homeappliances call:

{
  "data": {
    "homeappliances": [
      {
        "name": "Trockner",
        "brand": "Bosch",
        "vib": "WTX87E40",
        "connected": false,
        "type": "Dryer",
        "enumber": "WTX87E40/03",
        "haId": "BOSCH-WTX87E40-68A40E716339"
      },
      {
        "name": "Waschmaschine",
        "brand": "Bosch",
        "vib": "WAV28G43",
        "connected": false,
        "type": "Washer",
        "enumber": "WAV28G43/04",
        "haId": "BOSCH-WAV28G43-68A40E716D7D"
      },
      {
        "name": "Geschirrspüler",
        "brand": "Bosch",
        "vib": "SMV8YCX01E",
        "connected": true,
        "type": "Dishwasher",
        "enumber": "SMV8YCX01E/17",
        "haId": "012010517384000477"
      }
    ]
  }
}

The connected property is correct. The dish washer is still running, washer and dryer are off (disconnected). I assume I have to wait for the initial situation again to see what the API reports.

thoukydides commented 2 years ago

That's encouraging.

Assuming that the /api/homeappliances API continues to return the correct "connected" status when the problem next occurs then I should be able to use the periodic poll to correct the appliance state. Obviously this could take up to 1 hour to correct the state, since that is the poll interval (selected to minimise the risk of exceeding the draconian Home Connect Rate Limits).

Of course, analysis of the sequence of events that result in the initial failure may suggest alternative approaches...

thoukydides commented 2 years ago

I have a suspicion that this issue may be related to #32 and #35. The fixes for those issues involved inferring BSH.Common.Setting.PowerState from BSH.Common.EnumType.OperationState.Ready. That workaround may break the workaround that I was considering for this issue…

thoukydides commented 2 years ago

I have submitted a speculative change that may help with this issue in v0.23.5.

Previously the CONNECTED/DISCONNECTED events and BSH.Common.Setting.PowerState/BSH.Common.Status.OperationState updates (whether received as events or the results of explicitly reading the value) were handled independently, with the HomeKit characteristics set based on whichever was received last.

The new version combines the most recent values, with the DISCONNECTED state always overriding the other updates until the appliance becomes CONNECTED again. It also delays updating HomeKit until the next JS event cycle to avoid incorrect interim updates when both changes occur "simultaneously".

I have applied the same updated approach to updating the Active Program Switch, Status Active, and Status Fault, characteristics.

smhex commented 2 years ago

Hi, I installed your latest update, restarted Homebridge and collected the following log:

[2/8/2022, 6:55:03 PM] [Homebridge UI] Running Command: npm install --save homebridge-homeconnect@latest
[2/8/2022, 6:55:32 PM] Loaded plugin: homebridge-homeconnect@0.23.5
[2/8/2022, 6:55:32 PM] Registering platform 'homebridge-homeconnect.HomeConnect'
[2/8/2022, 6:55:40 PM] [homebridge-homeconnect] Launched child bridge with PID 3103
[2/8/2022, 6:55:41 PM] Registering platform 'homebridge-homeconnect.HomeConnect'
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Loaded homebridge-homeconnect v0.23.5 child bridge successfully
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] new HomeConnectPlatform
[2/8/2022, 6:55:41 PM] Publishing bridge accessory (name: homebridge-homeconnect, publishInfo: {
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Restored 3 cached accessories
[2/8/2022, 6:55:41 PM] Homebridge v1.4.0 (HAP v0.10.0) (homebridge-homeconnect) is running on port 33278.
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Refreshing access token in 70428 seconds
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Starting events stream for all appliances
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #1: STREAM https://api.home-connect.com/api/homeappliances/events
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #2: GET https://api.home-connect.com/api/homeappliances
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #2: OK +137ms 
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Found 3 appliances
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Scheduling configuration schema write
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Connecting accessory 'Trockner'
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Bosch Dryer (E-Nr: WTX87E40/03)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Connecting accessory 'Waschmaschine'
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Bosch Washer (E-Nr: WAV28G43/04)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Connecting accessory 'Geschirrspüler'
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Geschirrspüler] Bosch Dishwasher (E-Nr: SMV8YCX01E/17)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Geschirrspüler] Connected, so reading appliance state...
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #3: GET https://api.home-connect.com/api/homeappliances/012010517384000477
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Started events stream for all appliances
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Event START (0 items)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Event START (0 items)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Connected, so reading appliance state...
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Connected, so reading appliance state...
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Cache loaded (27 entries)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance power' [de-DE, updated 174488 seconds ago] is too old
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance settings' [de-DE, updated 174488 seconds ago] is too old
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Restored details of 12 programs
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Cache loaded (25 entries)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance power' [de-DE, updated 174491 seconds ago] is too old
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance settings' [de-DE, updated 174491 seconds ago] is too old
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Restored details of 10 programs
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #4: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #5: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Geschirrspüler] Cache loaded (22 entries)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance power' [de-DE, updated 177969 seconds ago] is too old
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 177969 seconds ago] is too old
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 177969 seconds ago] is too old
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Geschirrspüler] Restored details of 9 programs
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #3: OK +76ms 
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #6: GET https://api.home-connect.com/api/homeappliances/012010517384000477/status
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #4: OK +71ms 
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] The appliance is offline
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] GET status
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Error: The appliance is offline
    at HomeConnectDevice.requireConnected (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:545:19)
    at HomeConnectDevice.requireMonitor (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:558:14)
    at HomeConnectDevice.getStatus (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:105:18)
    at Array.<anonymous> (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:469:24)
    at HomeConnectDevice.readAll (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:502:33)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Ignoring appliance state read due to disconnection: The appliance is offline
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] Home Connect request #5: OK +74ms 
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] The appliance is offline
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] GET status
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Error: The appliance is offline
    at HomeConnectDevice.requireConnected (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:545:19)
    at HomeConnectDevice.requireMonitor (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:558:14)
    at HomeConnectDevice.getStatus (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:105:18)
    at Array.<anonymous> (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:469:24)
    at HomeConnectDevice.readAll (/homebridge/node_modules/homebridge-homeconnect/lib/homeconnect_device.js:502:33)
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Ignoring appliance state read due to disconnection: The appliance is offline
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Trockner] Appliance disconnected; abandoning 4 pending reads
[2/8/2022, 6:55:41 PM] [homebridge-homeconnect] [Waschmaschine] Appliance disconnected; abandoning 4 pending reads
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Scheduled configuration schema write complete
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #6: OK +3103ms 
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.RemoteControlActive=true (1 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Open (1 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Door open
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Inactive (3 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #7: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Inactive (Inactive)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] No program running
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #7: OK +67ms 
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.Off (1 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #8: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs/selected
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Off
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #8: OK +71ms 
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Root.SelectedProgram=Dishcare.Dishwasher.Program.Eco50 (0 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Ignoring GET active program in BSH.Common.EnumType.OperationState.Inactive
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Successfully read all appliance state
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] connected=true (7 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Connected
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #9: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings/BSH.Common.Setting.PowerState
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #10: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #11: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance programs' [de-DE, updated 177973 seconds ago] is too old
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #12: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Off
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Inactive (Inactive)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #9: OK +73ms 
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.Off (1 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance power' written to cache
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Off
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #11: OK +75ms 
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.Off (1 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance settings' written to cache
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Off
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Can be switched off
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support a child lock
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #10: OK +147ms 
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.Off (1 listeners)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance settings' written to cache
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #12: OK +146ms 
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance programs' written to cache
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Off
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support Functional Light
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] Home Connect request #13: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs/available
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 0 seconds ago]
[2/8/2022, 6:55:44 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support Ambient Light
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] Home Connect request #13: OK +92ms 
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] Scheduling configuration schema write
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] [Geschirrspüler] 'Program details' written to cache
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] [Geschirrspüler] Finished reading available program options
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] [Geschirrspüler] Adding services for 0 programs
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] [Geschirrspüler] Removing services for 0 programs
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance commands' [de-DE, updated 177973 seconds ago] is too old
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] Home Connect request #14: GET https://api.home-connect.com/api/homeappliances/012010517384000477/commands
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] Home Connect request #14: OK +70ms 
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance commands' written to cache
[2/8/2022, 6:55:45 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/8/2022, 6:55:48 PM] [homebridge-homeconnect] Scheduled configuration schema write complete
[2/8/2022, 7:23:58 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (2 items)
[2/8/2022, 7:23:58 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=14100 seconds (1 listeners)
[2/8/2022, 7:23:58 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=0 % (0 listeners)
[2/8/2022, 7:23:59 PM] [homebridge-homeconnect] [Geschirrspüler] Event STATUS (1 item)
[2/8/2022, 7:23:59 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Ready (3 listeners)
[2/8/2022, 7:23:59 PM] [homebridge-homeconnect] [Geschirrspüler] Operation state implies power is on
[2/8/2022, 7:23:59 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/8/2022, 7:23:59 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:23:59 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/8/2022, 7:23:59 PM] [homebridge-homeconnect] [Geschirrspüler] Inactive (Ready)
[2/8/2022, 7:23:59 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/8/2022, 7:24:02 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:24:02 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Root.ActiveProgram=Dishcare.Dishwasher.Program.Eco50 (0 listeners)
[2/8/2022, 7:24:02 PM] [homebridge-homeconnect] [Geschirrspüler] Event STATUS (1 item)
[2/8/2022, 7:24:02 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Run (3 listeners)
[2/8/2022, 7:24:02 PM] [homebridge-homeconnect] [Geschirrspüler] Active (Run)
[2/8/2022, 7:24:02 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 55 minutes remaining
[2/8/2022, 7:24:03 PM] [homebridge-homeconnect] [Geschirrspüler] Event STATUS (1 item)
[2/8/2022, 7:24:03 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Closed (1 listeners)
[2/8/2022, 7:24:03 PM] [homebridge-homeconnect] [Geschirrspüler] Door closed
[2/8/2022, 7:24:39 PM] [homebridge-homeconnect] [Geschirrspüler] Event STATUS (1 item)
[2/8/2022, 7:24:39 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Open (1 listeners)
[2/8/2022, 7:24:39 PM] [homebridge-homeconnect] [Geschirrspüler] Door open
[2/8/2022, 7:25:03 PM] [homebridge-homeconnect] [Geschirrspüler] Event STATUS (1 item)
[2/8/2022, 7:25:03 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Closed (1 listeners)
[2/8/2022, 7:25:03 PM] [homebridge-homeconnect] [Geschirrspüler] Door closed
[2/8/2022, 7:25:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:25:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=14040 seconds (1 listeners)
[2/8/2022, 7:25:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 54 minutes remaining
[2/8/2022, 7:26:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:26:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=1 % (0 listeners)
[2/8/2022, 7:26:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:26:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13980 seconds (1 listeners)
[2/8/2022, 7:26:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 53 minutes remaining
[2/8/2022, 7:27:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:27:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13920 seconds (1 listeners)
[2/8/2022, 7:27:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 52 minutes remaining
[2/8/2022, 7:28:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:28:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13860 seconds (1 listeners)
[2/8/2022, 7:28:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:28:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=2 % (0 listeners)
[2/8/2022, 7:28:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 51 minutes remaining
[2/8/2022, 7:29:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:29:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13800 seconds (1 listeners)
[2/8/2022, 7:29:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 50 minutes remaining
[2/8/2022, 7:30:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:30:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=3 % (0 listeners)
[2/8/2022, 7:30:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:30:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13740 seconds (1 listeners)
[2/8/2022, 7:30:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 49 minutes remaining
[2/8/2022, 7:31:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:31:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13680 seconds (1 listeners)
[2/8/2022, 7:31:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 48 minutes remaining
[2/8/2022, 7:32:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:32:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13620 seconds (1 listeners)
[2/8/2022, 7:32:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 47 minutes remaining
[2/8/2022, 7:33:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:33:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=4 % (0 listeners)
[2/8/2022, 7:33:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:33:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13560 seconds (1 listeners)
[2/8/2022, 7:33:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 46 minutes remaining
[2/8/2022, 7:34:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:34:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13500 seconds (1 listeners)
[2/8/2022, 7:34:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 45 minutes remaining
[2/8/2022, 7:35:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:35:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=5 % (0 listeners)
[2/8/2022, 7:35:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:35:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13440 seconds (1 listeners)
[2/8/2022, 7:35:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 44 minutes remaining
[2/8/2022, 7:36:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:36:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13380 seconds (1 listeners)
[2/8/2022, 7:36:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 43 minutes remaining
[2/8/2022, 7:37:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:37:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=6 % (0 listeners)
[2/8/2022, 7:37:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:37:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13320 seconds (1 listeners)
[2/8/2022, 7:37:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 42 minutes remaining
[2/8/2022, 7:38:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:38:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13260 seconds (1 listeners)
[2/8/2022, 7:38:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 41 minutes remaining
[2/8/2022, 7:39:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:39:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13200 seconds (1 listeners)
[2/8/2022, 7:39:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 40 minutes remaining
[2/8/2022, 7:40:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:40:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=7 % (0 listeners)
[2/8/2022, 7:40:44 PM] [homebridge-homeconnect] [Geschirrspüler] Event NOTIFY (1 item)
[2/8/2022, 7:40:44 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=13140 seconds (1 listeners)
[2/8/2022, 7:40:44 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 3 hours 39 minutes remaining

Most of the output is related to the dishwasher as it is currently running. The dryer and the washer are off. However, the washer is shown as ON again in Homebridge/Homekit. Here is the result of the web API client call /homeapplicances:

{
  "data": {
    "homeappliances": [
      {
        "name": "Trockner",
        "brand": "Bosch",
        "vib": "WTX87E40",
        "connected": false,
        "type": "Dryer",
        "enumber": "WTX87E40/03",
        "haId": "BOSCH-WTX87E40-68A40E716339"
      },
      {
        "name": "Waschmaschine",
        "brand": "Bosch",
        "vib": "WAV28G43",
        "connected": false,
        "type": "Washer",
        "enumber": "WAV28G43/04",
        "haId": "BOSCH-WAV28G43-68A40E716D7D"
      },
      {
        "name": "Geschirrspüler",
        "brand": "Bosch",
        "vib": "SMV8YCX01E",
        "connected": true,
        "type": "Dishwasher",
        "enumber": "SMV8YCX01E/17",
        "haId": "012010517384000477"
      }
    ]
  }
}

As far as I can see it matches the appliances connected states correctly. What shall I test do get a more useful output?

thoukydides commented 2 years ago

Thank you for trying the new plugin version and providing that log.

The behaviour of the Home Connect API this time is different to the previous log you provided. The earlier example started with the API indicating that the device was connected, allowing the appliance state and settings to be read, with a subsequent DISCONNECTED marking the appliance as being unreachable (off). However, this time the initial API responses indicated that the appliance was unreachable (off), so no further API requests related to that appliance are attempted. This points at a completely different cause for the issue...

Each time the plugin starts, for each appliance in the Home Connect account the plugin first needs to read the appliance's capabilities before it can initialise the associated HomeKit services and characteristics. If the required details have been cached sufficiently recently (during a previous homebridge boot) then the cached values are used (to reduce the risk of exceeding Home Connect API rate limits if homebridge is restarted frequently). Otherwise, the plugin attempts to read the capabilities via the Home Connect API. If the appliance is disconnected at plugin start-up then the plugin waits (for as long as necessary) for the appliance to become connected before continuing. If the subsequent read fails and there is an out-of-date cached value then that is used as a last resort.

This happens independently for each group of related functionality supported by a particular class of appliance, so it is entirely possible for some functionality to finish initialising whilst other functionality remains stalled waiting for the appliance to be connected.

In parallel with this process, once the appliance is connected the plugin reads its current configuration and status. This is used to set the initial state of the HomeKit services and characteristics. Again, the plugin waits as long as necessary for the appliance to become connected before doing this. Until then the HomeKit state is left as-is.

I had been assuming that the issue you raised occurred after the appliance had successfully initialised, and the plugin was failing to track the state correctly when the appliance subsequently disconnected. However, it now looks like the issue is due to restarting homebridge when the appliance is off. This results in some of the initialisation stalling until the appliance is connected - either just setting the initial HomeKit state, or (if cached values have expired) not even getting as far as configuring the appropriate HomeKit capabilities.

This plugin was originally developed for the three Home Connect appliances that I own - all of which are permanently connected. They do not have physical power switches but just enter a standby mode. For these appliances the DISCONNECTED state is essentially an error condition - it requires the appliances to be isolated at the mains, or for their Wi-Fi connection to fail. Stalling at start-up until the devices are able to respond is therefore entirely reasonable.

Even with other appliance types that do routinely get switched off, it is still necessary for the plugin to query their capabilities and configuration/status before initialisation can complete. The cache avoids the creation/configuration of HomeKit capabilities stalling on most subsequent restarts. However, the cache expiry is there because the appliance capabilities can and do change due to firmware updates, Home Connect API changes, or even some user settings. If the plugin always used the cached values for appliances that are disconnected at startup then those cached capabilities would never get updated. The cache does not get used for dynamic status for obvious reasons, so it does not help with setting the initial HomeKit state.

For the specific case of the Power switch, I suspect that there are two issues. The first is that there is no trigger to set its initial state - the live appliance state cannot be read, and no DISCONNECTED event is received because the appliance was already disconnected. The second is that if the cached values have expired then the initialisation is stalled waiting to query whether the appliance supports Off or Standby.

This is going to require some more thought...

Don't worry about providing any more logs at the moment.

smhex commented 2 years ago

Hi, your thoughts sound reasonable to me. I confirm the Homebridge restart is one impact. I just switched the washer ON and OFF again. Please find the corresponding log below.

/homebridge # tail -f /homebridge/homebridge.log | grep homeconnect
[2/8/2022, 9:47:57 PM] [homebridge-homeconnect] [Waschmaschine] Event CONNECTED (0 items)
[2/8/2022, 9:47:57 PM] [homebridge-homeconnect] [Waschmaschine] Appliance is now connected to Home Connect servers
[2/8/2022, 9:47:57 PM] [homebridge-homeconnect] [Waschmaschine] Connected, so reading appliance state...
[2/8/2022, 9:47:57 PM] [homebridge-homeconnect] Home Connect request #17: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D
[2/8/2022, 9:47:57 PM] [homebridge-homeconnect] Home Connect request #17: OK +118ms 
[2/8/2022, 9:47:57 PM] [homebridge-homeconnect] Home Connect request #18: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/status
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Event NOTIFY (2 items)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Root.ActiveProgram=null (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Root.SelectedProgram=LaundryCare.Washer.Program.Cotton.Eco4060 (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Event STATUS (1 item)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Remote operation NOT enabled (remote start disallowed)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #18: OK +2198ms 
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Open (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Door open
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.LocalControlActive=false (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Ready (3 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Operation state implies power is on
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.RemoteControlActive=true (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #19: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/settings
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Inactive (Ready)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #19: OK +126ms 
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.ChildLock=false (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #20: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/programs/selected
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #20: OK +65ms 
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Root.SelectedProgram=LaundryCare.Washer.Program.Cotton.Eco4060 (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Option.EnergyForecast=40 % (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Option.FinishInRelative=13200 seconds (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Option.WaterForecast=40 % (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] LaundryCare.Common.Option.LoadRecommendation=9000 gram (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] LaundryCare.Washer.Option.SpinSpeed=LaundryCare.Washer.EnumType.SpinSpeed.RPM1400 (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] LaundryCare.Washer.Option.Temperature=LaundryCare.Washer.EnumType.Temperature.Auto (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Ignoring GET active program in BSH.Common.EnumType.OperationState.Ready
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Successfully read all appliance state
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] connected=true (6 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Connected
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #21: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/settings/BSH.Common.Setting.PowerState
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #22: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/settings
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance programs' [de-DE, updated 19106 seconds ago]
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #23: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D/programs/available
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Inactive (Ready)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #21: OK +70ms 
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] 'Appliance power' written to cache
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #23: OK +70ms 
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Scheduling configuration schema write
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] 'Program details' written to cache
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Cache saved (25 entries)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Cannot be switched off
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Finished reading available program options
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Adding services for 0 programs
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Removing services for 0 programs
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance commands' [de-DE, updated 19106 seconds ago]
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] Home Connect request #22: OK +123ms 
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.ChildLock=false (0 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] 'Appliance settings' written to cache
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] On
[2/8/2022, 9:47:59 PM] [homebridge-homeconnect] [Waschmaschine] Cache saved (25 entries)
[2/8/2022, 9:48:02 PM] [homebridge-homeconnect] Scheduled configuration schema write complete
[2/8/2022, 9:48:28 PM] [homebridge-homeconnect] [Waschmaschine] Event DISCONNECTED (0 items)
[2/8/2022, 9:48:28 PM] [homebridge-homeconnect] [Waschmaschine] Appliance lost connection to Home Connect servers
[2/8/2022, 9:48:28 PM] [homebridge-homeconnect] [Waschmaschine] connected=false (3 listeners)
[2/8/2022, 9:48:28 PM] [homebridge-homeconnect] [Waschmaschine] Disconnected
[2/8/2022, 9:48:28 PM] [homebridge-homeconnect] [Waschmaschine] Off (disconnected)
[2/8/2022, 9:48:28 PM] [homebridge-homeconnect] [Waschmaschine] Inactive, attention required, in error state (disconnected)

As a result the state in HomeKit was updated accordingly. The switch state was set to OFF. However I noticed that the event stream for the dishwasher is missing despite the fact that it is still running. It noticed this behavior already a few days before when the "remaining time" log entries suddenly stopped (for any of the appliances). That is one of my other issues I wanted to investigate 😄 .

thoukydides commented 2 years ago

However I noticed that the event stream for the dishwasher is missing despite the fact that it is still running.

The plugin only opens a single event stream that is shared by all appliances in the Home Connect account. The log clearly shows events being received for the Washer appliance, so the event stream connection between the plugin and the Home Connect servers is still fine. The problem is that Home Connect servers are no longer sending events for the Dishwasher.

This appears to be a duplicate of issue #74. It is almost certainly a bug in the Home Connect API implementation, and there is nothing that I can do about it other than report it again at https://developer.home-connect.com/support/contact

thoukydides commented 2 years ago

There's another attempt at fixing this issue in v0.23.6. Fingers crossed!

If the appliance is disconnected when the plugin starts, then this status (from the /api/homeappliances response used to trigger creation of the HomeKit accessory) is now used to set the initial Power state (as well as the Active Program Switch, Status Active, and Status Fault, characteristics).

I have also made some related changes to clean-up the log output for disconnected appliances, but should not otherwise have any functional impact. These get rid of the Error: The appliance is offline and associated backtrace, and correct the Connected, so reading appliance state... message to Might be connected, so reading appliance state... when an event stream is (re)established. after the appliance has disconnected.

Functionality that depends on the reading appliance capabilities may still stall during initialisation if there are no sufficiently recent cached values. In the case of the Power switch this will not prevent it correctly showing that the appliance is Off, but will leave it as read-only in HomeKit until the appliance first connects.

smhex commented 2 years ago

Perfect! I just updated to the new version. Please find the latest log below. Currently, dryer and dishwasher are running:

[2/9/2022, 8:57:55 PM] [Homebridge UI] Running Command: npm install --save homebridge-homeconnect@latest
[2/9/2022, 8:58:17 PM] Loaded plugin: homebridge-homeconnect@0.23.6
[2/9/2022, 8:58:17 PM] Registering platform 'homebridge-homeconnect.HomeConnect'
[2/9/2022, 8:58:20 PM] [homebridge-homeconnect] Launched child bridge with PID 3536
[2/9/2022, 8:58:20 PM] Registering platform 'homebridge-homeconnect.HomeConnect'
[2/9/2022, 8:58:20 PM] [homebridge-homeconnect] Loaded homebridge-homeconnect v0.23.6 child bridge successfully
[2/9/2022, 8:58:20 PM] [homebridge-homeconnect] new HomeConnectPlatform
[2/9/2022, 8:58:20 PM] Publishing bridge accessory (name: homebridge-homeconnect, publishInfo: {
[2/9/2022, 8:58:20 PM] [homebridge-homeconnect] Restored 3 cached accessories
[2/9/2022, 8:58:20 PM] Homebridge v1.4.0 (HAP v0.10.0) (homebridge-homeconnect) is running on port 33278.
[2/9/2022, 8:58:20 PM] [homebridge-homeconnect] Refreshing access token in 59468 seconds
[2/9/2022, 8:58:20 PM] [homebridge-homeconnect] Starting events stream for all appliances
[2/9/2022, 8:58:20 PM] [homebridge-homeconnect] Home Connect request #1: STREAM https://api.home-connect.com/api/homeappliances/events
[2/9/2022, 8:58:20 PM] [homebridge-homeconnect] Home Connect request #2: GET https://api.home-connect.com/api/homeappliances
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #2: OK +135ms 
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Found 3 appliances
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Scheduling configuration schema write
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Connecting accessory 'Trockner'
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Trockner] Bosch Dryer (E-Nr: WTX87E40/03)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Connecting accessory 'Waschmaschine'
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Bosch Washer (E-Nr: WAV28G43/04)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Connecting accessory 'Geschirrspüler'
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Geschirrspüler] Bosch Dishwasher (E-Nr: SMV8YCX01E/17)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Trockner] Connected, so reading appliance state...
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] connected=false (3 listeners)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Disconnected
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Geschirrspüler] Connected, so reading appliance state...
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Started events stream for all appliances
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Trockner] Event START (0 items)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Event START (0 items)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #3: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Off (disconnected)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Inactive, attention required, in error state (disconnected)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #4: GET https://api.home-connect.com/api/homeappliances/012010517384000477
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Might be connected, so reading appliance state...
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #5: GET https://api.home-connect.com/api/homeappliances/BOSCH-WAV28G43-68A40E716D7D
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Trockner] Cache loaded (27 entries)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance power' [de-DE, updated 268248 seconds ago] is too old
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance settings' [de-DE, updated 268248 seconds ago] is too old
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Trockner] Restored details of 12 programs
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Cache loaded (25 entries)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance power' [de-DE, updated 83421 seconds ago]
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Cache 'Appliance settings' [de-DE, updated 83421 seconds ago]
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Restored details of 10 programs
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Cannot be switched off
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Geschirrspüler] Cache loaded (22 entries)
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance power' [de-DE, updated 93756 seconds ago] is too old
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 93756 seconds ago] is too old
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 93756 seconds ago] is too old
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Geschirrspüler] Restored details of 9 programs
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #4: OK +75ms 
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #6: GET https://api.home-connect.com/api/homeappliances/012010517384000477/status
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #3: OK +81ms 
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #7: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/status
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] Home Connect request #5: OK +78ms 
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Appliance disconnected; abandoning 5 pending reads
[2/9/2022, 8:58:21 PM] [homebridge-homeconnect] [Waschmaschine] Ignoring appliance state read due to disconnection
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #7: OK +2590ms 
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Closed (1 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Door closed
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.LocalControlActive=false (1 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Run (3 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Operation state implies power is on
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.RemoteControlActive=true (1 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #8: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/settings
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] On
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Active (Run)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #8: OK +65ms 
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.ChildLock=false (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #9: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/programs/selected
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] On
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #9: OK +64ms 
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Root.SelectedProgram=LaundryCare.Dryer.Program.Cotton (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #10: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/programs/active
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #10: OK +67ms 
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Root.ActiveProgram=LaundryCare.Dryer.Program.Cotton (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Option.FinishInRelative=0 seconds (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.ConnectedDry.OriginalProgramTime=13200 seconds (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Common.Option.ReferToProgram=LaundryCare.Dryer.Program.ConnectedDry (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.DryingTarget=LaundryCare.Dryer.EnumType.DryingTarget.CupboardDry (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.DryingTargetAdjustment=LaundryCare.Dryer.EnumType.DryingTargetAdjustment.Off (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.Gentle=false (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Dryer.Option.WrinkleGuard=LaundryCare.Dryer.EnumType.WrinkleGuard.Off (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Option.EstimatedTotalProgramTime=6360 seconds (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Option.ProgramProgress=2 % (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Option.RemainingProgramTime=6120 seconds (1 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Option.RemainingProgramTimeIsEstimated=true (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] LaundryCare.Common.Option.ProcessPhase=LaundryCare.Common.EnumType.ProcessPhase.Drying (0 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Successfully read all appliance state
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] connected=true (6 listeners)
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Connected
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #11: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/settings/BSH.Common.Setting.PowerState
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #12: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/settings
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance programs' [de-DE, updated 268251 seconds ago] is too old
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] Home Connect request #13: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/programs
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Program has 1 hour 42 minutes remaining
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] On
[2/9/2022, 8:58:23 PM] [homebridge-homeconnect] [Trockner] Active (Run)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #11: OK +74ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] 'Appliance power' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] On
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #12: OK +77ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.ChildLock=false (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] 'Appliance settings' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] On
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Cache saved (27 entries)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Cannot be switched off
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Scheduled configuration schema write complete
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #13: OK +189ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] 'Appliance programs' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Cache saved (27 entries)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #14: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/programs/available
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #14: OK +65ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] 11 of 12 programs are currently unavailable
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Scheduling configuration schema write
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] 'Program details' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Cache saved (27 entries)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Missing options for 1 programs
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] To update the program options for this appliance:
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner]   - Enable remote control on the appliance
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner]   - Avoid operating the appliance locally
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner]   - Ensure that no program is active
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner]   - Fill any consumables that may be required
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner]   - Either restart Homebridge or invoke the appliance's Identify routine
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Adding services for 0 programs
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Removing services for 0 programs
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Cache 'Appliance commands' [de-DE, updated 268251 seconds ago] is too old
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #15: GET https://api.home-connect.com/api/homeappliances/BOSCH-WTX87E40-68A40E716339/commands
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #6: OK +3131ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.RemoteControlStartAllowed=false (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.RemoteControlActive=true (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.DoorState=BSH.Common.EnumType.DoorState.Closed (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Door closed
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Status.OperationState=BSH.Common.EnumType.OperationState.Run (3 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Operation state implies power is on
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #16: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Remote operation NOT enabled (remote control activated, remote start disallowed)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Active (Run)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 0 seconds remaining
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #15: OK +73ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] 'Appliance commands' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Trockner] Cache saved (27 entries)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #16: OK +67ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #17: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs/selected
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #17: OK +68ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Root.SelectedProgram=Dishcare.Dishwasher.Program.Eco50 (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #18: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs/active
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #18: OK +157ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Root.ActiveProgram=Dishcare.Dishwasher.Program.Eco50 (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.StartInRelative=0 seconds (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Dishcare.Dishwasher.Option.ExtraDry=false (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Dishcare.Dishwasher.Option.HygienePlus=false (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Dishcare.Dishwasher.Option.IntensivZone=false (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Dishcare.Dishwasher.Option.VarioSpeedPlus=false (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Dishcare.Dishwasher.Option.SilenceOnDemand=false (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.ProgramProgress=24 % (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTime=10738 seconds (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.RemainingProgramTimeIsEstimated=true (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.EnergyForecast=30 % (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Option.WaterForecast=43 % (0 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Successfully read all appliance state
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] connected=true (7 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Connected
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #19: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings/BSH.Common.Setting.PowerState
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #20: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #21: GET https://api.home-connect.com/api/homeappliances/012010517384000477/settings
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance programs' [de-DE, updated 93759 seconds ago] is too old
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #22: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Program has 2 hours 58 minutes remaining
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Active (Run)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #19: OK +76ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance power' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Can be switched off
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #21: OK +175ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance settings' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #22: OK +176ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance programs' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #20: OK +202ms 
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] BSH.Common.Setting.PowerState=BSH.Common.EnumType.PowerState.On (1 listeners)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance settings' written to cache
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] On
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support a child lock
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] Home Connect request #23: GET https://api.home-connect.com/api/homeappliances/012010517384000477/programs/available
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support Functional Light
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance settings' [de-DE, updated 0 seconds ago]
[2/9/2022, 8:58:24 PM] [homebridge-homeconnect] [Geschirrspüler] Does not support Ambient Light
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] Home Connect request #23: OK +78ms 
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] 8 of 9 programs are currently unavailable
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] 'Program details' written to cache
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] Finished reading available program options
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] Adding services for 0 programs
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] Removing services for 0 programs
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] Cache 'Appliance commands' [de-DE, updated 93759 seconds ago] is too old
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] Home Connect request #24: GET https://api.home-connect.com/api/homeappliances/012010517384000477/commands
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] Home Connect request #24: OK +64ms 
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] 'Appliance commands' written to cache
[2/9/2022, 8:58:25 PM] [homebridge-homeconnect] [Geschirrspüler] Cache saved (22 entries)
[2/9/2022, 8:58:27 PM] [homebridge-homeconnect] Scheduled configuration schema write complete
[2/9/2022, 8:58:34 PM] [homebridge-homeconnect] [Trockner] Event NOTIFY (1 item)
[2/9/2022, 8:58:34 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Option.ProgramProgress=3 % (0 listeners)
[2/9/2022, 8:58:35 PM] [homebridge-homeconnect] [Trockner] Event NOTIFY (1 item)
[2/9/2022, 8:58:35 PM] [homebridge-homeconnect] [Trockner] BSH.Common.Option.RemainingProgramTime=6060 seconds (1 listeners)
[2/9/2022, 8:58:35 PM] [homebridge-homeconnect] [Trockner] Program has 1 hour 41 minutes remaining
/homebridge # 

The corresponding web API client shows the following appliance state:

{
  "data": {
    "homeappliances": [
      {
        "name": "Trockner",
        "brand": "Bosch",
        "vib": "WTX87E40",
        "connected": true,
        "type": "Dryer",
        "enumber": "WTX87E40/03",
        "haId": "BOSCH-WTX87E40-68A40E716339"
      },
      {
        "name": "Waschmaschine",
        "brand": "Bosch",
        "vib": "WAV28G43",
        "connected": false,
        "type": "Washer",
        "enumber": "WAV28G43/04",
        "haId": "BOSCH-WAV28G43-68A40E716D7D"
      },
      {
        "name": "Geschirrspüler",
        "brand": "Bosch",
        "vib": "SMV8YCX01E",
        "connected": true,
        "type": "Dishwasher",
        "enumber": "SMV8YCX01E/17",
        "haId": "012010517384000477"
      }
    ]
  }
}

As far as I can see for now, the states are correctly shown in HomeKit. The remaining time is also shown for both running appliances. I will continue monitoring...

Many thanks for your time you spent in those investigations! I really appreciate this 👍

thoukydides commented 2 years ago

That's great!

Thank you for testing and providing feedback so quickly. Those full debug logs were very helpful.