Некорректное значение map6e

1

добрый день!
в апреле настроил сбор метрик из map6e при помощи telegraf в базу influxdb
всё собирается исправно, но в базе встречаются единичные аномальные значения, вот пример.
я выбрал все значения за июнь по топику /devices/wb-map12e_14/controls/Ch 1 Total AP energy

1687169751631304646 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 75.77961
1685566800458635749 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84889
1685566801511745128 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84895
1685566802569793310 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84902
1685566803574522290 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84907
1685566804651347847 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84914
1685566805660690295 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84921
1685566806731180713 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84926
1685566807750137600 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84933
1685566808725560973 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84938
1685566809797949603 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84945
1685566810782137371 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.8495
1685566811819383090 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84957
1685566812830476459 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84962
1685566813871084269 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84969
1685566814876810084 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84976
1685566815872490711 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84981
1685566816862676617 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84987
1685566817885704929 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.84993
1685566818995710643 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.85
1685566820057491875 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.85007
1685566821101028858 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.85013
1685566822158789080 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.85019
1685566823120877549 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.85025
1685566824128563327 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.85032
1685566825116286395 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.85037
1685566826149380146 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 369.85044

отсортировал по значению и вывел первые 30
видно что в понедельник, 19 июня 2023 г., 13:15:51.631 [GMT+03:00] в топике было значение 75.77961

вот как это выглядит в ряду значений без сортировки

1687168765615331276 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63328
1687168766580863136 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63361
1687168767634110552 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63401
1687168768720849428 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63442
1687168769733348157 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63474
1687168770693416879 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63514
1687168771721721982 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63547
1687169750048834932 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.54793
1687169751631304646 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 75.77961
1687169760140400183 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63739
1687169761503140466 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63743
1687169762510018140 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63745
1687169763529343595 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63749
1687169764546086543 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63751
1687169765625259941 orangepi3-lts /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63755

если перевести timestamp в дату, то так лучше видно проблемное место

2023-06-19 12:59:25 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63328
2023-06-19 12:59:26 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63361
2023-06-19 12:59:27 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63401
2023-06-19 12:59:28 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63442
2023-06-19 12:59:29 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63474
2023-06-19 12:59:30 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63514
2023-06-19 12:59:31 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63547
2023-06-19 13:15:50 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.54793
2023-06-19 13:15:51 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 75.77961
2023-06-19 13:16:00 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63739
2023-06-19 13:16:01 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63743
2023-06-19 13:16:02 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63745
2023-06-19 13:16:03 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63749
2023-06-19 13:16:04 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63751
2023-06-19 13:16:05 /devices/wb-map12e_14/controls/Ch 1 Total AP energy 474.63755

в 12:59:31, видимо, отключалось электричество, в 13:15:50 метрика снова появилась, видимо, электричество включили обратно, но при этом значение было меньше чем до выключения, хоть и несущественно, а дальше в 13:16:00 уже значение 75, что существенно меньше.

в связи с этим вопрос: как могло произойти такое? почему значение у счётчика уменьшилось? это же теоретически не должно быть возможным.

3

Добрый день.

Так, но запись в базу - это уже окончательный этап путешествия данных.
То есть счетчик-modbus-mqtt-telegraf-influx
На этапе modbus-mqtt если что-то шло не так можно спросить логи.
А нет ли логов (в принципе должны еще остаться) wb-mqtt-serial за указанное время?

На этапе mqtt - на контроллере (если не выключна) есть своя база данных, в ней информация за период есть?
Просто пока не могу даже предположить причину.

4

в БД контроллера хранится статистика за 3 дня максимум
логи посмотрел - тоже не осталось уже ничего.
ясно, вобщем пока что объяснения нет

5

На всякий случай - можно написать правило , которое будет срабатывать на обновление топика, если новое значение меньше прошлого - тогда писать в лог или генерировать аларм.
Если больше - тогда запоминать в переменной значение. Если повторится - можно понять что проблема еще на контроллере появляется.

6

OK! хорошая идея, сделаю так.

7

сегодня сгенерировал правила для всех используемых каналов, по такому принципу:

var telegram = require("telegram"); 
var ps = new PersistentStorage("virtual-test-device-storage", {global: true});


defineRule("wb-map12e_14/Ch 1 Total AP energy", {
  whenChanged: "wb-map12e_14/Ch 1 Total AP energy",
  then: function (newValue, devName, cellName) {
      if(ps['s14ch1'] !== 0 && !ps['s14ch1']){
          ps['s14ch1'] = newValue
          var msg = "значение устройства {} (канал {}) проинициализировано впервые - {}".format(devName, cellName, ps['s14ch1'])
          telegram.SendMessage(msg)
      }
      if (newValue >= ps['s14ch1']){
          ps['s14ch1'] = newValue
      } else {
          var msg = "значение устройства {} (канал {}) уменьшилось, было {}, стало {}".format(devName, cellName, ps['s14ch1'], newValue)
          telegram.SendMessage(msg)
      }
  }
});

и так далее по всем каналам
в итоге послали в ребут щит с оборудованием и через минуту включили, я выдернул из системы лог с включенным дебагом. вот ссылка на него mqtt.log.gz — Яндекс Диск
ребут произошёл в Jul 11 14:12:46, смотрите строчку 326271 и далее.

собственно, что я увидел в телеграм канале:

image
image450×621 21.6 KB

то есть, получается, что при рестарте железки в топике реально возникает малое значение, правда потом оно, судя по всему, восстанавливается, прошу подтвердить или опровергнуть это утвереждение.

спасибо!

1 лайк
8

Со включенным Debug все записи которые в MQTT драйвер делают в нем и отражаются.
Что интересно, поиск по подстроке Ch 1 Total AP energy’ of device 'wb-map12e_14 с момента запуска драйвера выдает первое

Jul 11 14:14:55 wirenboard-AGOQTP4Y wb-mqtt-serial[2270]: DEBUG: [serial port driver] channel 'Ch 1 Total AP energy' of device 'wb-map12e_14' <-- 589.93451, error: ""

И это значение - не 75.77961
То есть на момент запуска wb-mqtt-serial у mqtt откуда-то было значение…
Пока не знаю как воспроизвести. Нет никаких правил которые пишут в MQTT?
Еще вариант - добавить правило, которое с помощью trackMQTT подписывается на корень устройства /devices//wb-map12e_14 и пишет в лог все что в него публикуется.

9

@paulstrong
А что за контроллер и релиз? Можете прислать диагностический архив, чтобы нам не задавать много уточняющих вопросов? Интересны версии софта там.

10

правил, пишущих в mqtt - нет, единственные правила, которые есть, это те, что я создал для логирования в телеграм.
добавил правила trackMqtt, вот tgz с логами, тут греп по wb-mqtt-serial и отдельно греп по wb-rules - logs.tgz — Яндекс Диск
вот время ребута:

Jul 12 14:27:44 wirenboard-AGOQTP4Y wb-rules[2598]: INFO: [rule info] trackMqtt INFO => {"topic":"/devices/wb-map12e_14/controls/Ch 1 Total AP energy","value":"599.34107"}
Jul 12 14:27:45 wirenboard-AGOQTP4Y wb-rules[2598]: INFO: [rule info] trackMqtt INFO => {"value":"599.34129","topic":"/devices/wb-map12e_14/controls/Ch 1 Total AP energy"}
Jul 12 14:29:53 wirenboard-AGOQTP4Y wb-rules[2571]: INFO: [rule info] trackMqtt INFO => {"topic":"/devices/wb-map12e_14/controls/Ch 1 Total AP energy","value":"599.10719"}
Jul 12 14:29:54 wirenboard-AGOQTP4Y wb-rules[2571]: INFO: [rule info] trackMqtt INFO => {"topic":"/devices/wb-map12e_14/controls/Ch 1 Total AP energy","value":"75.77961"}
Jul 12 14:30:05 wirenboard-AGOQTP4Y wb-rules[2571]: INFO: [rule info] trackMqtt INFO => {"topic":"/devices/wb-map12e_14/controls/Ch 1 Total AP energy","value":"599.357"}
11

по совету от @BrainRoot включил trackMqtt, потом сделал диагностический архив, прикладываю - diag_output_AGOQTP4Y_2023-07-12-14.22.50.zip — Яндекс Диск
также сделал его еще раз после ребута, когда проблема в очередной раз воспроизвелась - diag_output_AGOQTP4Y_2023-07-12-14.36.55.zip — Яндекс Диск
вдруг в динамике что-то видно будет

1 лайк
12

обращу внимание, что я каждый раз наблюдаю одно и то же, сразу после ребута значение почти правильное (незначительно меньше предыдущего), затем через секунду - уже некорректное (причем оно одинаковое всегда 75.77961, но у каждого топика своё неправильное), потом 8-10 секунд временной провал (всегда), и далее уже пошли корректные значения

13

Призвал разработчиков. У меня что-то идеи кончились.

1 лайк
14
  1. Я правильно вас понимаю, что при перезагрузке контроллера, пропадает питание и на счётчиках?
  2. Если сделать systemctl restart wb-mqtt-serial, тоже будет скачёк?
  3. Не могли бы вы прислать файл /var/lib/wb-mqtt-serial/libwbmqtt.db
17
  1. да, правильно, счётчики обестачиваются вместе с контроллером
  2. при рестарте сервиса wb-mqtt-serial скачка не наблюдаю, а вот если рестартнуть wb-mqtt-serial mosquitto, тогда в телеграм прилетают отбивки о том, что значение уменьшилось, провал не большой, но он есть

image
image447×782 26.5 KB

также попробовал просто ребутнуть контроллер, отбивок в телеграм тоже не было

3.libwbmqtt.db.gz — Яндекс Диск

18

Архив не распаковывается, можете перезалить?

19

так это не архив, это сжатый файл, утилитой gzip
вот несжатая версия
libwbmqtt.db (52 КБ)

20

Можете ещё перезапустить всё, чтоб был скачёк.
Потом выполнить journalctl -b -u wb-mqtt-serial > log.txt и прислать файл нам.
Кажется, что проблема не в сервисе wb-mqtt-serial.

21
22

Спасибо! Проблема ясна. В testing’е мы сделали сохранение значений раз в минуту. При неожиданной потере питания будет опубликовано последнее зафиксированное за минуту значение, потом оно обновится до текущего.

23

то есть тикет закрываем, вы приняли меры?