Make Home Assistant automation respond faster to blue 2-1

I have a blue 2-1 switch that is controlling both a zigbee group of smart lights and a shelly1 that is controlling power to a dumb light. The shelly1 isn’t zigbee, so I’m using an automation to turn on and off the shelly1 when the buttons are pressed. The automation is being triggered by the press up and press down events.

However, I’ve noticed that the automation is very slow, and it’s not because of the shelly (which responds quickly when Home Assistant itself just toggles the shelly on and off). It’s delayed by quite a bit compared to the zigbee lights (feels like a second or more, but hard to measure), and far longer than the shelly response delay.

However, I’ve noticed in my logbook that the blue switch sends multiple “On” events followed by a single “Press - Up” event. I’m guessing that the Press - Up event is delayed in some way compared to On (although I’m not sure why there are multiple On events every time).

Should I change to looking for the on event somehow? Is there something else I can do to get the automation to trigger faster after the blue 2-1 switch is pressed?

Example:

Switch - LR Wall 2 Press - Up event was fired
10:53:01 AM - 20 seconds ago

Switch - LR Wall 2 On event was fired
10:53:01 AM - 20 seconds ago

Switch - LR Wall 2 On event was fired
10:53:01 AM - 20 seconds ago

Switch - LR Wall 2 On event was fired
10:53:01 AM - Now

Based on your example, all the events have the same time stamp and show no delay. It also shows the up event fired at the same time as 2 of the on events (20 seconds ago).

One thing that does help speed things up is to adjust your button delay.

If you use multi-taps on the switch, you’ll struggle getting it reliable if the delay is lower than 300ms. If you don’t, set that to 0 and you shave off 0.5s.

I have tried removing the button delay entirely and it doesnt fix the problem, my home assistant automation seems to only fire approximately 1 second later, although it’s variable. I don’t think it’s the latency of sending the command to the shelly, as this functions close to instantly when triggered from home assistant. Maybe this is just the limitation of receiving the zigbee command and responding to it?

To followup, it’s definitely not the button delay because the automation is still responding more than a second after the directly zigbee bound lights start responding (which only happens after the switch has gone through the various delays to decide which type of tap was selected). I still haven’t been able to figure this out. I could possibly swap the shelly device for a zigbee device, but I couldnt find any switches.

Here’s an updated example from my logbook:

Switch - LR Wall 2 Press - Down event was fired
10:32:37 AM - 2 seconds ago

Switch - LR Wall 2 Off event was fired
10:32:37 AM - 2 seconds ago

Island Light L3 Light turned off
10:32:36 AM - 3 seconds ago

Switch LR Sink 2 - Island Light turned off
10:32:36 AM - 3 seconds ago

Island Light B1 Light turned off
10:32:36 AM - 3 seconds ago

light kitchen sink Light turned off
10:32:36 AM - 3 seconds ago

Island Light R1 Light turned off
10:32:36 AM - 3 seconds ago

Island Light L2 Light turned off
10:32:36 AM - 3 seconds ago

Island Light L1 Light turned off
10:32:36 AM - 3 seconds ago

Switch - LR Wall 2 Off event was fired
10:32:36 AM - 3 seconds ago

The logbook detects an “off event” and then almost a second later, a second off event, followed by a “Press - Down” event. This seems very consistent.

Looking into this, I was able to make the shelly light respond significantly faster by having home assistant listen and respond to the on or off zha events from the inovelli switch, rather than the press down or press up events.

This doesn’t seem right, however. Surely the switch knows that press down has happened when it sends the off zha command! Yet it waits a long time before sending press down.
(And for some reason sends the off event twice)

I am now on the latest 2.18 firmware for this switch.

It will not send a single press down immediately. It has to wait to determine if it’s a single press down, double press down, triple press down, ect.

Yes, but:

  1. I’ve completely disabled the delay
  2. it shouldn’t send the “off” command until it’s determined if it’s a single press down as well, but in this case it sends the off command and waits a second to send the press down event.

If I’m not mistaken, when it detects a double press down event, it will not send the off zigbee command. This is why in my other rooms, I am able to use the double press down to trigger special scenes without turning off the lights. This would mean that when it sends the off command, it’s decided that it is a single press down event. But it turns off the lights and waits almost a second before sending the single press down (or up) event.

And, I am able to get rid of the delay by listening for the on/off zha events rather than the press down or up events.

I’m wondering if I don’t have a bad switch or something. Here is the logbook:

Switch - LR Wall 2 Press - Up event was fired
2:45:20 PM

Switch - LR Wall 2 Move To Level With On Off event was fired with parameters: {‘level’: 254, ‘transition_time’: 5}
2:45:20 PM

Switch - LR Wall 2 On event was fired
2:45:20 PM

Switch - LR Wall 2 Move To Level With On Off event was fired with parameters: {‘level’: 254, ‘transition_time’: 5}
2:45:18 PM

Switch - LR Wall 2 On event was fired
2:45:18 PM

Basically, it’s firing an On event and a move to level on/off event twice, separated by almost 2 seconds, and only then issues a “Press Up” event. This is repeatable and consistent every single time. When I first started this I was not on the latest firmware, it seems the level with on/off command was possibly added in it?

Button delay is set to 0, but this shouldn’t matter because the observed delay is between the On event and the Press Up event, not between the button press and the On/Up event.

Here’s abbreviated specific log information from zha debugging:

2024-06-02 14:51:19.815 DEBUG (MainThread) [zigpy.zcl] [0x4665:2:0x0006] Received command 0x01 (TSN 69): on()
2024-06-02 14:51:19.926 DEBUG (MainThread) [zigpy.zcl] [0x4665:2:0x0008] Received command 0x04 (TSN 70): move_to_level_with_on_off(level=254, transition_time=5)
2024-06-02 14:51:21.230 DEBUG (MainThread) [zigpy.zcl] [0x4665:2:0x0006] Received command 0x01 (TSN 69): on()
2024-06-02 14:51:21.285 DEBUG (MainThread) [zigpy.zcl] [0x4665:2:0xfc31] Received command 0x00 (TSN 71): button_event(button_pressed=2, press_type=0)
2024-06-02 14:51:22.696 DEBUG (MainThread) [zigpy.zcl] [0x4665:2:0x0008] Received command 0x04 (TSN 70): move_to_level_with_on_off(level=254, transition_time=5)

(full debug log of commands filtered to network device 0x4665, which is the 2-1 switch is here: github gist

This is for a single up button press on my blue 2-1 switch. It takes 1.47 seconds from the first On event for the Button_event to be received. Why are there two On and move to level on/off zigbee events? I’m not sure, and maybe it doesn’t matter (other than adding extra noise to the zigbee network and possibly explaining why rapidly alternating up and down results in a weird state), but the odd issue seems to be how long the switch takes to communicate that the up button has been pressed after it has clearly decided that the up button has been pressed (given that it has sent the On and move_to_level events, which should only happen after it’s decided that a single up press has taken place).

I’m unable to replicate this on my end, but I also use Z2M not ZHA. Maybe one of the ZHA users can help further.

I’ll do some more testing and compare to other switches we have and other binding situations over the weekend. I can’t imagine how it would be related to ZHA vs Z2M as ZHA is simply decoding and reporting the zigbee signals sent by the switch, but I suppose it’s possible.

Just to eliminate ZHA… I’m running ZHA, but not seeing this issue in a very simple case (no bindings).
2-1 blue in on/off mode, scene delay off, wired to a couple of 4ft LED tubes; they turn on “instantaneously” - so within 1/4 second anyway! Added an automation, triggered by the “up” event and turning on a neighboring light (also wired blue 2-1). 2nd light is fraction of a second (less that 1/2) behind the first.
So, bindings issue? Waiting for for response from other group members? Something about group configuration, maybe “up” is getting echo’d back & creating the second?

Ok, I experimented by taking my light switch out of the zigbee group it was in and also removed all of its bindings. I also removed any other switches in the group. When I turn the light switch on, Home Assistant received the button press almost instantly and the shelly switch that I’m trying to control is immediately switched. These are the commands found in the log:

2024-06-09 19:28:09.770 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0006]
Received command 0x01 (TSN 48): on()

2024-06-09 19:28:09.776 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0008]
Received command 0x04 (TSN 49): move_to_level_with_on_off(level=254, transition_time=5)

2024-06-09 19:28:09.828 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0xfc31]
Received command 0x00 (TSN 50): button_event(button_pressed=2, press_type=0)

So, the switch sends on(), followed by moved_to_level_with_on_off(), followed by button_event(). This takes place in 58ms. It still suggests that if I want to respond as fast as possible, I should listen to the on event, and not the button events.

Then I bound my switch to a single smart bulb. Everything was still fast. I unbound it from the single smart bulb.

Then, I bound my switch to a group for OnOff and LevelControl. This group has about a dozen smart bulbs in it. But, at this point there is nothing other than the smart bulbs (no inovelli switches or anything else). Suddenly, the delay is long again. These are what I think are the relevant commands found in the log:

2024-06-09 20:55:20.380 DEBUG (MainThread) [zigpy.application] Received a packet:
ZigbeePacket(timestamp=datetime.datetime(2024, 6, 10, 0, 55, 20, 380065, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xD9EC), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=6, data=Serialized[b'\x11[\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=25, rssi=None)

2024-06-09 20:55:20.381 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0006]
Received command 0x01 (TSN 91): on()

2024-06-09 20:55:20.420 DEBUG (MainThread) [zigpy.application] Received a packet:
ZigbeePacket(timestamp=datetime.datetime(2024, 6, 10, 0, 55, 20, 420295, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xD9EC), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.Group: 1>, address=0x000B), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=6, data=Serialized[b'\x11[\x01'], tx_options=<TransmitOptions.NONE: 0>, radius=10, non_member_radius=0, lqi=105, rssi=None)

2024-06-09 20:55:20.421 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0006]
Received command 0x01 (TSN 91): on()

2024-06-09 20:55:22.365 DEBUG (MainThread) [zigpy.application]
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 6, 10, 0, 55, 22, 365377, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xD9EC), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=64561, data=Serialized[b'\x15/\x12]\x00\x02\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=32, rssi=None)

2024-06-09 20:55:22.366 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0xfc31]
Received command 0x00 (TSN 93): button_event(button_pressed=2, press_type=0)

2024-06-09 20:55:22.778 DEBUG (MainThread) [zigpy.application] Received a packet:
ZigbeePacket(timestamp=datetime.datetime(2024, 6, 10, 0, 55, 22, 778242, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xD9EC), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.Group: 1>, address=0x000B), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=8, data=Serialized[b'\x11\\\x04\xfe\x05\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=11, non_member_radius=0, lqi=18, rssi=None)

2024-06-09 20:55:22.779 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0008]
Received command 0x04 (TSN 92): move_to_level_with_on_off(level=254, transition_time=5)

2024-06-09 20:55:22.847 DEBUG (MainThread) [zigpy.application] Received a packet:
ZigbeePacket(timestamp=datetime.datetime(2024, 6, 10, 0, 55, 22, 847682, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xD9EC), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=0, profile_id=260, cluster_id=8, data=Serialized[b'\x11\\\x04\xfe\x05\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=29, non_member_radius=0, lqi=47, rssi=None)

2024-06-09 20:55:22.848 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0008]
Received command 0x04 (TSN 92): move_to_level_with_on_off(level=254, transition_time=5)

The switch seems to be sending two on() and move_to_level_with_on_off() events. I think the separate commands are actually to the group it’s bound to (group 0x000B) and the coordinator, 0x0000), which I suppose makes sense. I’m not sure that’s actually related to the issue.

The button event here seems to come really long after the on events, and then the move_to_level events are processed. This is not fully consistent as some times it is much faster, and also sometimes the order that the commands are received is different. Another time I did the logs, the timing was:

2024-06-09 21:00:57.081 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0006]
Received command 0x01 (TSN 103): on()

2024-06-09 21:00:57.504 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:1:0x0008]
Received command 0x0A (TSN 107): Report_Attributes(attribute_reports=[Attribute(attrid=0x0000, value=TypeValue(type=uint8_t, value=254))])

2024-06-09 21:00:57.590 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0008]
Received command 0x04 (TSN 104): move_to_level_with_on_off(level=254, transition_time=5)

2024-06-09 21:00:57.606 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:1:0x0006]
Received command 0x0A (TSN 106): Report_Attributes(attribute_reports=[Attribute(attrid=0x0000, value=TypeValue(type=Bool, value=<Bool.true: 1>))])

2024-06-09 21:00:57.611 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0xfc31]
Received command 0x00 (TSN 105): button_event(button_pressed=2, press_type=0)

2024-06-09 21:00:57.617 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0006]
Received command 0x01 (TSN 103): on()

2024-06-09 21:00:57.629 DEBUG (MainThread) [zigpy.zcl] [0xD9EC:2:0x0008]
Received command 0x04 (TSN 104): move_to_level_with_on_off(level=254, transition_time=5)

I added in the Report_Attribute commands I noticed here in case this is related.

Are the timestamps reported in the zigbee packet added by the switch or ZHA? I think they are added by the switch when the packet is sent, in which case it’s not a ZHA or network issue. However, I will note that this delay is only being noticed when the switch is bound to a zigbee group (in this case, a large group), not when the switch is not bound to anything or when bound to just one or two lights.

I am noticing now these Report_Attributes commands in the log, and it’s making me wonder if the switch is waiting for something to be reported back to it before it sends the button_event (in which case it would take longer for a large group or when there is a bunch of network traffic). Is that possible?

Just a theory here. When binding to a group, the switch needs to be part of that group. So when you hit the button and the on command gets sent to the group, it would then receive that on command as a member of that group. Which then may be triggering it the second time.

I always put my switches in the group in practice, but AFAIK the only reason this is necessary is so that when you send a command from homekit/home assistant, you set both the switch and the lights into the same state. The Inovelli documents do not always have us putting the switch itself into the group.

For my tests above, while trying to figure out what is going on, I removed the switch from the group and only have it bound to the group. The switch is not part of the group. The zigbee group contains only hue bulbs.

That being said, my initial observation about the “double commands” I think was misleading — I don’t think the double commands are actually the issue. It’s one set of commands to the coordinator, and one to the zigbee group. I don’t know enough about zigbee protocol to know if the protocol should just be monitoring for the group command or something, but it doesn’t seem inherently wrong to me, nor does it seem like it should be the cause of any delay.

There are two delays I’m seeing:

  1. button_event is not the first event sent, and can happen as much as 2 seconds after the switch has already decided that a single button press has occurred and sent the “on”/“off” event to the zigbee group.
  2. the “on”/“off” event that is sent to the coordinator often is faster than button_event (which is why it seemed like the delay was improved by modifying the popular home assistant blueprint to listen to “on”/“off” instead of button_event), but this is still also often delayed

It’s unclear to me why the switch wouldn’t just send these all at once. Maybe (wildly speculating), given the ReadAttribute commands, it’s waiting to make sure that the commands were actually processed by the group before it passes the command on to the coordinator. This would explain why the delay is longer when the group is larger.

That could be OK if I weren’t trying to process the button press in home assistant as soon as possible. It seems that the button_event should get communicated to the coordinator as soon as possible.