search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
71.16k stars 29.85k forks source link

Harmony Hub / Google devices suffering timeout errors after 2022.3 #67624

Closed ianfretwell closed 2 years ago

ianfretwell commented 2 years ago

The problem

Multiple devices seem to be suffering timeout issues since upgrading to 2022.3.0.

The following issues also seem to be of a similar type of nature too #67599 & #67578

Anybody able to confirm similar issues?

What version of Home Assistant Core has the issue?

2022.3.0

What was the last working version of Home Assistant Core?

2022.2.9

What type of installation are you running?

Home Assistant Container

Integration causing the issue

Harmony, Google

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Harmony:-
Logger: aioharmony.hubconnector_websocket
Source: /usr/local/lib/python3.9/site-packages/aioharmony/hubconnector_websocket.py:161
First occurred: 3 March 2022, 19:36:05 (19 occurrences)
Last logged: 11:05:09

192.168.1.80: Connection timed out for hub 13827915

Google:-
Logger: pychromecast.socket_client
Source: /usr/local/lib/python3.9/site-packages/pychromecast/socket_client.py:663
First occurred: 3 March 2022, 02:19:31 (8 occurrences)
Last logged: 04:53:11

[Bedroom Hub(192.168.1.116):8009] Error communicating with socket, resetting connection
[Living Room Hub(192.168.1.114):8009] Error communicating with socket, resetting connection
[Kitchen Hub(192.168.1.112):8009] Error communicating with socket, resetting connection
[Snug Hub(192.168.1.113):8009] Error communicating with socket, resetting connection

Additional information

No response

probot-home-assistant[bot] commented 2 years ago

google documentation google source (message by IssueLinks)

probot-home-assistant[bot] commented 2 years ago

harmony documentation harmony source (message by IssueLinks)

probot-home-assistant[bot] commented 2 years ago

Hey there @allenporter, mind taking a look at this issue as it has been labeled with an integration (google) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

probot-home-assistant[bot] commented 2 years ago

Hey there @ehendrix23, @bramkragten, @bdraco, @mkeesey, @aohzan, mind taking a look at this issue as it has been labeled with an integration (harmony) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

rob1981forest commented 2 years ago

I'm seeing these events too for Harmony and Google devices.

bdraco commented 2 years ago

Please enable debugpy: in your configuration.yaml

probot-home-assistant[bot] commented 2 years ago

cast documentation cast source (message by IssueLinks)

probot-home-assistant[bot] commented 2 years ago

Hey there @emontnemery, mind taking a look at this issue as it has been labeled with an integration (cast) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

ianfretwell commented 2 years ago

Please enable debugpy: in your configuration.yaml

OK, I did that. Checked config. Also performed upgrade to 2022.3.1. Restarted.

HA came up, promptly crashed - more or less at the end of setup with a stack overflow error.

Restarted - same again.

Removed 'debugpy:' , restarted. Came up just fine.

What was supposed to happened - because I'm guessing it wasn't this ?

bdraco commented 2 years ago

You should get logging about which integration is blocking your event loop.

If that's not working you'll have to disable integrations one by one until it works

ianfretwell commented 2 years ago

Apologies - been away.

What is meant by "blocking your event loop" ? I don't get what that could mean in relation to timeout events.

Thanks.

sambeetm commented 2 years ago

me too... 2022-03-11 15:13:40 ERROR (MainThread) [aioharmony.hubconnector_websocket] 192.168.1.53: Connection timed out for hub 16387953 2022-03-11 15:23:53 ERROR (MainThread) [aioharmony.hubconnector_websocket] 192.168.1.53: Connection timed out for hub 16387953 2022-03-11 15:54:07 ERROR (MainThread) [aioharmony.hubconnector_websocket] 192.168.1.53: Connection timed out for hub 16387953

ianfretwell commented 2 years ago

I don't think enough people are perhaps seeing the issue (maybe because of how they use their hubs) - so the assumption from the people who could probably help is that it'll be our WiFi setups causing this and not some change within HA itself.

I believe rob1981forest rolled back to 2022.2.x and the timeouts then stopped (i.e. back to normal).

We're probably just stuck with this until it affects somebody with the ability to fault find what has changed (and I also think it's not just Harmony that is affected, seems more like all network traffic is struggling for some reason).

Mariusthvdb commented 2 years ago

running 2022.4.0.dev20220319 and updating daily, I am seeing increasing timing issues, next to the ones I dont even bother about anymore... it does get frightening to see all of these loggings, and wonder if something fundamental should be changed.

mine have nothing to do with Harmony (dont have that) but it could be a more general issue?

what I think I did notice was that moving from some rest sensors, to the now core HA version sensors did make a change. I removed the rest sensors gladly, because in the past these seemed to cause response issues of their own. Replacing them with the core integration version and hassio thought didnt help.

small selection:

2022-03-19 09:42:02 WARNING (MainThread) [aioshelly.block_device] device 192.168.1.86 initialize error - TimeoutError()
2022-03-19 09:42:02 WARNING (MainThread) [homeassistant.components.buienradar.util] Unable to retrieve json data from Buienradar(Msg: , status: None,)
2022-03-19 09:42:05 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/discovery_flow.py", line 74, in _async_process_pending_flows
    await gather_with_concurrency(
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 192, in gather_with_concurrency
    return await gather(
  File "/usr/src/homeassistant/homeassistant/util/async_.py", line 190, in sem_task
    return await task
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 205, in async_init
    flow, result = await task
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 232, in _async_init
    result = await self._async_handle_step(flow, flow.init_step, data, init_done)
  File "/usr/src/homeassistant/homeassistant/data_entry_flow.py", line 335, in _async_handle_step
    result: FlowResult = await getattr(flow, method)(user_input)
  File "/usr/src/homeassistant/homeassistant/components/hue/config_flow.py", line 273, in async_step_homekit
    self.bridge = await self._get_bridge(discovery_info.host)
  File "/usr/src/homeassistant/homeassistant/components/hue/config_flow.py", line 73, in _get_bridge
    bridge = await discover_bridge(
  File "/usr/local/lib/python3.9/site-packages/aiohue/discovery.py", line 35, in discover_bridge
    bridge_id = await is_hue_bridge(host, websession)
  File "/usr/local/lib/python3.9/site-packages/aiohue/discovery.py", line 79, in is_hue_bridge
    async with websession.get(url, timeout=30) as res:
  File "/usr/local/lib/python3.9/site-packages/aiohttp/client.py", line 1138, in __aenter__
    self._resp = await self._coro
  File "/usr/local/lib/python3.9/site-packages/aiohttp/client.py", line 559, in _request
    await resp.start(conn)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/client_reqrep.py", line 898, in start
    message, payload = await protocol.read()  # type: ignore[union-attr]
  File "/usr/local/lib/python3.9/site-packages/aiohttp/streams.py", line 616, in read
    await self._waiter
aiohttp.client_exceptions.ServerDisconnectedError: Server disconnected
2022-03-19 09:42:10 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/custom-cards/decluttering-card/events
2022-03-19 09:42:12 WARNING (MainThread) [homeassistant.components.binary_sensor] Updating workday binary_sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:42:21 ERROR (MainThread) [homeassistant.components.mobile_app.notify] Timeout sending notification to https://mobile-apps.home-assistant.io/api/sendPushNotification
2022-03-19 09:42:22 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/lovelace-auto-entities/events
2022-03-19 09:42:22 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/hass-favicon/events
2022-03-19 09:42:22 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/hass-browser_mod/events
2022-03-19 09:42:22 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/lovelace-card-mod/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/lovelace-layout-card/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/lovelace-fold-entity-row/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/kalkih/simple-weather-card/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/iantrich/restriction-card/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/gurbyz/power-wheel-card/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/benct/lovelace-multiple-entity-row/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/azogue/eventsensor/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/arallsopp/hass-hue-icons/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/lovelace-toggle-lock-entity-row/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/lovelace-template-entity-row/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/lovelace-state-switch/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/thomasloven/lovelace-slider-entity-row/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/xirixiz/homeassistant-afvalwijzer/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/kalkih/mini-media-player/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/iMicknl/ha-tahoma/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/kalkih/mini-graph-card/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/Yevgenium/weather-chart-card/events
2022-03-19 09:42:23 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/bramkragten/swipe-card/events
2022-03-19 09:42:23 WARNING (MainThread) [aioshelly.block_device] device 192.168.1.235 initialize error - TimeoutError()
2022-03-19 09:42:23 WARNING (MainThread) [aioshelly.block_device] device 192.168.1.86 initialize error - TimeoutError()
2022-03-19 09:42:24 WARNING (MainThread) [homeassistant.components.sensor] Updating file sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:42:24 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalwijzer sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:42:24 WARNING (MainThread) [homeassistant.components.sensor] Updating nederlandse_spoorwegen sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:42:24 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/pnbruckner/ha-composite-tracker/events
2022-03-19 09:42:24 ERROR (MainThread) [homeassistant.components.github] An error occurred while processing new events - Timeout of 20 reached while waiting for https://api.github.com/repos/andrey-git/home-assistant-custom-ui/events

and summarized on Warning:

2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of counter is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of feedreader is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.components.scene] Setup of scene platform homeassistant is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2022-03-19 09:40:08 WARNING (MainThread) [homeassistant.setup] Setup of rest is taking over 10 seconds.
2022-03-19 09:40:11 WARNING (MainThread) [homeassistant.setup] Setup of python_script is taking over 10 seconds.
2022-03-19 09:40:11 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2022-03-19 09:40:11 WARNING (MainThread) [homeassistant.components.button] Setup of button platform mqtt is taking over 10 seconds.
2022-03-19 09:40:11 WARNING (MainThread) [homeassistant.components.light] Setup of light platform group is taking over 10 seconds.
2022-03-19 09:40:11 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform group is taking over 10 seconds.
2022-03-19 09:40:12 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Ha dev version' for version integration not ready yet: Timeout of 10 seconds was reached while fetching version for supervisor; Retrying in background
2022-03-19 09:40:12 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Ha stable version' for version integration not ready yet: Timeout of 10 seconds was reached while fetching version for supervisor; Retrying in background
2022-03-19 09:40:12 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Ha beta version' for version integration not ready yet: Timeout of 10 seconds was reached while fetching version for supervisor; Retrying in background
2022-03-19 09:40:12 WARNING (MainThread) [homeassistant.components.alarm_control_panel] Setup of alarm_control_panel platform manual is taking over 10 seconds.
2022-03-19 09:40:14 WARNING (MainThread) [homeassistant.components.media_player] Setup of media_player platform mpd is taking over 10 seconds.
2022-03-19 09:40:14 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Ha Rpi4' for forecast_solar integration not ready yet: Server disconnected; Retrying in background
2022-03-19 09:40:23 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Dorm Studenten' for shelly integration not ready yet: Timeout during device setup; Retrying in background
2022-03-19 09:40:24 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Tester' for shelly integration not ready yet: Timeout during device setup; Retrying in background
2022-03-19 09:40:24 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Symfonisk dining' for shelly integration not ready yet: Timeout during device setup; Retrying in background
2022-03-19 09:40:27 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Rotterdam' for luftdaten integration not ready yet: Did not receive sensor data from Sensor.Community; Retrying in background
2022-03-19 09:40:30 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Roosendaal' for luftdaten integration not ready yet; Retrying in background
2022-03-19 09:40:30 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Amsterdam Oost' for luftdaten integration not ready yet; Retrying in background
2022-03-19 09:40:30 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Rotterdam' for luftdaten integration not ready yet; Retrying in background
2022-03-19 09:40:30 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Tilburg' for luftdaten integration not ready yet; Retrying in background
2022-03-19 09:40:30 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Amsterdam Oost' for luftdaten integration not ready yet; Retrying in background
2022-03-19 09:40:30 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Tilburg' for luftdaten integration not ready yet; Retrying in background
2022-03-19 09:40:30 WARNING (MainThread) [coap] Received Type.ACK from <aiocoap.transports.tinydtls.DTLSClientConnection object at 0x7f747b97f0>, but could not match it to a running exchange.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform file is taking over 10 seconds.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform mqtt is taking over 10 seconds.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform command_line is taking over 10 seconds.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform nederlandse_spoorwegen is taking over 10 seconds.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform nmbs is taking over 10 seconds.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform darksky is taking over 10 seconds.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform darksky is taking over 10 seconds.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform waqi is taking over 10 seconds.
2022-03-19 09:40:31 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform command_line is taking over 10 seconds.
2022-03-19 09:41:30 WARNING (MainThread) [homeassistant.components.buienradar.util] Unable to retrieve json data from Buienradar(Msg: , status: None,)
2022-03-19 09:41:52 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform version is taking over 10 seconds.
2022-03-19 09:41:52 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform version is taking over 10 seconds.
2022-03-19 09:41:54 WARNING (MainThread) [homeassistant.components.sensor] Updating file sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:41:54 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalwijzer sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:41:54 WARNING (MainThread) [homeassistant.components.sensor] Updating nederlandse_spoorwegen sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:41:58 WARNING (MainThread) [aioshelly.block_device] device 192.168.1.235 initialize error - TimeoutError()
2022-03-19 09:42:01 WARNING (MainThread) [hass_nabucasa.cloud_api] Fetched https://remotestate.nabucasa.com/request_sync (500)
2022-03-19 09:42:02 WARNING (MainThread) [aioshelly.block_device] device 192.168.1.86 initialize error - TimeoutError()
2022-03-19 09:42:02 WARNING (MainThread) [homeassistant.components.buienradar.util] Unable to retrieve json data from Buienradar(Msg: , status: None,)
2022-03-19 09:42:12 WARNING (MainThread) [homeassistant.components.binary_sensor] Updating workday binary_sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:42:23 WARNING (MainThread) [aioshelly.block_device] device 192.168.1.235 initialize error - TimeoutError()
2022-03-19 09:42:23 WARNING (MainThread) [aioshelly.block_device] device 192.168.1.86 initialize error - TimeoutError()
2022-03-19 09:42:24 WARNING (MainThread) [homeassistant.components.sensor] Updating file sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:42:24 WARNING (MainThread) [homeassistant.components.sensor] Updating afvalwijzer sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:42:24 WARNING (MainThread) [homeassistant.components.sensor] Updating nederlandse_spoorwegen sensor took longer than the scheduled update interval 0:00:30
2022-03-19 09:42:31 WARNING (MainThread) [aioshelly.block_device] device 192.168.1.147 initialize error - TimeoutError()

and only Wifi devices are the Shelly's.

debugpy: initially startup fine, but wont make to through the startup process, and causes an auto-restart.... I did save the log so if at all useful Id be glad to share (in DM?)

bdraco commented 2 years ago

@Mariusthvdb The exception in your log above is something else. I opened https://github.com/home-assistant/core/issues/68388

mvdwetering commented 2 years ago

I have also been seeing seemingly random connectivity issues with Harmony (although not sure if it started with the 2020.3 release). I enabled the debugpy: (actually I already had it with start:false, so just called the service to activate. Maybe this avoids the crash that some people had?)

Anyways I see a lot of logging. Looks like roughly a line every other second. Just an excerpt which seems to be mostly repeating.

2022-03-20 18:46:40 WARNING (MainThread) [asyncio] Executing <Handle AbstractTransportDispatcher._cbFun(<pysnmp.carri...x7f480323ec40>, ('192.168.178.6', 161), b"0\x82\x02\x...0\x01\xd1\xff") created at /usr/local/lib/python3.9/site-packages/pysnmp/carrier/asyncio/dgram/base.py:65> took 0.115 seconds
2022-03-20 18:46:42 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-557142' coro=<EntityPlatform._update_entity_states() running at /usr/src/homeassistant/homeassistant/helpers/entity_platform.py:735> wait_for=<_GatheringFuture pending cb=[<TaskWakeupMethWrapper object at 0x7f47f4232d60>()] created at /usr/local/lib/python3.9/asyncio/tasks.py:706> created at /usr/src/homeassistant/homeassistant/core.py:442> took 0.484 seconds
2022-03-20 18:46:43 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f595fc10>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.116 seconds
2022-03-20 18:46:43 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f9246940>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.111 seconds
2022-03-20 18:46:46 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f56f7130>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.104 seconds
2022-03-20 18:46:47 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47fa808400>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.211 seconds
2022-03-20 18:46:49 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f8d0d4f0>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.104 seconds
2022-03-20 18:46:51 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f5a472b0>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.184 seconds
2022-03-20 18:46:55 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f5c7e730>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.155 seconds
2022-03-20 18:47:02 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47fa730790>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.138 seconds
2022-03-20 18:47:03 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f650b100>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.214 seconds
2022-03-20 18:47:04 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f480a386ac0>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.195 seconds
2022-03-20 18:47:05 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f4232df0>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.132 seconds
2022-03-20 18:47:06 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-557771' coro=<HueSyncBoxMediaPlayerEntity.async_update() running at /config/custom_components/huesyncbox/media_player.py:115> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f47f41ca130>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424> cb=[_wait.<locals>._on_completion() at /usr/local/lib/python3.9/asyncio/tasks.py:513] created at /usr/src/homeassistant/homeassistant/core.py:474> took 0.161 seconds
2022-03-20 18:47:06 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f480106adc0>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.282 seconds
2022-03-20 18:47:07 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-91961' coro=<APIConnection._read_loop() running at /usr/local/lib/python3.9/site-packages/aioesphomeapi/connection.py:476> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f480106adc0>()] created at /usr/local/lib/python3.9/asyncio/base_events.py:424>> took 0.253 seconds

Most lines seem to be related to Esphome. I will have a look at the huesyncbox line as that is the custom_integration I maintain :) I guess the one with pysnmp is the Brother integration (judging from the IP address)

From what I understand these warnings are printed when some code is blocking the eventloop for a long time (>100ms?). Blocking the eventloop is bad and can cause issues for other integrations that do not get called in time.

Should I create seperate tickets for each of these warnings?

hammermcg commented 2 years ago

Hi there, I seem to be suffering a similar issue with Heartbeat timeout to all of my Chromecast devices (even to a group of devices Party). Should I open a separate issue? This is happening once per minute - but not all Chromecast devices every minute, though all do become unavailable. (I've got about 8 chromecast devices)

Logger: pychromecast.socket_client Source: /usr/local/lib/python3.9/site-packages/pychromecast/socket_client.py:672 First occurred: May 21, 2022, 11:58:42 AM (6856 occurrences) Last logged: 11:21:15 AM

[Guest Mini(192.168.1.208):8009] Heartbeat timeout, resetting connection [Outdoor Speakers(192.168.0.150):8009] Heartbeat timeout, resetting connection [Party(192.168.0.150):32112] Heartbeat timeout, resetting connection [Outdoor Mini(192.168.1.49):8009] Heartbeat timeout, resetting connection [Theatre Chromecast(192.168.1.144):8009] Heartbeat timeout, resetting connection

And

Logger: pychromecast.socket_client Source: /usr/local/lib/python3.9/site-packages/pychromecast/socket_client.py:396 First occurred: May 21, 2022, 11:58:46 AM (670 occurrences) Last logged: 11:20:04 AM

[Outdoor Mini(192.168.1.49):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.49', 8009)), retrying in 5.0s [Kitchen Display(192.168.0.24):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.0.24', 8009)), retrying in 5.0s [Theatre Chromecast(192.168.1.144):8009] Failed to connect to service ServiceInfo(type='mdns', data='Chromecast-Ultra-34d10942b2741d7063f77e4832332137._googlecast._tcp.local.'), retrying in 5.0s [Guest Mini(192.168.1.208):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.208', 8009)), retrying in 5.0s [Party([::ffff:c0a8:96]):32112] Failed to connect to service ServiceInfo(type='host', data=('[::ffff:c0a8:96]', 32112)), retrying in 5.0s

From System Health,

Version core-2022.5.4 Installation Type Home Assistant OS Development false Supervisor true Docker true User root Virtual Environment false Python Version 3.9.9 Operating System Family Linux Operating System Version 5.15.38 CPU Architecture x86_64 Timezone Australia/Sydney Home Assistant Community Store GitHub API ok GitHub Content ok GitHub Web ok GitHub API Calls Remaining 5000 Installed Version 1.24.5 Stage running Available Repositories 1057 Downloaded Repositories 20 Home Assistant Cloud Logged In true Subscription Expiration June 21, 2022, 10:00 AM Relayer Connected true Remote Enabled true Remote Connected true Alexa Enabled false Google Enabled true Remote Server ap-southeast-1-0.ui.nabu.casa Reach Certificate Server ok Reach Authentication Server ok Reach Home Assistant Cloud ok Home Assistant Supervisor Host Operating System Home Assistant OS 8.0 Update Channel stable Supervisor Version supervisor-2022.05.2 Docker Version 20.10.14 Disk Total 48.5 GB Disk Used 24.1 GB Healthy true Supported true Board ova Supervisor API ok Version API ok Installed Add-ons Mosquitto broker (6.1.2), DahuaVTO2MQTT (1.0.14), Spotify Connect (0.11.0), InfluxDB (4.4.1), Grafana (7.5.2), Z-Wave JS (0.1.58), Terminal & SSH (9.4.0), Studio Code Server (5.0.4), Node-RED (11.1.2), Home Assistant Google Drive Backup (0.107.2), Samba share (9.6.1), CEC Scanner (3.0), SSH & Web Terminal (10.1.3), Check Home Assistant configuration (3.10.0), Glances (0.15.0), WireGuard (0.6.0) Dashboards Dashboards 8 Resources 15 Views 37 Mode storage

Mbussie commented 2 years ago

Hello, I have the same problems and that give the most problems when I use a group of nest speaker, is it Google, my replaced router or Home Assistant? My Guess it is Google... All the loudspeakers are working when you speak to them, but you can not always use them to play music in a group. A reset of the speakers helps only a little while...

cast 1

github-actions[bot] commented 2 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.