[BUG] Philips Hue Wall Switch and Dimmer Switch emit event 400 ms too late

[carlolars]

Bug description

Back in October, or was it November, I noticed that my Hue switches (wall and dimmer) started having a very noticeable delay when pressing a button until something actually happened (light turned on or off). I trigger on the short_release event which now is delayed alot.

For the Dimmer Switch there actually are two other events, on and off_with_effect, that are emitted immediately when pressing the button, but for the Wall Switch there are no such events so there is no workaround.

Looking at the logs there are two notifications received for a button, first one with press_type=0 and then 100ms later one with press_type=2, and then 300 ms later (ButtonPressQueue _ms_threshold?) the event is emitted. This cause a significant and very noticeable delay.

I would suggest that always emit an event for the very first command that is received.

Steps to reproduce

Just press a button on a Hue Wall or Dimmer switch and watch the logs or notice the delay if using it to turn on a light.

Expected behavior

The light should toggle instantly when pushing a button on the switch :)

Screenshots/Video

Screenshots/Video

[Paste/upload your media here]

Device signature

Device signature

[Paste the device signature here]

Diagnostic information

Diagnostic information

[Paste the diagnostic information here]

Logs

Logs

Hue Dimmer Switch:

2025-01-03 23:28:22.015 DEBUG (MainThread) [zigpy.zcl] [0xCF49:2:0xfc00] Received ZCL frame: b'\x1d\x0b\x10\x9a\x00\x04\x00\x000\x00!\x00\x00'
2025-01-03 23:28:22.016 DEBUG (MainThread) [zigpy.zcl] [0xCF49:2:0xfc00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x1D>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, direction=<Direction.Server_to_Client: 1>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4107, tsn=154, command_id=0, *direction=<Direction.Server_to_Client: 1>)
2025-01-03 23:28:22.016 DEBUG (MainThread) [zigpy.zcl] [0xCF49:2:0xfc00] Decoded ZCL frame: PhilipsRwlRemoteCluster:notification(button=4, param2=3145728, press_type=0, param4=33, param5=0)
2025-01-03 23:28:22.016 DEBUG (MainThread) [zigpy.zcl] [0xCF49:2:0xfc00] Received command 0x00 (TSN 154): notification(button=4, param2=3145728, press_type=0, param4=33, param5=0)
2025-01-03 23:28:22.016 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - handle_cluster_request tsn: [154] command id: 0 - args: [notification(button=4, param2=3145728, press_type=0, param4=33, param5=0)]
2025-01-03 23:28:22.016 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - handle_cluster_request button id: [4], button name: [<Button id=off, trigger=turn_off, action=off>]
[...]
2025-01-03 23:28:22.022 DEBUG (MainThread) [zigpy.zcl] [0xCF49:1:0x0006] Received ZCL frame: b'\x01\x9b@\x00\x00'
2025-01-03 23:28:22.022 DEBUG (MainThread) [zigpy.zcl] [0xCF49:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=155, command_id=64, *direction=<Direction.Client_to_Server: 0>)
2025-01-03 23:28:22.022 DEBUG (MainThread) [zigpy.zcl] [0xCF49:1:0x0006] Decoded ZCL frame: OnOff:off_with_effect(effect_id=<OffEffectIdentifier.Delayed_All_Off: 0>, effect_variant=0)
2025-01-03 23:28:22.022 DEBUG (MainThread) [zigpy.zcl] [0xCF49:1:0x0006] Received command 0x40 (TSN 155): off_with_effect(effect_id=<OffEffectIdentifier.Delayed_All_Off: 0>, effect_variant=0)
2025-01-03 23:28:22.023 DEBUG (MainThread) [zigpy.zcl] [0xCF49:1:0x0006] No explicit handler for cluster command 0x40: off_with_effect(effect_id=<OffEffectIdentifier.Delayed_All_Off: 0>, effect_variant=0)
2025-01-03 23:28:22.023 DEBUG (MainThread) [zha] Emitting event zha_event with data ZHAEvent(device_ieee=00:17:88:01:08:f0:73:95, unique_id='00:17:88:01:08:f0:73:95', data={'unique_id': '00:17:88:01:08:f0:73:95:1:0x0006', 'endpoint_id': 1, 'cluster_id': 6, 'command': 'off_with_effect', 'args': [<OffEffectIdentifier.Delayed_All_Off: 0>, 0], 'params': {'effect_id': <OffEffectIdentifier.Delayed_All_Off: 0>, 'effect_variant': 0}}, event_type='zha_event', event='zha_event') (1 listeners)
2025-01-03 23:28:22.023 DEBUG (MainThread) [zha] (ZHADeviceProxy) handling event protocol for event: ZHAEvent(device_ieee=00:17:88:01:08:f0:73:95, unique_id='00:17:88:01:08:f0:73:95', data={'unique_id': '00:17:88:01:08:f0:73:95:1:0x0006', 'endpoint_id': 1, 'cluster_id': 6, 'command': 'off_with_effect', 'args': [<OffEffectIdentifier.Delayed_All_Off: 0>, 0], 'params': {'effect_id': <OffEffectIdentifier.Delayed_All_Off: 0>, 'effect_variant': 0}}, event_type='zha_event', event='zha_event')
[...]
2025-01-03 23:28:22.142 DEBUG (MainThread) [zigpy.zcl] [0xCF49:2:0xfc00] Received ZCL frame: b'\x1d\x0b\x10\x9c\x00\x04\x00\x000\x02!\x01\x00'
2025-01-03 23:28:22.142 DEBUG (MainThread) [zigpy.zcl] [0xCF49:2:0xfc00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x1D>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, direction=<Direction.Server_to_Client: 1>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4107, tsn=156, command_id=0, *direction=<Direction.Server_to_Client: 1>)
2025-01-03 23:28:22.143 DEBUG (MainThread) [zigpy.zcl] [0xCF49:2:0xfc00] Decoded ZCL frame: PhilipsRwlRemoteCluster:notification(button=4, param2=3145728, press_type=2, param4=33, param5=1)
2025-01-03 23:28:22.143 DEBUG (MainThread) [zigpy.zcl] [0xCF49:2:0xfc00] Received command 0x00 (TSN 156): notification(button=4, param2=3145728, press_type=2, param4=33, param5=1)
2025-01-03 23:28:22.143 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - handle_cluster_request tsn: [156] command id: 0 - args: [notification(button=4, param2=3145728, press_type=2, param4=33, param5=1)]
2025-01-03 23:28:22.143 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - handle_cluster_request button id: [4], button name: [<Button id=off, trigger=turn_off, action=off>]
2025-01-03 23:28:22.143 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - handle_cluster_request button press type: [<PressType name=remote_button_short_release, action=short_release, trigger=remote_button_short_release, arg=short_release>], duration: [1]
[...]
2025-01-03 23:28:22.445 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - send_press_event click_count: [1]
2025-01-03 23:28:22.445 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - send_press_event evaluated press_type: [<PressType name=remote_button_short_press, action=press, trigger=remote_button_short_press, arg=press>]
2025-01-03 23:28:22.445 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - send_press_event emitting action: [off_press] event_args: {'button': 'off', 'press_type': 'press', 'command_id': 0, 'duration': 1, 'args': [4, 3145728, 0, 33, 1]}
2025-01-03 23:28:22.446 DEBUG (MainThread) [zha] Emitting event zha_event with data ZHAEvent(device_ieee=00:17:88:01:08:f0:73:95, unique_id='00:17:88:01:08:f0:73:95', data={'unique_id': '00:17:88:01:08:f0:73:95:2:0xfc00', 'endpoint_id': 2, 'cluster_id': 64512, 'command': 'off_press', 'args': {'button': 'off', 'press_type': 'press', 'command_id': 0, 'duration': 1, 'args': [4, 3145728, 0, 33, 1]}, 'params': {}}, event_type='zha_event', event='zha_event') (1 listeners)
2025-01-03 23:28:22.446 DEBUG (MainThread) [zha] (ZHADeviceProxy) handling event protocol for event: ZHAEvent(device_ieee=00:17:88:01:08:f0:73:95, unique_id='00:17:88:01:08:f0:73:95', data={'unique_id': '00:17:88:01:08:f0:73:95:2:0xfc00', 'endpoint_id': 2, 'cluster_id': 64512, 'command': 'off_press', 'args': {'button': 'off', 'press_type': 'press', 'command_id': 0, 'duration': 1, 'args': [4, 3145728, 0, 33, 1]}, 'params': {}}, event_type='zha_event', event='zha_event')
2025-01-03 23:28:22.447 DEBUG (MainThread) [zhaquirks.philips] PhilipsRwlRemoteCluster - send_press_event emitting simulated action: [off_short_release]
2025-01-03 23:28:22.447 DEBUG (MainThread) [zha] Emitting event zha_event with data ZHAEvent(device_ieee=00:17:88:01:08:f0:73:95, unique_id='00:17:88:01:08:f0:73:95', data={'unique_id': '00:17:88:01:08:f0:73:95:2:0xfc00', 'endpoint_id': 2, 'cluster_id': 64512, 'command': 'off_short_release', 'args': {'button': 'off', 'press_type': 'short_release', 'command_id': 0, 'duration': 1, 'args': [4, 3145728, 2, 33, 1]}, 'params': {}}, event_type='zha_event', event='zha_event') (1 listeners)
2025-01-03 23:28:22.447 DEBUG (MainThread) [zha] (ZHADeviceProxy) handling event protocol for event: ZHAEvent(device_ieee=00:17:88:01:08:f0:73:95, unique_id='00:17:88:01:08:f0:73:95', data={'unique_id': '00:17:88:01:08:f0:73:95:2:0xfc00', 'endpoint_id': 2, 'cluster_id': 64512, 'command': 'off_short_release', 'args': {'button': 'off', 'press_type': 'short_release', 'command_id': 0, 'duration': 1, 'args': [4, 3145728, 2, 33, 1]}, 'params': {}}, event_type='zha_event', event='zha_event')

Hue Wall Switch:

2025-01-03 22:48:06.188 DEBUG (MainThread) [zigpy.zcl] [0xA6F2:1:0xfc00] Received ZCL frame: b'\x1d\x0b\x10_\x00\x01\x00\x000\x00!\x00\x00'
2025-01-03 22:48:06.189 DEBUG (MainThread) [zigpy.zcl] [0xA6F2:1:0xfc00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x1D>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, direction=<Direction.Server_to_Client: 1>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4107, tsn=95, command_id=0, *direction=<Direction.Server_to_Client: 1>)
2025-01-03 22:48:06.190 DEBUG (MainThread) [zigpy.zcl] [0xA6F2:1:0xfc00] Decoded ZCL frame: PhilipsWallSwitchRemoteCluster:notification(button=1, param2=3145728, press_type=0, param4=33, param5=0)
2025-01-03 22:48:06.190 DEBUG (MainThread) [zigpy.zcl] [0xA6F2:1:0xfc00] Received command 0x00 (TSN 95): notification(button=1, param2=3145728, press_type=0, param4=33, param5=0)
2025-01-03 22:48:06.190 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - handle_cluster_request tsn: [95] command id: 0 - args: [notification(button=1, param2=3145728, press_type=0, param4=33, param5=0)]
2025-01-03 22:48:06.191 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - handle_cluster_request button id: [1], button name: [<Button id=left, trigger=turn_on, action=left>]
[...]
2025-01-03 22:48:06.288 DEBUG (MainThread) [zigpy.zcl] [0xA6F2:1:0xfc00] Received ZCL frame: b'\x1d\x0b\x10`\x00\x01\x00\x000\x02!\x01\x00'
2025-01-03 22:48:06.288 DEBUG (MainThread) [zigpy.zcl] [0xA6F2:1:0xfc00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x1D>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, direction=<Direction.Server_to_Client: 1>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4107, tsn=96, command_id=0, *direction=<Direction.Server_to_Client: 1>)
2025-01-03 22:48:06.288 DEBUG (MainThread) [zigpy.zcl] [0xA6F2:1:0xfc00] Decoded ZCL frame: PhilipsWallSwitchRemoteCluster:notification(button=1, param2=3145728, press_type=2, param4=33, param5=1)
2025-01-03 22:48:06.289 DEBUG (MainThread) [zigpy.zcl] [0xA6F2:1:0xfc00] Received command 0x00 (TSN 96): notification(button=1, param2=3145728, press_type=2, param4=33, param5=1)
2025-01-03 22:48:06.289 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - handle_cluster_request tsn: [96] command id: 0 - args: [notification(button=1, param2=3145728, press_type=2, param4=33, param5=1)]
2025-01-03 22:48:06.289 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - handle_cluster_request button id: [1], button name: [<Button id=left, trigger=turn_on, action=left>]
2025-01-03 22:48:06.289 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - handle_cluster_request button press type: [<PressType name=remote_button_short_release, action=short_release, trigger=remote_button_short_release, arg=short_release>], duration: [1]
[...]
2025-01-03 22:48:06.594 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - send_press_event click_count: [1]
2025-01-03 22:48:06.594 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - send_press_event evaluated press_type: [<PressType name=remote_button_short_press, action=press, trigger=remote_button_short_press, arg=press>]
2025-01-03 22:48:06.594 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - send_press_event emitting action: [left_press] event_args: {'button': 'left', 'press_type': 'press', 'command_id': 0, 'duration': 1, 'args': [1, 3145728, 0, 33, 1]}
2025-01-03 22:48:06.594 DEBUG (MainThread) [zha] Emitting event zha_event with data ZHAEvent(device_ieee=00:17:88:01:0b:03:b2:e6, unique_id='00:17:88:01:0b:03:b2:e6', data={'unique_id': '00:17:88:01:0b:03:b2:e6:1:0xfc00', 'endpoint_id': 1, 'cluster_id': 64512, 'command': 'left_press', 'args': {'button': 'left', 'press_type': 'press', 'command_id': 0, 'duration': 1, 'args': [1, 3145728, 0, 33, 1]}, 'params': {}}, event_type='zha_event', event='zha_event') (1 listeners)
2025-01-03 22:48:06.594 DEBUG (MainThread) [zha] (ZHADeviceProxy) handling event protocol for event: ZHAEvent(device_ieee=00:17:88:01:0b:03:b2:e6, unique_id='00:17:88:01:0b:03:b2:e6', data={'unique_id': '00:17:88:01:0b:03:b2:e6:1:0xfc00', 'endpoint_id': 1, 'cluster_id': 64512, 'command': 'left_press', 'args': {'button': 'left', 'press_type': 'press', 'command_id': 0, 'duration': 1, 'args': [1, 3145728, 0, 33, 1]}, 'params': {}}, event_type='zha_event', event='zha_event')
2025-01-03 22:48:06.594 DEBUG (MainThread) [zhaquirks.philips] PhilipsWallSwitchRemoteCluster - send_press_event emitting simulated action: [left_short_release]
2025-01-03 22:48:06.595 DEBUG (MainThread) [zha] Emitting event zha_event with data ZHAEvent(device_ieee=00:17:88:01:0b:03:b2:e6, unique_id='00:17:88:01:0b:03:b2:e6', data={'unique_id': '00:17:88:01:0b:03:b2:e6:1:0xfc00', 'endpoint_id': 1, 'cluster_id': 64512, 'command': 'left_short_release', 'args': {'button': 'left', 'press_type': 'short_release', 'command_id': 0, 'duration': 1, 'args': [1, 3145728, 2, 33, 1]}, 'params': {}}, event_type='zha_event', event='zha_event') (1 listeners)
2025-01-03 22:48:06.595 DEBUG (MainThread) [zha] (ZHADeviceProxy) handling event protocol for event: ZHAEvent(device_ieee=00:17:88:01:0b:03:b2:e6, unique_id='00:17:88:01:0b:03:b2:e6', data={'unique_id': '00:17:88:01:0b:03:b2:e6:1:0xfc00', 'endpoint_id': 1, 'cluster_id': 64512, 'command': 'left_short_release', 'args': {'button': 'left', 'press_type': 'short_release', 'command_id': 0, 'duration': 1, 'args': [1, 3145728, 2, 33, 1]}, 'params': {}}, event_type='zha_event', event='zha_event')

Additional information

No response

[MattWestb]

Are you searing lights with your automation or other things ?
If yes bind the remote to one Zigbee group or the lights (depends what method its supporting and if both groups is faster) and you is getting fates response and is also working if the system is off line.
If not you is unlucky then the devs have implanting more functionality with multiple press that the device is not doing native but is emulated in the quirk and its must have one delay of the first press for knowing if its coming more ones or not.

[carlolars]

Many of my automations for the lights have conditions so binding is unfortunately not always an option.

I see that this behavior was changed in the d84d94f commit which added "simulated short events". May I suggest to remove the simulated short events and instead send the short events immediately? A multi-press event would then first have multiples of press+release events and then the multiple press event.

There is probably a need for having a "single press" event that is sent after the multi-press event evaulation in case of a single press.

[MattWestb]

The right way is using one light switch controller for direct controlling light and one "HA switch" for doing other click clicks animations and not simulation functions for the devices that is int native implanted in them.
(your device is one light controller and not one HA switch)
Matter / Zigbee ZCL is having one separate class for sending multiple clicks and and if the device is certified with then you is getting pure clicks with attributes first and last and how many clicks being made like IKEA Symfonisk 2 and sommrig shortcut button (implanted on customer cluster but is matter compatible like all IKEA switches is then exposed by Dirigera in matter bridge to HA).
All other implantation is pure hacks and is only doing things worse but some users is linking doing "magic things" with there devices,
Feel free doing one PR for your implantation for getting the single click working some milliseconds faster.

[carlolars]

Several hundereds of milliseconds ;)

I'll prepare a PR.

[TheJulianJES]

Because we send two events at basically the exact same time, we also found another issue in ZHA (related to this):

• Phillips Hue Dimmer V2 doesn't update HA state correctly when used in automations home-assistant/core#131694

We should revert the click at the beginning to the previous behavior IMO. I think SHORT_PRESS and SHORT_RELEASE fire at the exact same time now, only SHORT_RELEASE should be delayed for the multi events.

If this change is somewhat reverted, SHORT_PRESS will probably fire on all clicks, even if there are multiple clicks. Assuming this is the behavior that we had before #2340, that is fine and correct IMO.
If you also use multi events, you just have to use SHORT_RELEASE instead of SHORT_PRESS then.

PRs welcome, as always!

(also cc @fholzer)