Not connected with Hass.io| Due to Hue? Asyncio.timeouterror

[Mariusthvdb]

Home Assistant release with the issue:

0.69.1, but started with updating to 0.68

Last working Home Assistant release (if known):
0.65

Operating environment (Hass.io/Docker/Windows/etc.):

Pi3 running Hassio
Component/platform:

Config:
Hue:
Hassio:

Description of problem:

upon practically each boot i get this error in the logs, and Hassio wont connect. Every once in a while there's a successful Hassio startup. Been like since the update to .68, and I have since tried to disable all components to see if theres a consistent change in Hassio setting up, but unfortunately I can not report any positive results. Out of ideas how to debug or change this. Though the errors in the logs are only at the end where Hassio is being setup, it always is at this point Hue complains about not being able to reach the host (which is there and is reachable for sure). Disabling Hue, both manually, and by discovery doesn't make a difference though.

2018-05-23 11:07:01 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/ping request
2018-05-23 11:07:02 ERROR (MainThread) [homeassistant.components.hassio] Not connected with Hass.io

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

Traceback (if applicable):
No idea if this is related, but it is the only thing besides the timing errors showing in the log

2018-05-23 11:22:37 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/web_protocol.py", line 381, in start
    resp = await self._request_handler(request)
  File "/usr/lib/python3.6/site-packages/aiohttp/web_app.py", line 322, in _handle
    resp = await handler(request)
  File "/usr/lib/python3.6/site-packages/aiohttp/web_middlewares.py", line 88, in impl
    return await handler(request)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/http/static.py", line 68, in staticresource_middleware
    return await handler(request)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/http/real_ip.py", line 27, in real_ip_middleware
    return await handler(request)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/http/ban.py", line 68, in ban_middleware
    return await handler(request)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/http/auth.py", line 54, in auth_middleware
    return await handler(request)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/http/view.py", line 104, in handle
    result = await result
  File "/usr/lib/python3.6/site-packages/homeassistant/components/websocket_api.py", line 230, in get
    return await ActiveConnection(request.app['hass'], request).handle()
  File "/usr/lib/python3.6/site-packages/homeassistant/components/websocket_api.py", line 422, in handle
    await self._writer_task
  File "/usr/lib/python3.6/site-packages/homeassistant/components/websocket_api.py", line 264, in _writer
    await self.wsock.send_json(message, dumps=JSON_DUMP)
  File "/usr/lib/python3.6/site-packages/aiohttp/web_ws.py", line 266, in send_json
    await self.send_str(dumps(data), compress=compress)
  File "/usr/lib/python3.6/site-packages/aiohttp/web_ws.py", line 255, in send_str
    await self._writer.send(data, binary=False, compress=compress)
  File "/usr/lib/python3.6/site-packages/aiohttp/http_websocket.py", line 609, in send
    return await self._send_frame(message, WSMsgType.TEXT, compress)
  File "/usr/lib/python3.6/site-packages/aiohttp/http_websocket.py", line 588, in _send_frame
    await self.protocol._drain_helper()
  File "/usr/lib/python3.6/asyncio/streams.py", line 211, in _drain_helper
    yield from waiter
BrokenPipeError: [Errno 32] Broken pipe

Additional information:

Seems related to the newly introduced Hue implementation , though I can not establish which causes which:

2018-05-23 11:07:00 WARNING (MainThread) [homeassistant.setup] Setup of hassio is taking over 10 seconds.
2018-05-23 11:07:01 ERROR (MainThread) [homeassistant.components.light.hue] Unable to reach bridge 192.168.1.212
2018-05-23 11:07:01 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/ping request
2018-05-23 11:07:02 ERROR (MainThread) [homeassistant.components.hassio] Not connected with Hass.io

after which the log is filled with timing errors and destroyed tasks:

2018-05-23 11:21:25 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:21:28 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:21:30 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:21:34 ERROR (MainThread) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2018-05-23 11:21:36 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:21:42 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:21:50 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:21:59 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:22:05 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:22:13 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:22:21 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2018-05-23 11:22:32 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting

[Mariusthvdb]

seems this https://github.com/home-assistant/home-assistant/blob/fa9b9105a813285dce9cdb12638e83188285b3bb/homeassistant/components/light/hue.py#L166 is the bit of code in hue.py causing the error in the log:

    try:
        with async_timeout.timeout(4):
            await api.update()
    except (asyncio.TimeoutError, aiohue.AiohueException):
        if not bridge.available:
            return

        _LOGGER.error('Unable to reach bridge %s', bridge.host)
        bridge.available = False

        for light_id, light in current.items():
            if light_id not in progress_waiting:
                light.async_schedule_update_ha_state()

        return

    if not bridge.available:
        _LOGGER.info('Reconnected to bridge %s', bridge.host)
        bridge.available = True

my hue bridge is available though, its the Hue implementation that apparently cant find it.

• How can bridge.available be changed so that it can find the Bridge?

• Secondly, can this be the origin of the supervisor/ping request timeout in the logs?

[balloob]

Your stack trace has nothing to do with either Hue or Hass.io. The stack trace is you refreshing your browser while there are pending messages.

Hue being unable to reach bridge once can be due to the internet not coming up yet when starting up.

I think that you are running too many things on your system, making the system unreasonable slow and it unable to send responses in time.

[Mariusthvdb]

HI,

Thanks for chiming in!

Hue being unable to reach bridge once can be due to the internet not coming up yet when starting up.

this is not only when starting up, it is happening constantly, Hue connecting and disconnecting> there's another thread on this same issue: #13949

and it started after Hue was implemented using asyncio, if thats what it's called.

maybe useful: Hue wont connect if a light, registered in the Hub, is physically without power. Not sure if this is related, but maybe the previously available option allow_unreachable could be reinstated in the new implementation?

Would you have any hints how to debug the supervisor ping request timeout? Ive tried setting debug levels in the logger, but see no extra info.
Is this something we can set? Maybe inspecting the ping request could give some answers.

Extra info for the config error leading to Hassio would be appreciated also, since no reference at all is to be found in the logs, and the system is quite responsive to be honest, no overloading at all.

btw, the bridge is truly available when this is happening, to all others devices, and also to Hassio itself, which can be concluded here:

Your stack trace has nothing to do with either Hue or Hass.io. The stack trace is you refreshing your browser while there are pending messages.

trying to fully understand what you're saying here, you mean I am manually hitting the refresh button, or do you mean the system itself is trying to refresh the browser.
If so, could the latter be caused by browser side customizations ? I ask because as we speak processor load is only 25%.

Too many things:

other than 4 daughters, there's only a tradfri and hue hub and a mqtt connected Zwave system. Should be less than a regular Home automation system?

Anyways, hope this helps in developing, thanks,
Marius

[balloob]

We should be able to handle 4 daughters for sure.

Can you check CPU usage? And what system are you running it on?

[Mariusthvdb]

lol.
Since 2 minutes, im on Hassio .70, running on a Pi3.
processor use has risen to 43%, hopefully that will calm down when all has settled.

i must add, that since having commented out the db_url to the MariaDB instance, and recorder using the homeassistant_v2.db again, processor use has been going up.

It is the second thing though i have to do to have Hassio appear again.
This is systematically and reproducible:

• Hue hub has to see all the lights

• recorder wont read the db_url and needs the default homeassistant_v2.db

• related: if Hassio shows all hue lights unavailable, a single interaction in the Hue app suffices to have everything reappear again. Seems it needs a heartbeat...

this all started when upgrading from .65.5 to .68 upward.

Haven't checked now with .70 yet, but will wait for .70.1 for the hue.hue_activate.scene to be operational again.

As an added test i created these rest sensors reading the availability of the Hue lamps as prove of their being live on the Hub:

Driveway being the Outdoors...

[balloobbot]

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 👍

[balloobbot]

This issue will be auto-closed because there hasn't been any activity for a few months. Feel free to open a new one if you still experience this problem 👍