Timeout errors starting after midnight

Blackmyre · October 20, 2024, 8:43am

A few nights ago I tried to check something in HomeAssistant from my [Android] phone shortly after midnight but it persistently reported “unable to connect”. Next morning I restarted the HomeAssistant container and everything seemed OK again, but I’ve had the same pattern repeatedly. The logs seem to indicate that various timeout-related warnings and errors begin a few seconds after midnight. This is a selection with some repeat messages removed for clarity:

2024-10-20 00:02:51.576 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for media_player.living_room (<class 'homeassistant.components.cast.media_player.CastMediaPlayerEntity'>) took 1.125 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+cast%22
2024-10-20 00:03:01.347 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for media_player.all (<class 'homeassistant.components.cast.media_player.CastMediaPlayerEntity'>) took 0.477 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+cast%22
2024-10-20 00:03:41.368 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for button.rbr50_restart (<class 'homeassistant.components.netgear.button.NetgearRouterButtonEntity'>) took 0.475 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+netgear%22
2024-10-20 00:03:55.272 ERROR (MainThread) [homeassistant.components.rest.data] Timeout while fetching data: http://home.boxersoft.com/bins/json
2024-10-20 00:03:55.483 WARNING (MainThread) [homeassistant.components.rest.util] Empty reply found when expecting JSON data
2024-10-20 00:03:58.973 ERROR (MainThread) [metno] Access to https://aa015h6buqvih86i1.api.met.no/weatherapi/locationforecast/2.0/complete returned error 'TimeoutError'
2024-10-20 00:03:59.024 ERROR (MainThread) [homeassistant.components.met.coordinator] Error fetching met data: Update failed: 
2024-10-20 00:13:31.862 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for media_player.panasonic (<class 'homeassistant.components.cast.media_player.CastMediaPlayerEntity'>) took 16.284 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+cast%22
2024-10-20 00:13:48.164 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for media_player.landing_speaker (<class 'homeassistant.components.cast.media_player.CastMediaPlayerEntity'>) took 6.449 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+cast%22
2024-10-20 00:14:15.036 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for sensor.living_room_lightswitch_wifi_signal (<class 'homeassistant.components.esphome.sensor.EsphomeSensor'>) took 0.895 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+esphome%22
2024-10-20 00:14:47.237 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for sensor.living_room_envirnoment_battery_sensor (<class 'homeassistant.components.homekit_controller.sensor.HomeKitBatterySensor'>) took 2.138 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+homekit_controller%22
2024-10-20 00:14:50.799 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for sensor.living_room_envirnoment_temperature (<class 'homeassistant.components.homekit_controller.sensor.HomeKitTemperatureSensor'>) took 0.442 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+homekit_controller%22
2024-10-20 00:14:55.423 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for climate.living_room_radiator (<class 'homeassistant.components.homekit_controller.climate.HomeKitHeaterCoolerEntity'>) took 3.056 seconds. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+homekit_controller%22
2024-10-20 00:16:02.052 WARNING (MainThread) [homeassistant.helpers.entity] Updating state for binary_sensor.100100874f_0 (<class 'custom_components.sonoff.binary_sensor.XRemoteSensor'>) took 3.107 seconds. Please create a bug report at https://github.com/AlexxIT/SonoffLAN/issues
2024-10-20 00:15:30.727 ERROR (ThreadPoolExecutor-ThreadScheduler_1) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Top-level exception occurred in callback while processing a message
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/google/cloud/pubsub_v1/subscriber/_protocol/streaming_pull_manager.py", line 126, in _wrap_callback_errors
    callback(message)
  File "/usr/local/lib/python3.12/site-packages/google_nest_sdm/google_nest_subscriber.py", line 294, in callback_wrapper
    future.result(NEW_SUBSCRIBER_TIMEOUT_SECONDS)
  File "/usr/local/lib/python3.12/concurrent/futures/_base.py", line 458, in result
    raise TimeoutError()
TimeoutError

The [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] error then repeats every 5-10 seconds or so until the server is restarted.

There’s also a persistent warning from the sonoff custom component but that seems to occur every 15 seconds throughout the day so although I obviously need to address that I suspect it’s unrelated to the more immediate problem:
2024-10-19 23:56:31.750 WARNING (MainThread) [custom_components.sonoff.core.ewelink.cloud] You logged in from another place

I can’t think of anything I’ve changed recently that might cause this behaviour, it’s been working fine for ages. My [container type] setup had been running v 2024.8 happily when the problems first appeared, I upgraded to 2024.10 yesterday but had same problem at midnight. I’m out of my depth. Can anyone point me in the right direction to fix this?

ShadowFist · October 20, 2024, 10:04am

Do you have any google-related integrations running? I would start by disabling those.

Also, long shot, but try setting a static IP for your HA instance if it’s not already set. Those warnings could be the result of a DHCP lease expiring and your router assigning a different IP.

Blackmyre · October 20, 2024, 10:36am

Yes, I have the Google Nest integration running for the Nest Doorbell and the Nest Thermostat. I could do without the doorbell but the thermostat is the heart of my home automation. I guess I could disable it shortly before midnight tonight to see if that prevents the problem. It’s a real pain that it only occurs at that time, it could take forever to track down if I only have one shot per 24hrs.

I already have a static IP address for my HomeAssistant server.

Thanks very much for the response, much appreciated. I’m on holiday in a couple of weeks and desperately want HA running reliably so I can monitor things while I’m away and control the heating when I leave/return.

Blackmyre · October 21, 2024, 7:10am

OK, I disabled the Google Nest integration last night and there were no problems at midnight. I re-enabled it shortly after midnight and everything continued to work fine, so it does look like that integration was doing something at midnight that fouled up. Good catch.

The obvious next question is “what do I do now?”. Presumably a great many people have this integration running happily, as I did until about a week ago…