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

wihome · 16.Июль.2025 11:41:19

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.

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

BrainRoot · 16.Июль.2025 14:01:06

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

wihome · 16.Июль.2025 18:04:20

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

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

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

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

BrainRoot · 16.Июль.2025 18:07:45

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

wihome · 16.Июль.2025 19:02:26

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

> Информация из 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"

BrainRoot · 17.Июль.2025 08:26:11

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

wihome · 17.Июль.2025 08:46:43

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

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

BrainRoot · 17.Июль.2025 09:18:00

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

Aleksandr_Khlebnikov · 24.Июль.2025 10:37:45

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

BrainRoot · 11.Август.2025 09:18:33

У меня подобное не воспроизводится.
Публикую устройство:

mosquitto_pub -t zigbee2mqtt/bridge/devices -m '[{"date_code":"20201026","definition":{"description":"Wireless button","exposes":[{"access":5,"category":"diagnostic","description":"Remaining battery in %","label":"Battery","name":"battery","property":"battery","type":"numeric","unit":"%","value_max":100,"value_min":0},{"access":5,"category":"diagnostic","description":"Reported battery voltage in millivolts","label":"Voltage","name":"voltage","property":"voltage","type":"numeric","unit":"mV"},{"access":1,"category":"diagnostic","description":"Triggered action (e.g. a button click)","label":"Action","name":"action","property":"action","type":"enum","values":["single","double","long"]},{"access":1,"category":"diagnostic","description":"Link quality (signal strength)","label":"Linkquality","name":"linkquality","property":"linkquality","type":"numeric","unit":"lqi","value_max":255,"value_min":0}],"model":"SNZB-01","options":[],"supports_ota":false,"vendor":"SONOFF"},"disabled":false,"endpoints":{"1":{"bindings":[{"cluster":"genOnOff","target":{"endpoint":1,"ieee_address":"0x00124b001f31552a","type":"endpoint"}},{"cluster":"genPowerCfg","target":{"endpoint":1,"ieee_address":"0x00124b001f31552a","type":"endpoint"}}],"clusters":{"input":["genBasic","genIdentify","genPowerCfg"],"output":["genOnOff","genIdentify"]},"configured_reportings":[{"attribute":"batteryVoltage","cluster":"genPowerCfg","maximum_report_interval":7200,"minimum_report_interval":3600,"reportable_change":0},{"attribute":"batteryPercentageRemaining","cluster":"genPowerCfg","maximum_report_interval":7200,"minimum_report_interval":3600,"reportable_change":0}],"scenes":[]}},"friendly_name":"moes_sceneswitch_1","ieee_address":"0x00124b002454cd17","interview_completed":true,"interview_state":"SUCCESSFUL","interviewing":false,"manufacturer":"eWeLink","model_id":"WB01","network_address":22741,"power_source":"Battery","supported":true,"type":"EndDevice"}]'

публикую событие

mosquitto_pub -t zigbee2mqtt/moes_sceneswitch_1 -m '{"action":"4_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}'

Затем перезапускаю wb-rules и (после публикации устройства)

mosquitto_pub -t zigbee2mqtt/moes_sceneswitch_1 -m '{"action":"1_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}'

wihome · 11.Август.2025 12:37:01

Модифицировал wb-zigbee2mqtt и заставил его отдать то, что прилетает в Bridge Device для реального пульта Moes (адрес устройства изменён, также используется имя moes_sceneswitch_2, чтобы не пересекалось с существующим устройством).

Публикую устройство:

sudo mosquitto_pub -t zigbee2mqtt/bridge/devices -m '[{"date_code":"","definition":{"description":"Wireless switch with 4 buttons","exposes":[{"access":1,"category":"diagnostic","description":"Remaining battery in %, can take up to 24 hours before reported","label":"Battery","name":"battery","property":"battery","type":"numeric","unit":"%","value_max":100,"value_min":0},{"access":1,"category":"diagnostic","description":"Triggered action (e.g. a button click)","label":"Action","name":"action","property":"action","type":"enum","values":["1_single","1_double","1_hold","2_single","2_double","2_hold","3_single","3_double","3_hold","4_single","4_double","4_hold"]},{"access":1,"category":"diagnostic","description":"Link quality (signal strength)","label":"Linkquality","name":"linkquality","property":"linkquality","type":"numeric","unit":"lqi","value_max":255,"value_min":0}],"model":"TS0044","options":[],"supports_ota":false,"vendor":"Tuya"},"disabled":false,"endpoints":{"1":{"bindings":[],"clusters":{"input":["genBasic","genPowerCfg","genOnOff"],"output":["genOta","genTime"]},"configured_reportings":[],"scenes":[]},"2":{"bindings":[],"clusters":{"input":["genPowerCfg","genOnOff"],"output":[]},"configured_reportings":[],"scenes":[]},"3":{"bindings":[],"clusters":{"input":["genPowerCfg","genOnOff"],"output":[]},"configured_reportings":[],"scenes":[]},"4":{"bindings":[],"clusters":{"input":["genPowerCfg","genOnOff"],"output":[]},"configured_reportings":[],"scenes":[]}},"friendly_name":"moes_sceneswitch_2","ieee_address":"0x0000000000000001","interview_completed":true,"interview_state":"SUCCESSFUL","interviewing":false,"manufacturer":"_TZ3000_kfu8zapd","model_id":"TS0044","network_address":1022,"power_source":"Battery","supported":true,"type":"EndDevice"}]'

Подписываюсь на прослушивание топиков в соседней консоли:

sudo mosquitto_sub -v -t zigbee2mqtt/moes_sceneswitch_2 -t /devices/moes_sceneswitch_2/controls/action

Имитирую сигнал action: 4_single:

sudo mosquitto_pub -t zigbee2mqtt/moes_sceneswitch_2 -m '{"action":"4_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}'

Получаю:

zigbee2mqtt/moes_sceneswitch_2 {"action":"4_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}
/devices/moes_sceneswitch_2/controls/action 4_single

Перезагружаю wb-rules.service:

sudo systemctl restart wb-rules.service

Повторно публикую устройство, затем отправляю сигнал action: 1_single:

sudo mosquitto_pub -t zigbee2mqtt/moes_sceneswitch_2 -m '{"action":"1_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}'

Получаю:

zigbee2mqtt/moes_sceneswitch_2 {"action":"1_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}
/devices/moes_sceneswitch_2/controls/action 4_single

Наблюдается расхождение между переданным и полученным значениями.

BrainRoot · 11.Август.2025 13:03:25

Wired Home:

Повторно публикую устройство, затем отправляю сигнал action: 1_single:
sudo mosquitto_pub -t zigbee2mqtt/moes_sceneswitch_2 -m '{"action":"1_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}'

Так, а точно ли после перезапуска wb-rules топики устройств (/devices/moes_sceneswitch_2/) удаляются и пересоздаются? для чистоты эксперимента - выполните после остановки wb-rules и до запуска MQTT в контроллерах Wiren Board — Wiren Board

wihome · 11.Август.2025 13:17:52

Контрольная отправка значения перед остановкой сервиса, action: 4_single. Пришло 4_single.

Останавливаю сервис:

sudo systemctl stop wb-rules.service

Очищаю очередь сообщений:

sudo mqtt-delete-retained '/devices/moes_sceneswitch_2/#'

Соседняя консоль информирует:

/devices/moes_sceneswitch_2/controls/action (null)

Запускаю сервис:

sudo systemctl start wb-rules.service

Выполняю публикацию устройства:

sudo mosquitto_pub -t zigbee2mqtt/bridge/devices -m '[{"date_code":"","definition":{"description":"Wireless switch with 4 buttons","exposes":[{"access":1,"category":"diagnostic","description":"Remaining battery in %, can take up to 24 hours before reported","label":"Battery","name":"battery","property":"battery","type":"numeric","unit":"%","value_max":100,"value_min":0},{"access":1,"category":"diagnostic","description":"Triggered action (e.g. a button click)","label":"Action","name":"action","property":"action","type":"enum","values":["1_single","1_double","1_hold","2_single","2_double","2_hold","3_single","3_double","3_hold","4_single","4_double","4_hold"]},{"access":1,"category":"diagnostic","description":"Link quality (signal strength)","label":"Linkquality","name":"linkquality","property":"linkquality","type":"numeric","unit":"lqi","value_max":255,"value_min":0}],"model":"TS0044","options":[],"supports_ota":false,"vendor":"Tuya"},"disabled":false,"endpoints":{"1":{"bindings":[],"clusters":{"input":["genBasic","genPowerCfg","genOnOff"],"output":["genOta","genTime"]},"configured_reportings":[],"scenes":[]},"2":{"bindings":[],"clusters":{"input":["genPowerCfg","genOnOff"],"output":[]},"configured_reportings":[],"scenes":[]},"3":{"bindings":[],"clusters":{"input":["genPowerCfg","genOnOff"],"output":[]},"configured_reportings":[],"scenes":[]},"4":{"bindings":[],"clusters":{"input":["genPowerCfg","genOnOff"],"output":[]},"configured_reportings":[],"scenes":[]}},"friendly_name":"moes_sceneswitch_2","ieee_address":"0x0000000000000001","interview_completed":true,"interview_state":"SUCCESSFUL","interviewing":false,"manufacturer":"_TZ3000_kfu8zapd","model_id":"TS0044","network_address":1022,"power_source":"Battery","supported":true,"type":"EndDevice"}]'

Имитирую сигнал action: 1_single:

sudo mosquitto_pub -t zigbee2mqtt/moes_sceneswitch_2 -m '{"action":"1_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":300
0}'

Вывод соседней консоли:

zigbee2mqtt/moes_sceneswitch_2 {"action":"1_single","battery":100,"last_seen":1752741399642,"linkquality":76,"voltage":3000}
/devices/moes_sceneswitch_2/controls/action 4_single

Наблюдается расхождение между переданным и полученным значениями.

BrainRoot · 11.Август.2025 14:33:44

Обновите пакеты пожалуйста, актуальный релиз 2507. Если в нем воспроизведется - буду пробовать и у себя воспроизводить.

wihome · 11.Август.2025 14:42:54

Обновление до 2507 было выполнено пару дней назад, состояние ПО контроллера актуальное.

BrainRoot · 12.Август.2025 12:30:40

Воспроизвел синтетически.
Написал такое:

//08_12_test_01.js
function makeNewVirtualControl(vdName, nameControl, typeControl){
  if (getDevice(vdName) === undefined) {
    defineVirtualDevice(vdName, {
      title: vdName,
      cells: {},
    })
  } 
  else{
    log.debug("Устройство "+vdName+" уже есть.")
  }
     //Тут проверим есть ли уже контрол и если нет - создадим.
    if (!getDevice(vdName).isControlExists(nameControl)) {
      log.debug("Контрола "+nameControl+" нет, создаем.")
      getDevice(vdName).addControl(nameControl, typeControl);
    }
    else{
      log.debug("Контрол "+nameControl+" уже есть.")
    }
      
}

function makeRuleWithVirt(name, topick, virtDevName, virtDevParam){
  //создадим виртуальное
  makeNewVirtualControl(virtDevName, name, virtDevParam);
  //создадим правило
  trackMqtt(topick, function(message) {
    log.info("Сработал trackMqtt name: {}, value: {}".format(message.topic, message.value));
    //Записшем значение в виртуальное
    dev[virtDevName+"/"+name] = parseInt(message.value)
  });

}


makeRuleWithVirt("someValue", '/test/testvalue', "test_08_12", {type: "value", value: 0, readonly: true})

UPD: код почему-то не вставился.
Сделал

mosquitto_pub -t /test/testvalue -m 3

вижу в логе

2025-08-12 14:17:47Error in getting device: Device with given ID doesn't exist
2025-08-12 14:17:47Контрола someValue нет, создаем.
2025-08-12 14:44:53Сработал trackMqtt name: /test/testvalue, value: 3

Перезапускаю wb-rules.
Публикую другое значение

mosquitto_pub -t /test/testvalue -m 2

Вижу в логе.

2025-08-12 15:12:53Устройство test_08_12 уже есть.
2025-08-12 15:12:53Контрол someValue уже есть.
2025-08-12 15:13:02Сработал trackMqtt name: /test/testvalue, value: 2

При этом в топике виртуального устройства

То есть существует проблема с публикацией в созданные до перезапуска виртуальные устройства.
Описал ее разработчикам.

BrainRoot · 13.Август.2025 11:48:23

Еще покопаюсь, думаю что не все причины понял, это только одна.

BrainRoot · 28.Август.2025 12:37:13

Пока ничего нового не нашел. Tему закрываю, ждем исправления в wb-rules.

Тема		Ответов	Просм.
Скрипт трижды отрабатывает одно сообщение топика zigbee2mqtt Rule Engine	19	287	05.03.2024
Перестают работать wb-rules с ошибкой [wbgo_mqtt] MQTT token wait timeout: *mqtt.PublishToken Rule Engine	57	518	10.09.2025
Перестало работать правило, ошибка can't convert control Rule Engine	39	527	20.08.2024
Диковатый глюк в wb-rules Rule Engine	52	1147	21.12.2021
Сломаное виртуальное устройство	12	47	09.04.2025

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

Связанные темы