Баг обработки первого сообщения от zigbee2mqtt после перезагрузки сервиса wb-rules.service

Wiren Board 8.5.1, release wb-2504 (as stable)

После перезагрузки сервиса wb-rules.service, первое сообщение от Zigbee-устройства замещается сохранённым

sudo systemctl restart wb-rules.service

Обнаружено при использовании пульта Moes Scene Switch ZS-SR-R01, у которого при коротком нажатии одной из 4-х кнопок прилетает 1_single, 2_single, 3_single, 4_single соответственно.

Начальные условия:

  • контроллер загружен
  • правила корректно обрабатываются
  • нажатия кнопок на пульте передаются в топик /devices/moes_sceneswitch_1/controls/action

Воспроизведение бага:

  • нажать на пульте кнопку 4, получив в топик значение 4_single
  • в консоли контроллера перезапустить сервис wb-rules.service
  • нажать на пульте кнопку 1, в топик прилетит значение 4_single

В попытках выяснить причины такого поведения, добавил логирование в функцию initTracker файла wb-zigbee2mqtt.js:

Модифицированный код

В результате обнаружил следующее поведение внутри wb-rules:

  • в момент подписки через trackMqtt на топик /devices/moes_sceneswitch_1/controls/action прилетает сохранённое значение 4_single (игнорируем)
  • при нажатии 1-й кнопки на пульте, initTracker устанавливает корректное значение 1_single, выдавая сообщение вида
wb-z2m: control NOT exists, setting value...
1_single

После чего в топик /devices/moes_sceneswitch_1/controls/action повторно прилетает сохранённое значение 4_single и метка времени last_seen соответствует моменту времени до перезагрузки сервиса. Последующие нажатия кнопок обрабатываются корректно.

В качестве эксперимента, подписался на отслеживание в коде правил двух топиков:

  • zigbee2mqtt/moes_sceneswitch_1
  • /devices/moes_sceneswitch_1/controls/action

Видно, что zigbee2mqtt отправляет новое значение 1_single, но перезагруженные правила первое нажатие кнопки трактуют как сохранённое 4_single.

Скриншот лога из веб-интерфейса контроллера

Добрый день. А что именно публикует в топик устройства z2m?

Добрый день. Стандартная связка zigbee2mqtt и wb-zigbee2mqtt, в этой части ничего не менялось. Глубже в коды контроллера пока что не вникал - работаю на сброшенной до заводских настроек и затем обновлённой до актуального состояния версии.

Код в сценариях wb-rules только прослушивает, на данном этапе в топики ничего не записывает.

zigbee2mqtt отправляет набор полей, конвертер wb-zigbee2mqtt при инициализации создаёт виртуальное устройство и следит за обновлением значений в контролах.

Первое искажённое значение как-то связано с инициализацией контрола на созданном wb-zigbee2mqtt виртуальном устройстве (контрол не существует до момента первого с перезапуска wb-rules.service нажатия на кнопку).

Вот я про это и спрашиваю. Что, какие записи в топики устрйоства публикует z2m? Подпишитсь на них, лучше с дататаймом, для того чтобы сопоставить с логами и покажите.

На запущенном контроллере, до перезапуска сервиса (последнее из серии нажатий).

> Информация из wb-zigbee2mqtt, initTracker
2025-07-16 21:46:38 wb-z2m: control EXISTS, setting value...
2025-07-16 21:46:38 4_single
> Обработка в скрипте wb-rules
2025-07-16 21:46:38 Handling "zigbee2mqtt/moes_sceneswitch_1"
2025-07-16 21:46:38 {"action":"4_single","battery":92,"last_seen":1752691495694,"linkquality":72,"voltage":2900}
2025-07-16 21:46:38 Handling "/devices/moes_sceneswitch_1/controls/action"
2025-07-16 21:46:38 Incoming value of "action": "4_single", stamp "1752691495694", passing
2025-07-16 21:46:38 Value of "action" trough getDevice(): "4_single"

Сразу после перезапуска wb-rules.service, момент подписки при инициализации скрипта:

> Обработка в скрипте wb-rules
2025-07-16 21:50:45 Handling "/devices/moes_sceneswitch_1/controls/action"
2025-07-16 21:50:45 Incoming value of "action": "4_single", stamp undefined, suppressing

Нажатие на 1-ю кнопку беспроводного пульта, спустя некоторое время:

> Обработка в скрипте wb-rules
2025-07-16 21:57:25 Handling "zigbee2mqtt/moes_sceneswitch_1"
2025-07-16 21:57:25 {"action":"1_single","battery":92,"last_seen":1752692142282,"linkquality":76,"voltage":2900}
> Информация из wb-zigbee2mqtt, initTracker
2025-07-16 21:57:25 wb-z2m: control NOT exists, setting value...
2025-07-16 21:57:25 1_single
> Обработка в скрипте wb-rules
2025-07-16 21:57:25 Handling "/devices/moes_sceneswitch_1/controls/action"
2025-07-16 21:57:25 Incoming value of "action": "4_single", stamp "1752691495694", passing
2025-07-16 21:57:25 Value of "action" trough getDevice(): "4_single"

Я планирую у себя воспроизвести. Для этого мне нужнно знать - что публикует сам z2m.
Подпишитесь так: Скрипт трижды отрабатывает одно сообщение топика zigbee2mqtt - #18 от пользователя BrainRoot
Ну и, как я понимаю - проблема в том что публикуется вместо “реального” события - то что публиковалось последним перед перезапуском wb-rules?

Да, «реальное» событие замещается старым.

mosquitto_sub -v -t zigbee2mqtt/moes_sceneswitch_1 -t /devices/moes_sceneswitch_1/controls/action

// Нажатие на кнопку 4 до перезапуска сервиса wb-rules.service
zigbee2mqtt/moes_sceneswitch_1 {"action":"4_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}
/devices/moes_sceneswitch_1/controls/action 4_single

// Первое нажатие на кнопку 1 после перезапуска сервиса
zigbee2mqtt/moes_sceneswitch_1 {"action":"1_single","battery":100,"last_seen":1752741438326,"linkquality":116,"voltage":3000}
/devices/moes_sceneswitch_1/controls/action 4_single

// Следующее нажатие на ту же кнопку
zigbee2mqtt/moes_sceneswitch_1 {"action":"1_single","battery":100,"last_seen":1752741445760,"linkquality":69,"voltage":3000}
/devices/moes_sceneswitch_1/controls/action 1_single

Отлично, то что нужно. И с описанием, благодарю.

Добрый день, удалось ли решить вопрос?