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
73.78k stars 30.88k forks source link

philips hue integration: Attempts to (re)connect to bridge failed #81641

Closed jaroslawp closed 1 year ago

jaroslawp commented 2 years ago

The problem

Since few versions of home assistant the hue integration has problems connecting to the philips hue bridge: a reload of the integration helps to cure he problem - but only temporarily .. for few hours at most. This problem happened in the past (on all 2022.X versions of home assistant at least) but was far less frequent. I am aware of https://github.com/home-assistant/core/issues/73654 and https://github.com/home-assistant/core/issues/70086 which are marked as solved now .. but seems this may be little bit different (please see: Additional information)

What version of Home Assistant Core has the issue?

2022.11.1

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Philips Hue

Link to integration documentation on our website

https://www.home-assistant.io/integrations/hue/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

aiohttp.client_exceptions.ClientConnectorError: Cannot connect to host 192.168.1.249:443 ssl:False [Connect call failed ('192.168.1.249', 443)]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 200, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1744, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1781, in _execute_service
    await cast(Callable[[ServiceCall], Awaitable[None]], handler.job.target)(
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 208, in handle_service
    await service.entity_service_call(
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 678, in entity_service_call
    future.result()  # pop exception if have
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 943, in async_request_call
    await coro
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 715, in _handle_entity_call
    await result
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 570, in async_handle_light_on_service
    await light.async_turn_on(**filter_turn_on_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/hue/v2/light.py", line 211, in async_turn_on
    await self.bridge.async_request_call(
  File "/usr/src/homeassistant/homeassistant/components/hue/bridge.py", line 134, in async_request_call
    raise HomeAssistantError(
homeassistant.exceptions.HomeAssistantError: Request failed due connection error: Cannot connect to host 192.168.1.249:443 ssl:False
 [Connect call failed ('192.168.1.249', 443)]
2022-11-06 07:54:51.699 WARNING (MainThread) [aiohue.v2[192.168.1.249].events] 10 Attempts to (re)connect to bridge failed - This might be an indication of connection issues.

Additional information

It seems that for some reason hue bridge (v2 running 1.53.1953188020) is 'blacklisting' for some period of time the home assistant: when above problem occurs here is what I see:

from home assistant system:

wget -S --no-check-certificate https://192.168.1.249/api

Connecting to 192.168.1.249 (192.168.1.249:443) wget: can't connect to remote host (192.168.1.249): Connection refused

at the same time from other system on same network:

wget -S --no-check-certificate https://192.168.1.249/api

--2022-11-06 08:18:01-- https://192.168.1.249/api Connecting to 192.168.1.249:443... connected. WARNING: The certificate of ‘192.168.1.249’ is not trusted. WARNING: The certificate of ‘192.168.1.249’ hasn't got a known issuer.

[...]

2022-11-06 08:18:02 (48.6 MB/s) - ‘api’ saved [95]

this 'blacklist' lasts for ~ 1 minute and then again for ~ 1 minute I can perform above wget calls: the strange thing is it happens only from home assistant system (raspberry) I was not able to trigger this from my laptop ...

and after some more hammering of the bridge I was able to catch this error:

wget: server returned error: HTTP/1.1 429 Too Many Requests

and few requests later connection problem happened again.

I understand this may be a bug (or 'feature'...) of current bridge firmware - but perhaps introducing a (progressively growing) delay in aiohttp retries could make the integration more useable ? : at present when it gets in this state it does not seem to recover until I reload the integration in UI.

home-assistant[bot] commented 2 years ago

Hey there @balloob, @marcelveldt, mind taking a look at this issue as it has been labeled with an integration (hue) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `hue` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Change the title of the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign hue` Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)

hue documentation hue source (message by IssueLinks)

chrisjenx commented 1 year ago

I had to restart home assistant, guessing its a bug either with networking/intergration on HA. I could access Hue and PowerCycled it already, only rebooting HA fixed it (maybe a python network client bug?)

chrisjenx commented 1 year ago

Broke a couple of hours later, I just set both the EdgeMax and Hue to static IP's I'll feed back if that helps. Does seem to be a unique bug to HA & Hue.

marcelveldt commented 1 year ago

Do you have anything else running that does something with Hue ? Like homematic IP, Node red, custom integrations ? The Hue bridge indeed has a rate limiter but we keep to the limits, unless something else is also connecting to the bridge.

chrisjenx commented 1 year ago

Just Home Assistant, only other thing is me using the App, I would hope that doesn't add to the limits?

chrisjenx commented 1 year ago

For reference, rebooting the HA box (Virtual Machine) fixes it every time. Which makes me think it might be a HA/Python client bug not Hue? Unless Hue cuts off HA until it rebooted ? But it's all the same MAC and IP addresses so it's not like Hue would see a connection from a different client

marcous83 commented 1 year ago

I also had these errors in the log. Just setting the static Hue bridge IP in configuration.yaml seems to have solved it (of course you should make sure it is also set as static IP in your router).

Has been working flawlessly over two weeks now.

Op do 1 dec. 2022 19:08 schreef Christopher Jenkins < @.***>:

For reference, rebooting the HA box (Virtual Machine) fixes it every time. Which makes me think it might be a HA/Python client bug not Hue? Unless Hue cuts off HA until it rebooted ? But it's all the same MAC and IP addresses so it's not like Hue would see a connection from a different client

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/81641#issuecomment-1334157491, or unsubscribe https://github.com/notifications/unsubscribe-auth/ATAPA2HNNM57FJKMKJGTZPDWLDSTFANCNFSM6AAAAAARYJ63AQ . You are receiving this because you are subscribed to this thread.Message ID: @.***>

chrisjenx commented 1 year ago

Yeah looks like setting static IP address on the router and hue seems to have fixed it...

jaroslawp commented 1 year ago

Unfortunately this does not (entirely) fix it for me: I did set up static IP for the bridge in configuration.yaml, set up the bridge itself to use static ip (it was already getting a fixed ip assigned by dhcp before), performed bridge cleanup and power cycled it ...

it seems to be much better now:

jaroslawp commented 1 year ago

After some more testing it does not really fix it for me at all ... the connection to hue bridge seems to be dropping every few seconds (it stays connected for about maximum of ~ 1m40s or so before dropping again)... not sure how can I debug this further ?

2022-12-15 10:11:46.527 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Connected to EventStream
2022-12-15 10:13:09.170 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 2 seconds
2022-12-15 10:13:11.181 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 4 seconds
2022-12-15 10:13:15.185 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 6 seconds
2022-12-15 10:13:21.190 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 8 seconds
2022-12-15 10:13:29.196 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 10 seconds
2022-12-15 10:13:39.200 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 12 seconds
2022-12-15 10:13:49.006 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Error while sending keepalive: Cannot connect to host 192.168.1.249:443 ssl:False [Connect call failed ('192.168.1.249', 443)]
2022-12-15 10:13:51.230 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 14 seconds
2022-12-15 10:14:05.234 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 16 seconds
2022-12-15 10:14:21.252 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 18 seconds
2022-12-15 10:14:39.259 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 20 seconds
2022-12-15 10:14:39.259 WARNING (MainThread) [aiohue.v2[192.168.1.249].events] 10 Attempts to (re)connect to bridge failed - This might be an indication of connection issues.
2022-12-15 10:14:49.011 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Error while sending keepalive: Cannot connect to host 192.168.1.249:443 ssl:False [Connect call failed ('192.168.1.249', 443)]
2022-12-15 10:14:59.268 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 22 seconds
2022-12-15 10:15:21.273 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Disconnected from EventStream - Reconnect will be attempted in 24 seconds
2022-12-15 10:15:45.415 DEBUG (MainThread) [aiohue.v2[192.168.1.249].events] Connected to EventStream
marcelveldt commented 1 year ago

I have 2 Hue bridges and have never been able to reproduce this issue. So this could be related to the fact you're running in a virtual environment or you have some sort of rogue automation that is doing a lot of calls to Hue entities.

Our code is doing exactly what it should do: keep track of the connection and reconnect on failures.

BTW: Setting a static IP is no longer needed once this PR is merged and released: https://github.com/home-assistant/core/pull/85506

jaroslawp commented 1 year ago

@marcelveldt : I believe I have found what caused the problem for me: it was the Nmap Tracker integration - after disabling it all went back to normal: interesting fact - I had both nmap tracker and hue both running since more than a year but the issue started to appear only few months ago ... perhaps some hue bridge firmware update and/or home assistant change in between triggered it. Thanks!

marcelveldt commented 1 year ago

Well, in theory the nmap integration connects to devices in your network so in case of the Hue bridge this can affect the connection as Hue does not allow multiple simultane connections from the same IP since recent bridge versions.