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

ghost / unexpected hue dimmer events #99125

Closed
spasche opened this issue Aug 27, 2023 · 28 comments · Fixed by #113047
Closed

ghost / unexpected hue dimmer events #99125

spasche opened this issue Aug 27, 2023 · 28 comments · Fixed by #113047
Assignees

Comments

@spasche
Copy link

spasche commented Aug 27, 2023

The problem

Since 2023.8.x I'm getting unexpected hue dimmer events (i.e. events that trigger when the dimmers were not activated since several hours).
This happens very seldomly, such as 2-3 times a week.
I have automations that respond to dimmer events, that's why I notice some very strange behaviors (in addition to having lights turn on unexpectedly).
When the issue happens, I get many ghost dimmer events in a short timeframe.

What version of Home Assistant Core has the issue?

2023.8.4

What was the last working version of Home Assistant Core?

2023.7.x (not 100% sure though)

What type of installation are you running?

Home Assistant Container

Integration causing the issue

Philips Hue

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?

Yesterday the issue happened, and I can see the following errors in the logs:

2023-08-26 14:48:12.138 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'
2023-08-26 14:54:35.074 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'
2023-08-26 14:54:35.075 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'
2023-08-26 14:54:35.076 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'

Additional information

No response

@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!

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 Renames 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)

@cgilis
Copy link

cgilis commented Sep 4, 2023

I have the same here, my gate is now opening at random times :-) so I had to remove the autmations

@pszafer
Copy link
Contributor

pszafer commented Sep 11, 2023

can you show your automations?

@flfue
Copy link
Contributor

flfue commented Sep 12, 2023

I saw the same issue twice as well, hue_events are triggered randomly and I figured out that it happened both times at rougly quarter past 2pm. 2pm is the time my hue bridge was configured to perform automatic updates. Didn't see the issue anymore since I disabled the updates. First time it happened 22nd of August 2:16pm, second time 8th of September 2:21pm.

Update: The release notes page shows a new software release on the 16th that could fit my occurance on the 22nd. There is nothing shown on the 8th though (https://www.philips-hue.com/de-de/support/release-notes/bridge).

@cgilis
Copy link

cgilis commented Sep 12, 2023

I saw the same issue twice as well, hue_events are triggered randomly and I figured out that it happened both times at rougly quarter past 2pm. 2pm is the time my hue bridge was configured to perform automatic updates. Didn't see the issue anymore since I disabled the updates. First time it happened 22nd of August 2:16pm, second time 8th of September 2:21pm.

Update: The release notes page shows a new software release on the 16th that could fit my occurance on the 22nd. There is nothing shown on the 8th though (https://www.philips-hue.com/de-de/support/release-notes/bridge).

For me, almost exactly the same first time was on August 18th.

@flfue
Copy link
Contributor

flfue commented Sep 12, 2023

Interresting is also that the latest software version according to release notes should be 1.59.1959194030 but my bridge has already 1.59.1959194040 installed (likely there was a second update that is not in the release notes). Chances are high that the issue is triggered either by an update or restart of the bridge.

@cgilis
Copy link

cgilis commented Sep 12, 2023

Indeed, mine was around 3h15 while my bridge auto updates on 3h.
So I also turned off auto update :-)

Now I dare to turn on my automation again.. 🤣

@spasche
Copy link
Author

spasche commented Sep 14, 2023

Thanks for the feedbacks. I also noticed that these issues happened shortly after the bridge auto update time. So it's highly likely to be related to the bridge update.

It would be great if aiohue was able to detect such condition and inhibit firing ghost dimmer events when that happens.

Nevertheless there is a workaround, I'll update the bridge manually for now.

@cgilis
Copy link

cgilis commented Sep 14, 2023

What I just was thinking about,
What if there is a power outage, so after the power is back, and the hub is started. Will this fire actions? 😅

@Robbe-B
Copy link

Robbe-B commented Sep 18, 2023

I'm having the same problem with ghost events.
I use the dimmer switch for my bathroom ventilation, the dimmer events are triggering the increase / decrease speed of the fan entity.
I've also started seeing these ghost events.
After checking the logbook in HA and seeing these dimmer events randomly getting fired, I figured maybe this was interfering with some other remote control or something.
Anyway after reading this, I've disabled the automatic updates in the Hue app.
Let's hope this will be a solution to the problem.
Thanks for reporting this issue !

@zSprawl
Copy link

zSprawl commented Sep 18, 2023

I too have been noticing this issue but it has taken me a while because I thought it was Homekit at first since I had just setup Homekit integrations. So I disabled all of that stuff thinking Apple was turning my lights on and off. Then I disabled Alexa. Then I disabled Google Home. Now I just have some lights on the Hue bridge, using the Hue integration, and it's STILL happening. I'm not sure if it was the update to HA or recent firmware updates to the bridge, but I have and have always had auto-update disabled.

Once I power cycle the Hue hub, things seem better for a few days, but then they returned today, so I'm not sure what is going on anymore. There is nothing in the logs to point me to anything... so far. I did just turn on debugging for the Hue integration in hopes of seeing something next time.

@rbp1987
Copy link

rbp1987 commented Sep 19, 2023

I have also seen this behaviour when the bridge gets updated. I have 2 Hue Bridge's in use in my environment and I changed the Automatic updates on one to be 5 hours after the the other. Today I received a new update for the Hue Bridge and saw ‘hue_event’ at 5am and 10am as the Bridge was updated.

Today my bridge updated from 1.59.1959194030 to 1.60.1960062030 but there are no release notes on the Hue website at the moment for 1.60.1960062030

@danharvey
Copy link

I also have the same issue as described here with "ghost" hue button presses triggering around 3am BST (hue hub is set to update 2am - GMT I guess).

I have 6 Hue switches ("Hue dimmer switch (RWL022)") with one of the buttons toggling AC in each room. So we now have the AC turning on seemingly randomly overnight. When I looked at logs in the past there was not much to report.

This happened again last night coinciding with the Hue hub update @rbp1987 mentioned.

The triggers don't happen straight away

  • Room A: 02:50:36 - 18 hours ago
  • Room B: 02:51:46 - 18 hours ago
  • Room C: 02:58:07 - 18 hours ago
  • Room D: 03:00:29 - 18 hours ago
  • Room E: 03:14:53 - 18 hours ago
  • Room F: 03:18:47 - 18 hours ago

Similar log event as flagged in the issue by @spasche

Logs around room A/B trigger

2023-09-20 02:50:36.490 WARNING (MainThread) [homeassistant.helpers.state] Integration device_tracker does not support reproduce state
2023-09-20 02:50:36.492 WARNING (MainThread) [homeassistant.helpers.state] Integration sensor does not support reproduce state
2023-09-20 02:51:46.111 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'
2023-09-20 02:51:46.180 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^

Logs around room C trigger

2023-09-20 02:58:07.427 WARNING (MainThread) [homeassistant.helpers.state] Integration device_tracker does not support reproduce state
2023-09-20 02:58:07.429 WARNING (MainThread) [homeassistant.helpers.state] Integration sensor does not support reproduce state
2023-09-20 02:58:40.806 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'
2023-09-20 02:58:40.821 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'

Logs around room D trigger

2023-09-20 03:00:29.784 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'
2023-09-20 03:00:29.794 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/sensors.py", line 57, in _handle_event
    await super()._handle_event(evt_type, evt_data)
  File "/usr/local/lib/python3.11/site-packages/aiohue/v2/controllers/base.py", line 257, in _handle_event
    callback(evt_type, cur_item)
  File "/usr/src/homeassistant/homeassistant/components/hue/event.py", line 101, in _handle_event
    self._trigger_event(resource.button.last_event.value)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'last_event'

There wasn't any logs around room E or F trigger oddly... so hard to know if theses errors in the logs are a distraction or not.

@CoryAlbrecht
Copy link

I just experienced this now, with the same log lines reported by others. Hue update is set for 3am.

@xBourner
Copy link

Having exactly the same. I am using two dimmer remote to control light, tv (with a smart plug) and music in my bedroom. it drives me crazy because lights turn on in the middle of the night and the tv goes off while watching.

It seems to start a little later than the auto update in hue app so I disabled the auto update. I also think about hooking the remotes to Z2M so I’m not using the hue hub anymore until there is a real fix.
or anyone has other suggestions?

@issue-triage-workflows
Copy link

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.

@issue-triage-workflows issue-triage-workflows bot closed this as not planned Won't fix, can't repro, duplicate, stale Mar 29, 2024
@cgilis
Copy link

cgilis commented Mar 29, 2024

I think it's still an open issue..

@rvrignaud
Copy link

Yes I still have the issue as well

@Robbe-B
Copy link

Robbe-B commented Apr 1, 2024

Same

@Robbe-B
Copy link

Robbe-B commented Apr 9, 2024

Still an issue,
Using HA Core 2024.4.2
Manually triggering a Philips Hue Bridge update. (Auto Update disabled)
Ghost events came +- 10 seconds after the update finished.
This for all buttons at once:
image

@idekker
Copy link
Contributor

idekker commented Apr 11, 2024

Since this issue is driving me crazy I spend some time debugging and analysing. :)

At first I thought it is the Hue bridge sending out button-press events, but it is not. Well, not exactly anyway.
I managed to capture the events sent by the bridge a little while after it received an update:

[
    {
        "creationtime": "2024-04-11T17:01:55Z",
        "data": [
            /* ... */
            {
                "button": {
                    "event_values": [
                        "initial_press",
                        "repeat",
                        "short_release",
                        "long_release",
                        "long_press"
                    ],
                    "repeat_interval": 800
                },
                "id": "ab3acc07-99cb-4ab1-ba60-762d37bfc9ab",
                "id_v1": "/sensors/218",
                "metadata": {
                    "control_id": 1
                },
                "owner": {
                    "rid": "c4e15f4a-3aaf-4e18-8c0f-dfcb598ca93d",
                    "rtype": "device"
                },
                "type": "button"
            },
            {
                "button": {
                    "event_values": [
                        "initial_press",
                        "repeat",
                        "short_release",
                        "long_release",
                        "long_press"
                    ],
                    "repeat_interval": 800
                },
                "id": "0d3e62e5-fc35-4743-bc47-5c8fe3be7a9b",
                "id_v1": "/sensors/218",
                "metadata": {
                    "control_id": 2
                },
                "owner": {
                    "rid": "c4e15f4a-3aaf-4e18-8c0f-dfcb598ca93d",
                    "rtype": "device"
                },
                "type": "button"
            },
            {
                "button": {
                    "event_values": [
                        "initial_press",
                        "repeat",
                        "short_release",
                        "long_release",
                        "long_press"
                    ],
                    "repeat_interval": 800
                },
                "id": "a5849f61-dbc0-4506-aea2-78de3149a15c",
                "id_v1": "/sensors/218",
                "metadata": {
                    "control_id": 3
                },
                "owner": {
                    "rid": "c4e15f4a-3aaf-4e18-8c0f-dfcb598ca93d",
                    "rtype": "device"
                },
                "type": "button"
            },
            {
                "button": {
                    "event_values": [
                        "initial_press",
                        "repeat",
                        "short_release",
                        "long_release",
                        "long_press"
                    ],
                    "repeat_interval": 800
                },
                "id": "44f87541-05d1-4806-9c6a-85bf38d170e4",
                "id_v1": "/sensors/218",
                "metadata": {
                    "control_id": 4
                },
                "owner": {
                    "rid": "c4e15f4a-3aaf-4e18-8c0f-dfcb598ca93d",
                    "rtype": "device"
                },
                "type": "button"
            }
            /* ... */
        ],
        "id": "198842c8-c56d-4321-8976-0c6d01b70134",
        "type": "update"
    }
]

Notice that both the button_report and last_event properties are missing from each button service update-event.
Yet, the debug logging in Home Assistant / aiohue has them listed:

2024-04-11 19:01:55.818 DEBUG (MainThread) [homeassistant.components.hue.bridge.button] Received status update for event.hue_dimmer_switch_3_button_2
2024-04-11 19:01:55.819 DEBUG (MainThread) [homeassistant.components.hue.bridge.button] Received status update for event.hue_dimmer_switch_3_button_4
2024-04-11 19:01:55.819 DEBUG (MainThread) [homeassistant.components.hue.bridge.button] Received status update for event.hue_dimmer_switch_3_button_3
2024-04-11 19:01:55.819 DEBUG (MainThread) [homeassistant.components.hue.bridge.button] Received status update for event.hue_dimmer_switch_3_button_1
2024-04-11 19:01:55.819 DEBUG (MainThread) [homeassistant.components.hue.bridge.device_power] Received status update for sensor.hue_dimmer_switch_3_battery
2024-04-11 19:01:55.821 DEBUG (MainThread) [homeassistant.components.hue.bridge.button] Received status update for event.hue_dimmer_switch_3_button_2
2024-04-11 19:01:55.822 DEBUG (MainThread) [homeassistant.components.hue.bridge.button] Received status update for event.hue_dimmer_switch_3_button_4
2024-04-11 19:01:55.822 DEBUG (MainThread) [homeassistant.components.hue.bridge.button] Received status update for event.hue_dimmer_switch_3_button_3
2024-04-11 19:01:55.822 DEBUG (MainThread) [homeassistant.components.hue.bridge.button] Received status update for event.hue_dimmer_switch_3_button_1
2024-04-11 19:01:55.822 DEBUG (MainThread) [homeassistant.components.hue.bridge.device_power] Received status update for sensor.hue_dimmer_switch_3_battery
2024-04-11 19:01:55.824 DEBUG (MainThread) [homeassistant.components.hue.v2.hue_event] Received button event: Button(id='ab3acc07-99cb-4ab1-ba60-762d37bfc9ab', owner=ResourceIdentifier(rid='c4e15f4a-3aaf-4e18-8c0f-dfcb598ca93d', rtype=<ResourceTypes.DEVICE: 'device'>), metadata=ButtonMetadata(control_id=1), button=ButtonFeature(button_report=ButtonReport(updated=datetime.datetime(2024, 4, 11, 4, 51, 47, 903000, tzinfo=datetime.timezone.utc), event=<ButtonEvent.SHORT_RELEASE: 'short_release'>), last_event=<ButtonEvent.SHORT_RELEASE: 'short_release'>, repeat_interval=800, event_values=[<ButtonEvent.INITIAL_PRESS: 'initial_press'>, <ButtonEvent.REPEAT: 'repeat'>, <ButtonEvent.SHORT_RELEASE: 'short_release'>, <ButtonEvent.LONG_RELEASE: 'long_release'>, <ButtonEvent.LONG_PRESS: 'long_press'>]), id_v1='/sensors/218', type=<ResourceTypes.BUTTON: 'button'>)
2024-04-11 19:01:55.825 INFO (MainThread) [homeassistant.components.automation.woonkamer_tv_remote_switch_on_watch_tv] Woonkamer: TV Remote Switch 'on': Watch TV: Running automation actions
2024-04-11 19:01:55.825 INFO (MainThread) [homeassistant.components.automation.woonkamer_tv_remote_switch_on_watch_tv] Woonkamer: TV Remote Switch 'on': Watch TV: Executing step call service
2024-04-11 19:01:55.827 DEBUG (MainThread) [homeassistant.components.hue.v2.hue_event] Received button event: Button(id='0d3e62e5-fc35-4743-bc47-5c8fe3be7a9b', owner=ResourceIdentifier(rid='c4e15f4a-3aaf-4e18-8c0f-dfcb598ca93d', rtype=<ResourceTypes.DEVICE: 'device'>), metadata=ButtonMetadata(control_id=2), button=ButtonFeature(button_report=ButtonReport(updated=datetime.datetime(2024, 4, 11, 12, 3, 19, 804000, tzinfo=datetime.timezone.utc), event=<ButtonEvent.SHORT_RELEASE: 'short_release'>), last_event=<ButtonEvent.SHORT_RELEASE: 'short_release'>, repeat_interval=800, event_values=[<ButtonEvent.INITIAL_PRESS: 'initial_press'>, <ButtonEvent.REPEAT: 'repeat'>, <ButtonEvent.SHORT_RELEASE: 'short_release'>, <ButtonEvent.LONG_RELEASE: 'long_release'>, <ButtonEvent.LONG_PRESS: 'long_press'>]), id_v1='/sensors/218', type=<ResourceTypes.BUTTON: 'button'>)
2024-04-11 19:01:55.828 INFO (MainThread) [homeassistant.components.automation.woonkamer_tv_remote_switch_up_watch_smart_tv] Woonkamer: TV Remote Switch 'up': Watch Smart TV: Running automation actions
2024-04-11 19:01:55.828 INFO (MainThread) [homeassistant.components.automation.woonkamer_tv_remote_switch_up_watch_smart_tv] Woonkamer: TV Remote Switch 'up': Watch Smart TV: Executing step call service
2024-04-11 19:01:55.833 DEBUG (MainThread) [homeassistant.components.hue.v2.hue_event] Received button event: Button(id='a5849f61-dbc0-4506-aea2-78de3149a15c', owner=ResourceIdentifier(rid='c4e15f4a-3aaf-4e18-8c0f-dfcb598ca93d', rtype=<ResourceTypes.DEVICE: 'device'>), metadata=ButtonMetadata(control_id=3), button=ButtonFeature(button_report=ButtonReport(updated=datetime.datetime(2024, 3, 31, 17, 15, 12, 286000, tzinfo=datetime.timezone.utc), event=<ButtonEvent.SHORT_RELEASE: 'short_release'>), last_event=<ButtonEvent.SHORT_RELEASE: 'short_release'>, repeat_interval=800, event_values=[<ButtonEvent.INITIAL_PRESS: 'initial_press'>, <ButtonEvent.REPEAT: 'repeat'>, <ButtonEvent.SHORT_RELEASE: 'short_release'>, <ButtonEvent.LONG_RELEASE: 'long_release'>, <ButtonEvent.LONG_PRESS: 'long_press'>]), id_v1='/sensors/218', type=<ResourceTypes.BUTTON: 'button'>)
2024-04-11 19:01:55.834 INFO (MainThread) [homeassistant.components.automation.woonkamer_tv_remote_switch_down_listen_to_radio] Woonkamer: TV Remote Switch 'down': Listen to Radio: Running automation actions
2024-04-11 19:01:55.834 INFO (MainThread) [homeassistant.components.automation.woonkamer_tv_remote_switch_down_listen_to_radio] Woonkamer: TV Remote Switch 'down': Listen to Radio: Executing step call service
2024-04-11 19:01:55.834 DEBUG (MainThread) [homeassistant.components.hue.v2.hue_event] Received button event: Button(id='44f87541-05d1-4806-9c6a-85bf38d170e4', owner=ResourceIdentifier(rid='c4e15f4a-3aaf-4e18-8c0f-dfcb598ca93d', rtype=<ResourceTypes.DEVICE: 'device'>), metadata=ButtonMetadata(control_id=4), button=ButtonFeature(button_report=ButtonReport(updated=datetime.datetime(2024, 4, 11, 12, 47, 15, 859000, tzinfo=datetime.timezone.utc), event=<ButtonEvent.SHORT_RELEASE: 'short_release'>), last_event=<ButtonEvent.SHORT_RELEASE: 'short_release'>, repeat_interval=800, event_values=[<ButtonEvent.INITIAL_PRESS: 'initial_press'>, <ButtonEvent.REPEAT: 'repeat'>, <ButtonEvent.SHORT_RELEASE: 'short_release'>, <ButtonEvent.LONG_RELEASE: 'long_release'>, <ButtonEvent.LONG_PRESS: 'long_press'>]), id_v1='/sensors/218', type=<ResourceTypes.BUTTON: 'button'>)
2024-04-11 19:01:55.835 INFO (MainThread) [homeassistant.components.automation.woonkamer_tv_remote_switch_off_off] Woonkamer: TV Remote Switch 'off': Off: Running automation actions
2024-04-11 19:01:55.835 INFO (MainThread) [homeassistant.components.automation.woonkamer_tv_remote_switch_off_off] Woonkamer: TV Remote Switch 'off': Off: Executing step call service
2024-04-11 19:01:55.835 DEBUG (MainThread) [homeassistant.components.hue.bridge.device_power] Received status update for sensor.hue_dimmer_switch_3_battery
2024-04-11 19:01:56.137 INFO (MainThread) [homeassistant.components.automation.switch_to_harmony_activity_without_huesyncbox_and_subwoofer] AV Woonkamer: Switch to Harmony activity without Subwoofer: Running automation actions
2024-04-11 19:01:56.138 INFO (MainThread) [homeassistant.components.automation.switch_to_harmony_activity_without_huesyncbox_and_subwoofer] AV Woonkamer: Switch to Harmony activity without Subwoofer: Executing step call service
2024-04-11 19:01:56.141 INFO (MainThread) [homeassistant.components.automation.new_automation_2] AV Woonkamer: zet versterkers aan: Running automation actions
2024-04-11 19:01:56.141 INFO (MainThread) [homeassistant.components.automation.new_automation_2] AV Woonkamer: zet versterkers aan: Executing step call service

Digging through the code I found that aiohue is actually first 'merging' the event with the 'cached' state before the merged resource is processed as event: https://github.com/home-assistant-libs/aiohue/blob/main/aiohue/v2/controllers/base.py#L227

I think this is wrong. Especially for event/command based events. For whatever reason the bridge is telling subscribers that some properties inside the button resource (may) have changed value, but since it is not saying anything about button_report (and the deprecated last_event) property, it is explicitly saying these haven't changed value. Merging this with the 'cached' state where both properties already had a value results in these values being seen as part of the event.

It is kind of questionable why the bridge sends update-events for button resources without any changes, but imagine there would be other changeable properties in the button resource, or maybe even inside the button feature (I see there is code to ignore resources when the button feature is missing). For instance a name of the button, or a property that controls the behaviour of a LED if each button had one. This property could change independently from actual buttons being pressed, so their update-events would (should) only indicate the value change of those. Yet, if the merged resource is used to process the event it would also be seen as a button event in aiohue / Home Assistant.

Long story short: I think the received event should be used for event processing and the merged resource can be used to maintain a complete view on the actual state. I think it relates to this feature request: home-assistant-libs/aiohue#136

@marcelveldt
Copy link
Member

It is not wrong, the state has changed and we send a full object further down the chain.
Hue has no concept of "a button has been pressed" - it only has the concept of "some attribute has changed somewhere".

So we should just translate this into our own truth and only care for the attribute that actually changed.

@marcelveldt
Copy link
Member

I think it relates to this feature request: home-assistant-libs/aiohue#136

No that is unrelated, its about receiving the raw events. It wont solve anything as HA is reacting on the event as a whole (so also if some attribute updates). We should either introduce the concept of a "button pressed event" in the aiolibrary or do some more filtering in HA.

The simplest solution would be to store the previous button value in HA and compare it when the event comes in. That way you explicitly know the difference between " the button object updated" and "a button was pressed"

@marcelveldt marcelveldt reopened this Apr 11, 2024
@marcelveldt
Copy link
Member

I'll have a look at this again tomorrow, I have been very busy with other stuff so this one got a bit forgotten. I'll chew a bit on it if I'm going to implement some custom logic for button events in the aiohue lib or just compare the last button state in HA.

Still. its crap that the hue bridge sends an attribute changed event (while no attributes changed!) after/when its updating the firmware

@idekker
Copy link
Contributor

idekker commented Apr 11, 2024

It is not wrong, the state has changed and we send a full object further down the chain.

That's the thing, it didn't change. The update-event is just repeating what was already known. If you would compare the state before and after merging, they would be the same.

For button-events you cannot really compare states either, because after the first repeat state all repeat events would be filtered out. Every second updated would change value, but you could get 2 such events every second. If updated would have a higher precision then you could assume it is a new event="repeat" event and manually add it to the diff.

I agree the bridge should not send events for things that haven't changed, but as long that this doesn't happen for the (physical) button (press) and rotary properties itself there shouldn't be a functional problem.

You're correct in saying that Hue does not communicate "a button has been pressed", but indeed communicates "some attribute has been changed". But if you look at events from a stateless system point of view, you can use events to know when "a button has been pressed" and that's when an update event is send with button_report.

I'm not familiar with how Home Assistant handles events upstream. Maybe you need special handling for button (and rotary) events based on the RAW event content and the existing handling for others.

@marcelveldt
Copy link
Member

Exactly, I will add that soon. Requires a bit less of refactoring but that should fix it for good. So a little bit more patience please

@cgilis
Copy link

cgilis commented May 15, 2024

Is it fixed? :-) THX btw!
Can we enable auto updates again?

@idekker
Copy link
Contributor

idekker commented May 15, 2024

I'm not convinced this fixes the ghost events seen after a bridge update. As mentioned earlier, aiohue merges the incoming event with the cached state which is then passed to the home assistant integration, so if the cached state has a button_report, then all events reaching the changed code will always have button_report. Only if the cached state does not have button_report, then it will not try to process it any further... but if there is no button_report, I wonder what HA event it would be mapped to.

@github-actions github-actions bot locked and limited conversation to collaborators Jun 14, 2024
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.