search

leikoilja / ha-google-home

Home Assistant Google Home custom component
MIT License
438 stars 73 forks source link

Devices that go offline do not fetch the alarm state after returning #196

Open sebirdman opened 3 years ago

sebirdman commented 3 years ago

Describe the bug

Every morning at around 02:50 my google homes go offline for some reason for about 10 minutes. I get the log: "maybe it is offline" and then they come back online.

However. If i have any alarms set, these alarms do not show back up. After restarting home assistant they still show as unavailable. It appears that alarms do not show up in the state unless they are set while the integration is running and connected.

Version of the integration

1.4.1

Logs

I can get more logs, currently typing this from phone as this just happened a few minutes ago.

KapJI commented 3 years ago

Yeah, more logs should be useful. We're continuously querying all devices. When it come back online, alarms should be fetched.

sebirdman commented 3 years ago

@KapJI So here are my steps that i can reproduce the problem with:

1) set alarm for 1 hour via voice 2) reboot home assistant 3) Observe:

2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Got 4 devices. Iterating...
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Appending new device. name: Kitchen Display, ip: 10.20.1.39, port: 8009, model: Google Nest Hub
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Initializing GoogleDevice...
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Set self name to Kitchen Display, IP to 10.20.1.39, PORT to 8009 and model to Google Nest Hub
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Appending new device. name: Public Areas, ip: 10.20.1.39, port: 32149, model: Google Cast Group
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Initializing GoogleDevice...
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Set self name to Public Areas, IP to 10.20.1.39, PORT to 32149 and model to Google Cast Group
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Appending new device. name: Whole Home, ip: 10.20.1.39, port: 32131, model: Google Cast Group
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Initializing GoogleDevice...
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Set self name to Whole Home, IP to 10.20.1.39, PORT to 32131 and model to Google Cast Group
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Appending new device. name: Garage speaker, ip: 10.20.1.42, port: 8009, model: Google Home Mini
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Initializing GoogleDevice...
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.scanner] Set self name to Garage speaker, IP to 10.20.1.42, PORT to 8009 and model to Google Home Mini
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Iterating in 17 homegraph devices
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Looking for 'Hardware corner Wifi' in local network
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Hardware corner Wifi] Initializing new Device instance
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Hardware corner Wifi] google_device is not provided, using manually provided IP and PORT
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Hardware corner Wifi] Set device_name to "Hardware corner Wifi", local_auth_token to "Q***********************************************************************************************************", IP to "None", PORT to "None" and hardware to "Nest Wifi point"
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Adding Hardware corner Wifi to devices list
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Looking for 'Nest Wifi router' in local network
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Nest Wifi router] Initializing new Device instance
2021-04-13 18:38:42 ERROR (SyncWorker_6) [glocaltokens.client] [Device - Nest Wifi router] local_auth_token must follow the correct format
2021-04-13 18:38:42 WARNING (SyncWorker_6) [glocaltokens.client] Nest Wifi router device initialization failed because of missing local_auth_token, skipping.
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Looking for 'Garage speaker' in local network
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Garage speaker] Initializing new Device instance
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Garage speaker] google_device is provided, using it's IP and PORT
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Garage speaker] Set device_name to "Garage speaker", local_auth_token to "O***********************************************************************************************************", IP to "10.20.1.42", PORT to "8009" and hardware to "Google Home Mini"
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Adding Garage speaker to devices list
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Looking for 'Master Bedroom speaker' in local network
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Master Bedroom speaker] Initializing new Device instance
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Master Bedroom speaker] google_device is not provided, using manually provided IP and PORT
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Master Bedroom speaker] Set device_name to "Master Bedroom speaker", local_auth_token to "V***********************************************************************************************************", IP to "None", PORT to "None" and hardware to "Google Home"
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Adding Master Bedroom speaker to devices list
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'LG webOS Smart TV' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Looking for 'Kitchen Display' in local network
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Kitchen Display] Initializing new Device instance
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Kitchen Display] google_device is provided, using it's IP and PORT
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Kitchen Display] Set device_name to "Kitchen Display", local_auth_token to "l***********************************************************************************************************", IP to "10.20.1.39", PORT to "8009" and hardware to "Google Nest Hub"
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Adding Kitchen Display to devices list
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Looking for 'Nest Wifi router' in local network
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Nest Wifi router] Initializing new Device instance
2021-04-13 18:38:42 ERROR (SyncWorker_6) [glocaltokens.client] [Device - Nest Wifi router] local_auth_token must follow the correct format
2021-04-13 18:38:42 WARNING (SyncWorker_6) [glocaltokens.client] Nest Wifi router device initialization failed because of missing local_auth_token, skipping.
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'Mobile Speaker' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'Upstairs' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Looking for 'Nest Wifi router' in local network
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Nest Wifi router] Initializing new Device instance
2021-04-13 18:38:42 ERROR (SyncWorker_6) [glocaltokens.client] [Device - Nest Wifi router] local_auth_token must follow the correct format
2021-04-13 18:38:42 WARNING (SyncWorker_6) [glocaltokens.client] Nest Wifi router device initialization failed because of missing local_auth_token, skipping.
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'Kitchen' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'Google Wifi router' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'Downer' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'Upper' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'Google Wifi router' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] 'Google Wifi router' local_auth_token is not found in Homegraph, skipping
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Looking for 'Nest Wifi router' in local network
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Nest Wifi router] Initializing new Device instance
2021-04-13 18:38:42 ERROR (SyncWorker_6) [glocaltokens.client] [Device - Nest Wifi router] local_auth_token must follow the correct format
2021-04-13 18:38:42 WARNING (SyncWorker_6) [glocaltokens.client] Nest Wifi router device initialization failed because of missing local_auth_token, skipping.
2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] Sucessfully initialized 4 Google Home devices
2021-04-13 18:38:42 DEBUG (MainThread) [custom_components.google_home] Failed to fetch timers/alarms information from device Hardware corner Wifi. We could not determine it's IP address, the device is either offline or is not compatible Google Home device. Will try again later.
2021-04-13 18:38:42 DEBUG (MainThread) [custom_components.google_home] Failed to fetch timers/alarms information from device Master Bedroom speaker. We could not determine it's IP address, the device is either offline or is not compatible Google Home device. Will try again later.
2021-04-13 18:38:42 DEBUG (MainThread) [custom_components.google_home] Fetching data from Google Home device Garage speaker - https://10.20.1.42:8443/setup/assistant/alarms
2021-04-13 18:38:42 DEBUG (MainThread) [custom_components.google_home] Fetching data from Google Home device Kitchen Display - https://10.20.1.39:8443/setup/assistant/alarms
2021-04-13 18:38:42 DEBUG (MainThread) [custom_components.google_home] Succesfully retrieved data from Garage speaker.
2021-04-13 18:38:42 DEBUG (MainThread) [custom_components.google_home] Getting Do Not Disturb setting from Google Home device Garage speaker
2021-04-13 18:38:42 DEBUG (MainThread) [custom_components.google_home] Requesting endpoint setup/assistant/notifications for Google Home device Garage speaker - https://10.20.1.42:8443/setup/assistant/notifications
2021-04-13 18:38:43 DEBUG (MainThread) [custom_components.google_home] Received Do Not Disturb setting from Google Home device Garage speaker - Enabled: False
2021-04-13 18:38:43 DEBUG (MainThread) [custom_components.google_home] Succesfully retrieved data from Kitchen Display.
2021-04-13 18:38:43 DEBUG (MainThread) [custom_components.google_home] Getting Do Not Disturb setting from Google Home device Kitchen Display
2021-04-13 18:38:43 DEBUG (MainThread) [custom_components.google_home] Requesting endpoint setup/assistant/notifications for Google Home device Kitchen Display - https://10.20.1.39:8443/setup/assistant/notifications
2021-04-13 18:38:43 DEBUG (MainThread) [custom_components.google_home] Received Do Not Disturb setting from Google Home device Kitchen Display - Enabled: False
2021-04-13 18:38:43 DEBUG (MainThread) [custom_components.google_home] Finished fetching sensor data in 23.804 seconds

Specifically:

2021-04-13 18:38:42 DEBUG (MainThread) [custom_components.google_home] Failed to fetch timers/alarms information from device Master Bedroom speaker. We could not determine it's IP address, the device is either offline or is not compatible Google Home device. Will try again later.

I see regular polling:

2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Fetching data from Google Home device Garage speaker - https://10.20.1.42:8443/setup/assistant/alarms
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Fetching data from Google Home device Kitchen Display - https://10.20.1.39:8443/setup/assistant/alarms
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Succesfully retrieved data from Garage speaker.
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Getting Do Not Disturb setting from Google Home device Garage speaker
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Requesting endpoint setup/assistant/notifications for Google Home device Garage speaker - https://10.20.1.42:8443/setup/assistant/notifications
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Succesfully retrieved data from Kitchen Display.
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Getting Do Not Disturb setting from Google Home device Kitchen Display
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Requesting endpoint setup/assistant/notifications for Google Home device Kitchen Display - https://10.20.1.39:8443/setup/assistant/notifications
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Received Do Not Disturb setting from Google Home device Garage speaker - Enabled: False
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Received Do Not Disturb setting from Google Home device Kitchen Display - Enabled: False
2021-04-13 18:45:13 DEBUG (MainThread) [custom_components.google_home] Finished fetching sensor data in 0.047 seconds

But i do not see the problem device being queried here.

Strangely, I notice that this one device has this log:

2021-04-13 18:38:42 DEBUG (SyncWorker_6) [glocaltokens.client] [Device - Master Bedroom speaker] google_device is not provided, using manually provided IP and PORT

EDIT:

A second reboot seems to make the device show up. So this feels like it's something timing related.

KapJI commented 3 years ago

google_device is not provided indicates this device is not found in local network by zeroconf discovery. This is how we get ip address of the device.

Right now we only run zeroconf discovery once during HA startup. If device was not found, it won't get any updates.

leikoilja commented 3 years ago

hmm, we perhaps after introducing uids for devices we can force run glocaltokens task to discover devices to solve this issue, @KapJI, @DurgNomis-drol ? :)

KapJI commented 3 years ago

Yeah, that's actually pretty similar to #122