Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Philips Hue integration not properly reporting light states #61819

Closed
espo73 opened this issue Dec 14, 2021 · 28 comments · Fixed by home-assistant-libs/aiohue#88
Closed

Philips Hue integration not properly reporting light states #61819

espo73 opened this issue Dec 14, 2021 · 28 comments · Fixed by home-assistant-libs/aiohue#88
Assignees

Comments

@espo73
Copy link

espo73 commented Dec 14, 2021

The problem

The hue integration isn't reporting the proper current state of lights. The light.turn_on or light.turn_off calls work properly, but the toggle does not since the state isn't represented properly in the system. Restarting the integration does get the correct current state, but does not then update when I change a light state. Changing state in the UI I can see the state change (for instance turning the light off) and the light does actually turn off, however, the display flips back to ON a sec or so later (but the light does stay off).

What version of Home Assistant Core has the issue?

2021.12.1

What was the last working version of Home Assistant Core?

1021.11.5

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/

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Nothing appears in the logs that I can find.

Additional information

No response

@probot-home-assistant
Copy link

hue documentation
hue source
(message by IssueLinks)

@probot-home-assistant
Copy link

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!
(message by CodeOwnersMention)

@marcelveldt
Copy link
Member

Please have a look at your logfile if there are any errors reported.
Also, what bridge version do you have ? A V2 version (square shape) ?

@espo73
Copy link
Author

espo73 commented Dec 14, 2021

It's a V2 Hub. I looked again in the log file and could not find any errors. It also appears to be a somewhat random issue. Most lights do appear to report properly right now when I went back to repo the issue, but there was at least 1 that was not. They all do report properly in the Hue app.

@marcelveldt
Copy link
Member

Ok, please have a look if you find more details, like:

  • Is it a regular light or a "grouped light" created for a zone or room ?
  • If regular light, what brand/model

Are there any connectivity issues reported ? You can see this in the Hue app --> light settings
You can also enable the (default hidden/disabled) zigbee connectivity sensor for the device in HA

@sylphaenos
Copy link

sylphaenos commented Dec 14, 2021

I'm experiencing the same issue on a V2 bridge with various (Hue brand) lights: Hue Go, LCA005 bulbs (new), LCT001 bulbs (old), and some other bulb models like LCT007 & LCB001.

While "stuck" in either on or off state, the bulbs still function & report their state correctly in the Hue app, and their corresponding zigbee connectivity sensor entity reports "connected" in Home Assistant. HA sees them as available, but on (when really off), or vice versa.

There are no relevant messages in the log, I assume because Home Assistant doesn't know anything is wrong. Reloading the integration or restarting HA seems to fix it for a short time, but within a few hours bulbs start getting "stuck" again.

Edit: I think both individual bulbs and entire rooms/zones have gotten stuck but will keep an eye on it to be sure. Haven't seen any connectivity issues reported in the Hue app. Also, thank you very much for your work on the Hue integration!

@espo73
Copy link
Author

espo73 commented Dec 14, 2021

For me they are all Phillips branded lights. I have the lights in some rooms and 2 in a one zone. I use both the regular lights and the room/zone entities for control. I just went in and disabled all of the new scenes that got pulled in from the integration (had over 50 of those created as I have over 30 devices and about 10 different rooms/zones) and it seems to have stabilized at least for now (after a system restart).

@marcelveldt
Copy link
Member

OK, this means that no events are coming in from the bridge. The bridge streams events about state changes.
If that streaming of events fail for whatever reason, this is the result. So now we'll have to find out why that happens.
First thing to look is the HA logfile, are there any errors/warnings in there ?

Second thing is eliminate all other apps that are contacting the bridge. There are a few really bad behaving apps out there that poll the bridge at insane intervals which it just can't handle.

A few that come to mind:

  • Hue plugin in Homematic IP CCU
  • Node Red plugin for Hue

Or any other app/platform that connects to the Hue bridge may interfere.
Also check if the bridge has all updates applied.

There is a guard in the code that whenever it may happen that the eventstream with the bridge gets lost, it will be reconnected if there are no events received in 30 minutes. So would be interesting to know if it self heals after 30 minutes.

@marcelveldt
Copy link
Member

For me they are all Phillips branded lights. I have the lights in some rooms and 2 in a one zone. I use both the regular lights and the room/zone entities for control. I just went in and disabled all of the new scenes that got pulled in from the integration (had over 50 of those created as I have over 30 devices and about 10 different rooms/zones) and it seems to have stabilized at least for now (after a system restart).

Should not matter. The scenes will not have impact on performance or whatever.
Disabling only hides them in HA. If you don't want them, delete them in the Hue app.

@sylphaenos
Copy link

To be clear, while this is happening, other lights still function normally in Home Assistant. So it seems like the bridge is delivering some events successfully, but not for all bulbs.

The only apps I'm using are Home Assistant and the official Hue app (on 2-3 devices), no other apps/plugins or Node Red. The Home Assistant integration doesn't appear to self-heal even after leaving it alone for many hours–restarting it was the only fix.

@marcelveldt
Copy link
Member

To be clear, while this is happening, other lights still function normally in Home Assistant. So it seems like the bridge is delivering some events successfully, but not for all bulbs.

The only apps I'm using are Home Assistant and the official Hue app (on 2-3 devices), no other apps/plugins or Node Red. The Home Assistant integration doesn't appear to self-heal even after leaving it alone for many hours–restarting it was the only fix.

Ah, OK, it only happens for a few lights then ? So some lights keep working? That's interesting.
Is there any clue if it's always the same lights or completely random?

@sylphaenos
Copy link

I've seen it happen on most of my lights/rooms, but the Hue Gos are the most automated lights in the house so it's most noticeable there. They have the latest firmware and so does the bridge, but some of my other bulbs didn't–updating now.

It's probably also worth mentioning that I recently went from ~20 to 38 lights on 1 bridge. Even on 2021.11.5 and earlier this started causing (very rare) issues with the oldest bulb, LCT001, reporting the wrong state after an automation. This new sticking issue happens on all models and much more frequently though so I don't think it's the same issue, but maybe also congestion related.

@marcelveldt
Copy link
Member

You could try to enable debug logging for the hue component. That way you will see every event in the eventlog.
After that switch a light on/off and check if the event comes in.

@espo73
Copy link
Author

espo73 commented Dec 14, 2021

For me the bridge and all of my lights do have the latest firmware on them also. I don't have any third-party apps hitting the bridge, but I do have a custom app polling the bridge once per minute to get state information (and that doesn't appear to be throwing any errors).

@espo73
Copy link
Author

espo73 commented Dec 14, 2021

You could try to enable debug logging for the hue component. That way you will see every event in the eventlog. After that switch a light on/off and check if the event comes in.

Do you have a reference to be able to do this and how to get to the event log when running Home Assistant OS (I'm also running this headless). Not much experience here. And BTW it started to do it again (so it was stable for an hour after restart) and it's pretty much all the lights right now.

@picotrain77
Copy link

I also have been experiencing some odd hue issues ever since the update.

All my bulbs are hue, all motion sensors are hue, it's a V2 bridge and everything is up to date FW. Everything is paired directly to hue bridge.

The hue system has been the most reliable system in my house and I can't recall every having a single issue with it directly and or via HA.

However since updating to 2021.12 I am experiencing issues natively in hue and in HA.

For example, came home in the dark and outside lights did not activate. Hue detected motion and also reported it to HA, however hue didn't turn the lights on...first time this has ever happened, but I assume this is purely a hue issue.

I then find intermittently that if I call light turn on or off it's not actioned, but if I use hue app and trigger the lights the light always actions and HA instantly represents this change.

Restarting HA seems to rectify the issue but like others it seems to only fix it for a short period of time.

I can't understand any link with updating HA use use V2 api and hue itself messing around natively but it's a massive coincidence as the system has been faultless for years until now.

If I can help debug please tell me what I can help with.

Thanks for all your work, it's very much appreciated

@marcelveldt
Copy link
Member

marcelveldt commented Dec 14, 2021

Strange that these issues are reported as many others are experiencing the opposite, a more reliable setup with instant updates and fast response times. I have a pretty large Hue setup myself too and running this new version for almost 2 months now without a single issue.

That said, there could be a small oversight or edge case somewhere. Its software so those things may happen unfortunately. At the same time Signify launched a bunch of updates, pushing towards this new V2 API. So there might as well be some bugs in the Hue bridge atm, like for some of the remote switches.

Try to reload the integration if it gets stuck instead of restarting HA. You can do that by pressing the 3 dots on the Hue "card" in Settings -> Integrations.

And, I keep repeating this, please look at the logs. There might be a clue in there.
If you system gets in a stuck state, Go to settings and view the full log. Is there some error or warning in there regarding Hue? if so, share it with me here or on discord PM.

Enabling debug log for the Hue component is explained here:
https://www.home-assistant.io/integrations/logger/

So you will need (something like) this in your configuration:

Schermafbeelding 2021-12-14 om 23 30 28

@sylphaenos
Copy link

sylphaenos commented Dec 14, 2021

OK, I just had a light automation fail after the initial post-restart period where everything works correctly. This automation turns a Hue Go on for 3 seconds, then off.

Here are the debug logs from when the automation ran successfully 30 minutes ago:

Click to expand
2021-12-14 16:00:00 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_go_2
2021-12-14 16:00:00 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable
2021-12-14 16:00:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_go_2
2021-12-14 16:00:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable
2021-12-14 16:00:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_go_2
2021-12-14 16:00:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable
2021-12-14 16:00:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable
2021-12-14 16:00:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_go_2
2021-12-14 16:00:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable
2021-12-14 16:00:04 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable
2021-12-14 16:00:14 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_go_2
2021-12-14 16:00:14 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable

It ran again just now and was recorded in the logbook. The light turned on, but not off. This time there were no Hue logs at all, so we can assume the bridge didn't send any events for this light change. Home Assistant also didn't record any state changes for the light in the logbook–just the automation occurrence.

Editing to add the YAML:

Automation
alias: Water reminder
description: ''
trigger:
  - platform: time_pattern
    minutes: /30
action:
  - service: script.notify_hue_go_2
    data:
      color: deepskyblue
      brightness: 40
      delay: 3
mode: single
Notify script
alias: Notify Hue Go 2
variables:
  color: linen
  brightness: 35
  delay: 1
sequence:
  - choose:
      - conditions:
          - condition: state
            entity_id: input_boolean.notifying_hue_go_2
            state: 'off'
        sequence:
          - service: input_boolean.turn_on
            target:
              entity_id: input_boolean.notifying_hue_go_2
          - service: script.save_portable_light_state
  - service: light.turn_on
    target:
      entity_id: light.hue_go_2
    data_template:
      brightness_pct: '{{ brightness }}'
      color_name: '{{ color }}'
  - delay:
      hours: 0
      minutes: 0
      seconds: '{{ delay }}'
      milliseconds: 0
  - choose:
      - conditions:
          - condition: state
            entity_id: input_boolean.notifying_hue_go_2
            state: 'on'
        sequence:
          - service: script.restore_portable_light_state
          - service: input_boolean.turn_off
            target:
              entity_id: input_boolean.notifying_hue_go_2
mode: restart
icon: hue:go

@sylphaenos
Copy link

I haven't gotten any new Hue log messages since this happened, while toggling lights through the Hue app or Home Assistant.

HA can still control lights using light.turn_off and light.turn_on, and those changes are reflected in entity state. Using light.toggle works once (except on the Hue Go, which is already stuck) but doesn't reflect the change in HA, so subsequent light.toggle calls don't work at all since HA state is now out of sync with reality.

@sylphaenos
Copy link

sylphaenos commented Dec 15, 2021

I actually just received a bunch of Hue debug messages again–all at once, for lights I've been toggling while the bridge wasn't reporting, so it does seem to reconnect after a period of time.

Click to expand debug logs
2021-12-14 16:58:54 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.ikea_lamp
2021-12-14 16:58:54 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:58 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.spotlight_2
2021-12-14 16:58:58 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.spotlight_2
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.ikea_lamp
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.ikea_lamp
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_top
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_top
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_middle
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_middle
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_bottom
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_bottom
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.spotlight_1
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.spotlight_1
2021-12-14 16:58:59 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.spotlight_2
2021-12-14 16:59:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.spotlight_2
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.ikea_lamp
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.ikea_lamp
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_top
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_top
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_middle
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_middle
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_bottom
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.floor_lamp_bottom
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.spotlight_1
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.spotlight_1
2021-12-14 16:59:03 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office

The same light automation ran again but still left the Hue Go in a stuck state, reporting off but actually on. The log this time was shorter, and the last 2 messages arrived much later:

2021-12-14 17:00:00 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_go_2
2021-12-14 17:00:00 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable
2021-12-14 17:00:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_go_2
2021-12-14 17:00:01 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable
2021-12-14 17:01:55 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_go_2
2021-12-14 17:01:55 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.portable

After this run, I manually turned off the light to sync up Home Assistant's state with the real light state, and the automation works again. So it seems like lights that get out of sync while the bridge stops reporting don't update to the correct state in HA even after the bridge is back.

@espo73
Copy link
Author

espo73 commented Dec 15, 2021

Been running with degbug for about 4 hours now and just saw all messages from Hue stop for about 30 minutes:

2021-12-14 19:31:12 DEBUG (MainThread) [homeassistant.components.hue.bridge.light_level] Received status update for sensor.pantry_sensor_light_level
2021-12-14 19:31:12 DEBUG (MainThread) [homeassistant.components.hue.bridge.light_level] Received status update for switch.pantry_sensor_illuminance
2021-12-14 19:34:39 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.front_2
2021-12-14 19:36:08 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.front_2
2021-12-14 19:36:45 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.bedroom_closet_sensor_temperature
2021-12-14 19:38:58 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.hue_outdoor_motion_sensor_1_temperature
2021-12-14 19:52:05 ERROR (MainThread) [aioharmony.hubconnector_websocket] 192.168.1.76: Connection timed out for hub 16884416
2021-12-14 20:11:41 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.bedroom_closet_sensor_temperature
2021-12-14 20:15:08 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.office_sensor_temperature
2021-12-14 20:15:46 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.pantry_sensor_temperature
2021-12-14 20:20:07 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.office_sensor_temperature
2021-12-14 20:23:53 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.hue_outdoor_motion_sensor_1_temperature
2021-12-14 20:25:07 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.office_sensor_temperature
2021-12-14 20:26:13 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.front_2

However, when I go and change the state of a light now, I don't see any status messages coming back from that light. The only light status I get is for one of the lights that reconnected (that particular light does lose connection occasionally) I also thought that maybe the harmony controller timeout was something but looked back earlier in the log and that didn't cause any disruption in the Hue messages a couple of times in the past (the harmony controller isn't in a good wifi spot in my house).

Went it and reloaded the integration and the lights then got the proper current state. Toggled one of them a few times and now status messages from the light are coming in.

2021-12-14 20:26:13 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.front_2
2021-12-14 20:38:19 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_white_lamp_1
2021-12-14 20:38:19 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 20:38:20 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 20:38:43 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_white_lamp_1
2021-12-14 20:38:43 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 20:38:44 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 20:38:46 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.hue_white_lamp_1
2021-12-14 20:38:46 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 20:38:47 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.office
2021-12-14 20:38:51 DEBUG (MainThread) [homeassistant.components.hue.bridge.temperature] Received status update for sensor.hue_outdoor_motion_sensor_1_temperature

So just reloading the integration did seem to solve the problem for me at this point.

@majkers
Copy link

majkers commented Dec 15, 2021

I don't know if I should create new issue or is it related? I have IKEA bulbs connected to hue bridge v2. and if they are switch off (totally by a wall switch) they do not turn their state to unavailable but stay on.... I "can" turn them on and off (ie. change their state) from Home Assistant even though they are unavailable. Everything wokrs ok for Philips bulbs.

Related to this #61603 ?

@Nutti85
Copy link

Nutti85 commented Dec 15, 2021

Don't know if it's related but my GF woke up in the middle of the night with my Hue play bar flashing at full brightness right in her face. I have no automations running on those lights. They are only controlled manually through the Hue app and HA.

@marcelveldt
Copy link
Member

Don't know if it's related but my GF woke up in the middle of the night with my Hue play bar flashing at full brightness right in her face. I have no automations running on those lights. They are only controlled manually through the Hue app and HA.

No, that is not related

@marcelveldt
Copy link
Member

I think I've just found the issue. It's related to network issues. If something happens on your network causing the connection to the bridge to be unavailable for a short time, the connection will be lost. It will auto retry but if the connection issue isn't still resolved in that retry it gets stuck. It's waiting forever on the reconnect attempt without timing out. I'm going to fix that bug and add some warnings if this happens too often. At the same time my advice would be to have a look at your network topology why the connection gets lost from time to time.

@marcelveldt marcelveldt mentioned this issue Dec 15, 2021
22 tasks
@majkers
Copy link

majkers commented Dec 15, 2021

I think You did not :( I've just updated to 2012.2 and now all my light (not only IKEA ones) ar wrongly reporting states. I will report new issue with more info... #61926
EDIT. For now I will do more tests. Looks like quick toggling of light via HA (turn on and off) leaves light states as ON and updated after a long while to OFF

@smonesi
Copy link

smonesi commented Dec 15, 2021

I have the same issue, lights go out of sync very often.

It looks like events are lost, and while some event doesn't cause much trouble (eg. a light changing color) other events (eg. a light turning on or off) cannot be easily recovered and the light remains out of sync even after other events on the same light are received. Maybe a change in color should always result in the light being considered as turned on?

I enabled debug logging both on homeassistant.components.hue and on aiohue and I got this:

Dec 15 20:25:10 fenix hass[1413777]: 2021-12-15 20:25:10 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.go_uno
Dec 15 20:25:10 fenix hass[1413777]: 2021-12-15 20:25:10 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.soggiorno
Dec 15 20:25:10 fenix hass[1413777]: 2021-12-15 20:25:10 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.divano_destra
Dec 15 20:25:10 fenix hass[1413777]: 2021-12-15 20:25:10 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.soggiorno
Dec 15 20:25:11 fenix hass[1413777]: 2021-12-15 20:25:11 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Disconnected from EventStream () - Reconnect will be attempted in 4 seconds
Dec 15 20:25:15 fenix hass[1413777]: 2021-12-15 20:25:15 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Connected to EventStream
Dec 15 20:25:21 fenix hass[1413777]: 2021-12-15 20:25:21 DEBUG (MainThread) [homeassistant.components.hue.bridge.light] Received status update for light.go_uno
Dec 15 20:25:21 fenix hass[1413777]: 2021-12-15 20:25:21 DEBUG (MainThread) [homeassistant.components.hue.bridge.grouped_light] Received status update for light.soggiorno

Also, without touching any light for a while:

Dec 15 20:26:26 fenix hass[1413777]: 2021-12-15 20:26:26 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Disconnected from EventStream () - Reconnect will be attempted in 4 seconds
Dec 15 20:26:30 fenix hass[1413777]: 2021-12-15 20:26:30 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Connected to EventStream
Dec 15 20:26:41 fenix hass[1413777]: 2021-12-15 20:26:41 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Disconnected from EventStream () - Reconnect will be attempted in 4 seconds
Dec 15 20:26:45 fenix hass[1413777]: 2021-12-15 20:26:45 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Connected to EventStream
Dec 15 20:26:56 fenix hass[1413777]: 2021-12-15 20:26:56 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Disconnected from EventStream () - Reconnect will be attempted in 4 seconds
Dec 15 20:27:00 fenix hass[1413777]: 2021-12-15 20:27:00 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Connected to EventStream
Dec 15 20:27:11 fenix hass[1413777]: 2021-12-15 20:27:11 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Disconnected from EventStream () - Reconnect will be attempted in 4 seconds
Dec 15 20:27:15 fenix hass[1413777]: 2021-12-15 20:27:15 DEBUG (MainThread) [aiohue.v2[192.168.1.21].events] Connected to EventStream

Basically, I have lots of disconnections/reconnections and if an event happens in the 4 seconds between those two logs, a status is lost forever.

Apart from understanding why I got so many disconnections, shouldn't the state of the lights be refreshed upon reconnecting to avoid any potential issue?

I never had issues with HA 2021.11 (apart from some noticeable delay, sometimes, between the actual status of the light and the status reported by HA), nor with hue lights in general (22 lights, 5 sensors and 3 buttons).

@marcelveldt
Copy link
Member

Please continue the conversation in #61926

@smonesi thanks for you debug log! I had a feeling that the connection gets lost, that's why I added the debug log of (re)connects. Now is the question why the connection gets lost

@marcelveldt marcelveldt mentioned this issue Dec 15, 2021
22 tasks
@github-actions github-actions bot locked and limited conversation to collaborators Jan 14, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

8 participants