Erratic button event sequence from Ikea Rodret (E2201)

[protyposis]

What happened?

The Ikea Rodret dimmer (Koenkk/zigbee-herdsman-converters#5964) sends key-press commands repeatedly, e.g., multiple commands for a single press. The sequence seems to depend on the history of key-presses which happened earlier. For example, pressing on can result in a sequence like on/on/off/on. If automated through HA, this results in crazy light effects 😅

Here is an example log of the off button pressed once:

Debug 2023-12-04 18:58:17Received Zigbee message from 'Switch14', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Info 2023-12-04 18:58:17MQTT publish: topic 'zigbee2mqtt/Switch14', payload '{"action":null,"battery":100,"last_seen":"2023-12-04T17:58:17.755Z","linkquality":47,"update":{"installed_version":16777287,"latest_version":16777287,"state":"idle"},"update_available":false}'
Debug 2023-12-04 18:58:17Received Zigbee message from 'Switch14', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Info 2023-12-04 18:58:18MQTT publish: topic 'zigbee2mqtt/Switch14', payload '{"action":"off","battery":100,"last_seen":"2023-12-04T17:58:17.894Z","linkquality":47,"update":{"installed_version":16777287,"latest_version":16777287,"state":"idle"},"update_available":false}'
Info 2023-12-04 18:58:18MQTT publish: topic 'zigbee2mqtt/Switch14', payload '{"action":"","battery":100,"last_seen":"2023-12-04T17:58:17.894Z","linkquality":47,"update":{"installed_version":16777287,"latest_version":16777287,"state":"idle"},"update_available":false}'
Info 2023-12-04 18:58:18MQTT publish: topic 'zigbee2mqtt/Switch14/action', payload 'off'
Debug 2023-12-04 18:58:27Received Zigbee message from 'Switch14', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Info 2023-12-04 18:58:27MQTT publish: topic 'zigbee2mqtt/Switch14', payload '{"action":"off","battery":100,"last_seen":"2023-12-04T17:58:26.995Z","linkquality":83,"update":{"installed_version":16777287,"latest_version":16777287,"state":"idle"},"update_available":false}'
Info 2023-12-04 18:58:27MQTT publish: topic 'zigbee2mqtt/Switch14', payload '{"action":"","battery":100,"last_seen":"2023-12-04T17:58:26.995Z","linkquality":83,"update":{"installed_version":16777287,"latest_version":16777287,"state":"idle"},"update_available":false}'
Info 2023-12-04 18:58:27MQTT publish: topic 'zigbee2mqtt/Switch14/action', payload 'off'
Debug 2023-12-04 18:58:27Received Zigbee message from 'Switch14', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Info 2023-12-04 18:58:27MQTT publish: topic 'zigbee2mqtt/Switch14', payload '{"action":"off","battery":100,"last_seen":"2023-12-04T17:58:27.146Z","linkquality":83,"update":{"installed_version":16777287,"latest_version":16777287,"state":"idle"},"update_available":false}'
Info 2023-12-04 18:58:27MQTT publish: topic 'zigbee2mqtt/Switch14', payload '{"action":"","battery":100,"last_seen":"2023-12-04T17:58:27.146Z","linkquality":83,"update":{"installed_version":16777287,"latest_version":16777287,"state":"idle"},"update_available":false}'
Info 2023-12-04 18:58:27MQTT publish: topic 'zigbee2mqtt/Switch14/action', payload 'off'
Debug 2023-12-04 18:58:36Received Zigbee message from 'Switch14', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Info 2023-12-04 18:58:36MQTT publish: topic 'zigbee2mqtt/Switch14', payload '{"action":null,"battery":100,"last_seen":"2023-12-04T17:58:36.238Z","linkquality":51,"update":{"installed_version":16777287,"latest_version":16777287,"state":"idle"},"update_available":false}'

There are five commandOff commands, resulting in multiple MQTT action messages.

The same happens for the on and brightness commands. Here is another example log of an on/dim_up/dim_release/on/off key-press sequence (only the Zigbee messages):

2023-12-04 19:47:32Received Zigbee message from 'Switch14', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-04 19:47:34Received Zigbee message from 'Switch14', type 'commandMoveWithOnOff', cluster 'genLevelCtrl', data '{"movemode":0,"rate":83}' from endpoint 1 with groupID 0
2023-12-04 19:47:35Received Zigbee message from 'Switch14', type 'commandStopWithOnOff', cluster 'genLevelCtrl', data '{}' from endpoint 1 with groupID 0
2023-12-04 19:47:36Received Zigbee message from 'Switch14', type 'commandMoveWithOnOff', cluster 'genLevelCtrl', data '{"movemode":0,"rate":83}' from endpoint 1 with groupID 0 // unexpected
2023-12-04 19:47:36Received Zigbee message from 'Switch14', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-04 19:47:37Received Zigbee message from 'Switch14', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-04 19:47:44Received Zigbee message from 'Switch14', type 'commandMoveWithOnOff', cluster 'genLevelCtrl', data '{"movemode":0,"rate":83}' from endpoint 1 with groupID 0 // unexpected
2023-12-04 19:47:46Received Zigbee message from 'Switch14', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0 // unexpected
2023-12-04 19:47:55Received Zigbee message from 'Switch14', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0 // unexpected

The logs show 4 unexpectedly repeated commands, and a few more happened later.

Similar behavior of the Ikea Symfonisk remote is described in #18013 (comment) and #17195.

What did you expect to happen?

Every key-press action should only be published once.

How to reproduce it (minimal and precise)

Pair the switch (firmware 1.0.47), press buttons and check logs.

Zigbee2MQTT version

1.34.0

Adapter firmware version

20221226

Adapter

Sonoff ZBDongle-P

Debug log

No response

[Koenkk]

Could you provide the herdsman debug log of this?

See this on how to enable the herdsman debug logging. Note that this is only logged to STDOUT and not to log files.

[protyposis]

I rebooted the system and the problem is gone. That probably explains why not everybody in the linked issues saw the behavior. I'll post the logs when the problem reappears and close this issue until then. Thanks for your help!

[protyposis]

I paired a new Rodret today and it happened again. Here's an example with herdsman logs:

I pressed the following button sequence:

• 4x on
• 4x off
• 4x on
• 4x off

The following sequence was logged by Z2M:

2023-12-14 13:12:50Received Zigbee message from 'Switch16', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:12:51Received Zigbee message from 'Switch16', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:12:51Received Zigbee message from 'Switch16', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:12:52Received Zigbee message from 'Switch16', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:12:52Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:12:53Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:12:53Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:12:54Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:01Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0 // unexpected
2023-12-14 13:13:01Received Zigbee message from 'Switch16', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:01Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0 // unexpected
2023-12-14 13:13:01Received Zigbee message from 'Switch16', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:02Received Zigbee message from 'Switch16', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:02Received Zigbee message from 'Switch16', type 'commandOn', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:03Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:04Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:04Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:05Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
2023-12-14 13:13:13Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0 // unexpected
2023-12-14 13:13:14Received Zigbee message from 'Switch16', type 'commandOff', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0 // unexpected

So there are 4 unexpected events. Herdsman log: _addon_45df7312_zigbee2mqtt_logs.txt

Sometimes this can get much worse with a "storm" of unexpected events. I haven't noticed a pattern, but the unexpected events always seem to be kind of replays from past button presses.

Interestingly, restarting the Z2M container doesn't fix it, but rebooting the system does (as also reported in my previous post). Maybe it's related to the coordinator?

[protyposis]

Paired another one. Same issue, disconnecting/reconnecting the coordinator fixes it.

[Koenkk]

Please provide the herdsman debug log

See this on how to enable the herdsman debug logging. Note that this is only logged to STDOUT and not to log files.

[protyposis]

Logs are attached above in #20024 (comment)

[Koenkk]

Pushed a possible fix!

Changes will be available in the dev branch in a few hours from now.

[protyposis]

I paired another one today and wasn't able to reproduce the issue - so I guess I can confirm that your fix works :) Thank you!