Теряется связь с контроллером WB8.4 или контроллер зависает

Запустил wb-rules руками, с флагом -debug

Через какое-то время сервис упал в логах вот это

20-06-2024 17:13:54.142 [wpa_supplicant]	wlan0: WPA: Group rekeying completed with 74:4d:28:be:55:ff [GTK=CCMP]
20-06-2024 17:13:54.140	RTW: send eapol packet - WPA Group Key 2/2
20-06-2024 17:13:54.139	RTW: set group key camid:2, addr:74:4d:28:be:55:ff, kid:2, type:AES
20-06-2024 17:13:54.132	RTW: recv eapol packet - WPA Group Key 1/2
20-06-2024 17:04:15.940 [wb-mqtt-serial]	WARNING: [modbus] failed to read 2 input(s) @ 1536 of device modbus:80: Serial protocol error: request timed out
20-06-2024 17:03:22.943 [mosquitto]	1718892202: Client rules-wirenboard-AFHCBGVX-448000 closed its connection.
20-06-2024 17:03:22.942 [mosquitto]	1718892202: Client wb-rules-engine-wirenboard-AFHCBGVX-448000 closed its connection.
20-06-2024 17:03:22.926 [session-27.scope]	DEBUG: [wbgo_mqtt] GOT MESSAGE: /devices/metrics/controls/load_average_1min --- 0.19
20-06-2024 17:03:22.715 [session-27.scope]	DEBUG: trying to invoke callback 15329 in context 0x4000090f30
20-06-2024 17:03:22.700 [session-27.scope]	DEBUG: store callback 15329 at context 0x4000090f30
20-06-2024 17:03:22.699 [session-27.scope]	DEBUG: trying to invoke callback 15328 in context 0x4000090f30
20-06-2024 17:03:22.699 [session-27.scope]	DEBUG: [ruleengine] RulesLists for all: map[{battery Reset}:[0x400026ce60] {buzzer enabled}:[0x40004ebf90] {buzzer frequency}:[0x40004ebf40] {buzzer volume}:[0x40004ebf40] {power_status working on battery}:[0x4000248cd0] {system Reboot}:[0x40002fa0a0] {wb-adc Vin}:[0x4000248cd0]]
20-06-2024 17:03:22.699 [session-27.scope]	DEBUG: [ruleengine] RunRules, event  &{{power_status working on battery} true true false false} , timer
20-06-2024 17:03:22.698 [session-27.scope]	DEBUG: [backend] MSG: 0
20-06-2024 17:03:22.698 [session-27.scope]	DEBUG: [backend] MSG: 0
20-06-2024 17:03:22.698 [session-27.scope]	DEBUG: [backend] handleControlValue() topic: /devices/power_status/controls/working on battery
20-06-2024 17:03:22.698 [session-27.scope]	DEBUG: [wbgo_mqtt] GOT MESSAGE: /devices/power_status/controls/working on battery --- 0
20-06-2024 17:03:22.697 [session-27.scope]	DEBUG: rule engine: running rules after control change: {power_status working on battery}
20-06-2024 17:03:22.697 [session-27.scope]	DEBUG: control change: {power_status working on battery}
20-06-2024 17:03:22.697 [session-27.scope]	DEBUG: [tx 0x40002663b0] End()
20-06-2024 17:03:22.697 [session-27.scope]	DEBUG: [engine] driverEventHandler(event wbgong.ControlValueEvent(ControlValueEvent{Device:power_status,Control:working on battery,Value:0->0}))
20-06-2024 17:03:22.696 [session-27.scope]	DEBUG: [wbgo_mqtt] PUB: /devices/power_status/controls/working on battery -> 0

При падении нет никакой осмысленной ошибки.
Последнее сообщение от сервиса в 20-06-2024 17:03:22.926

Что-то мне не нравится

20-06-2024 17:03:22.698 [session-27.scope]	DEBUG: [wbgo_mqtt] GOT MESSAGE: /devices/power_status/controls/working on battery --- 0
20-06-2024 17:03:22.697 [session-27.scope]	DEBUG: rule engine: running rules after control change: {power_status working on battery}
20-06-2024 17:03:22.697 [session-27.scope]	DEBUG: control change: {power_status working on battery}
20-06-2024 17:03:22.697 [session-27.scope]	DEBUG: [tx 0x40002663b0] End()
20-06-2024 17:03:22.697 [session-27.scope]	DEBUG: [engine] driverEventHandler(event wbgong.ControlValueEvent(ControlValueEvent{Device:power_status,Control:working on battery,Value:0->0}))
20-06-2024 17:03:22.696 [session-27.scope]	DEBUG: [wbgo_mqtt] PUB: /devices/power_status/controls/working on battery -> 0

То что сообщения при батарейку.
Позову разработчиков.

а еще меня очень смущает большое количество таймаутов mqtt в логах

а я вынул батарейку неделю назад, и выключил ее в настройках. До сих пор не поставил. Может в этом дело.

Так, а покажите что в этих топиках?
Вывод

timeout 5 mosquitto_sub -v -t '/devices/power_status/#'

Для проверки - очистите все retained топики

mqtt-delete-retained '/#' && reboot

Ну и проверим, будет ли воспроизводится.
Хотя - начать можно с

mqtt-delete-retained '/devices/power_status/#'

и без перезапуска.

➜  ~ ssh root@192.168.1.205
root@192.168.1.205's password:
          _                _                         _
__      _(_)_ __ ___ _ __ | |__   ___   __ _ _ __ __| |
\ \ /\ / / | '__/ _ \ '_ \| '_ \ / _ \ / _` | '__/ _` |
 \ V  V /| | | |  __/ | | | |_) | (_) | (_| | | | (_| |
  \_/\_/ |_|_|  \___|_| |_|_.__/ \___/ \__,_|_|  \__,_|

Welcome to Wiren Board 8.4.3 (s/n AFHCBGVX), release unstable.latest (as testing)
Linux wirenboard-AFHCBGVX 6.8.0-wb7 #24 SMP Tue Jun 18 09:25:18 UTC 2024 aarch64 GNU/Linux

System load:   0.94 0.30 0.10	Up time:       0 min
Memory usage:  5% of 3.84G  	Usage of /:    38% of 2.0G   	/mnt/data:     4% of 55G

Last login: Thu Jun 20 15:49:47 2024 from 192.168.1.105
root@wirenboard-AFHCBGVX:~#
root@wirenboard-AFHCBGVX:~# mqtt-delete-retained '/devices/power_status/#'
100%|█████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 13/13 [00:00<00:00, 1659.44it/s]
root@wirenboard-AFHCBGVX:~#
root@wirenboard-AFHCBGVX:~#
root@wirenboard-AFHCBGVX:~# timeout 5 mosquitto_sub -v -t '/devices/power_status/#'
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
root@wirenboard-AFHCBGVX:~#

Так, у меня выдает конвенционные топики:

 timeout 5 mosquitto_sub -v -t '/devices/power_status/#'
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery/meta {"order":2,"readonly":true,"title":{"en":"Working on battery","ru":"Работа от батареи"},"type":"switch"}
/devices/power_status/controls/working on battery/meta/type switch
/devices/power_status/controls/working on battery/meta/order 2
/devices/power_status/controls/working on battery/meta/readonly 1
/devices/power_status/controls/Vin 24.6
/devices/power_status/controls/Vin/meta {"order":1,"readonly":true,"title":{"en":"Input voltage","ru":"Входное напряжение"},"type":"voltage"}
/devices/power_status/controls/Vin/meta/type voltage
/devices/power_status/controls/Vin/meta/order 1
/devices/power_status/controls/Vin/meta/readonly 1
/devices/power_status/meta {"driver":"wb-rules","title":{"en":"Power status","ru":"Статус питания"}}
/devices/power_status/meta/name Power status
/devices/power_status/meta/driver wb-rules
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0

Батарейки нет и не конфигурировалась.
Предположу что и напряжение не показывает в “устройствах”?

Что-то показывает

приложен диагностический архив, доступен только сотрудникам поддержки
(320,6 КБ)

Контроллер работает, пока ни разу не завис с момента переключения на testing.
После очистки retained топиков сервис больше не перезапускается.
Сейчас еще раз выполнил команду, и вот что вывело:

root@wirenboard-AFHCBGVX:~# timeout mosquitto_sub -v -t '/devices/power_status/#'#'
/devices/power_status/meta {"driver":"wb-rules","title":{"en":"Power status","ru":"Статус питания"}}
/devices/power_status/meta/name Power status
/devices/power_status/meta/driver wb-rules
/devices/power_status/controls/Vin 13.1
/devices/power_status/controls/Vin/meta {"order":1,"readonly":true,"title":{"en":"Input voltage","ru":"Входное напряжение"},"type":"voltage"}
/devices/power_status/controls/Vin/meta/type voltage
/devices/power_status/controls/Vin/meta/order 1
/devices/power_status/controls/Vin/meta/readonly 1
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery/meta {"order":2,"readonly":true,"title":{"en":"Working on battery","ru":"Работа от батареи"},"type":"switch"}
/devices/power_status/controls/working on battery/meta/type switch
/devices/power_status/controls/working on battery/meta/order 2
/devices/power_status/controls/working on battery/meta/readonly 1
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
/devices/power_status/controls/working on battery 0
root@wirenboard-AFHCBGVX:~#

Выглядит, как будто все в порядке. Таймаутов тоже не видел в логах больше.
Есть один нюанс после переключения на testing:

apt-get update работает долго, затем

root@wirenboard-AFHCBGVX:~# apt-get update
Сущ:1 http://debian-mirror.wirenboard.com/debian bullseye InRelease
Сущ:2 https://deb.nodesource.com/node_16.x bullseye InRelease
Сущ:3 http://debian-mirror.wirenboard.com/debian bullseye-updates InRelease
Сущ:4 http://debian-mirror.wirenboard.com/debian bullseye-backports InRelease
Сущ:5 http://debian-mirror.wirenboard.com/debian-security bullseye-security InRelease
Пол:6 http://deb.wirenboard.com/wb8/bullseye testing InRelease [3 943 B]
Пол:7 http://deb.wirenboard.com/wb8/bullseye testing/main arm64 Packages [37,7 kB]
Получено 41,6 kB за 3с (12,1 kB/s)
Чтение списков пакетов… Готово
N: Пропускается получение настроенного файла «main/binary-armhf/Packages», так как репозиторий «http://deb.wirenboard.com/wb8/bullseye testing InRelease» не поддерживает архитектуру «armhf»
root@wirenboard-AFHCBGVX:~#

Таймауты стали появляться реже

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

Да, так оно и выглядит в норме.

Да, в WB8 ведь уже

dpkg --print-architecture
arm64

Но это думаю уберут.

А это - исключительно аппаратный вопрос.
Путь единичного запроса такой:
Порт контроллера → устройство.
Если устройство получило удачно запрос (верный CRC) - то оно отвечает. Если что-то с запросом не так (несуществующий регистр но CRC верен) - ответит ошибкой. Если в пакете не совпадает CRC - то молчит.
Это как раз основная причина таймаутов, если устройство “правильное”. Наши - правильные.
А вот если устройство удачно получило запрос но его ответ получен контроллером с ошибкой - как раз и будет запись в лог “invalid CRC”/
Из скриншота понятно что устройство 80 не получало 4 раза а 69 - получило запрос удачно но его ответ испорчен.

Сейачс перестали работать зеркала… ну почему все такое ненадежное?

root@wirenboard-AFHCBGVX:~# ping 8.8.8.8
PING 8.8.8.8 (8.8.8.8) 56(84) bytes of data.
64 bytes from 8.8.8.8: icmp_seq=1 ttl=102 time=24.1 ms
64 bytes from 8.8.8.8: icmp_seq=2 ttl=102 time=25.2 ms
^C
--- 8.8.8.8 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1001ms
rtt min/avg/max/mdev = 24.114/24.662/25.211/0.548 ms
root@wirenboard-AFHCBGVX:~# apt-get update
Ошб:1 https://deb.nodesource.com/node_16.x bullseye InRelease
  Certificate verification failed: The certificate is NOT trusted. The certificate chain uses not yet valid certificate.  Could not handshake: Error in the certificate verification. [IP: 104.22.4.26 443]
Сущ:2 http://debian-mirror.wirenboard.com/debian bullseye InRelease
Сущ:3 http://debian-mirror.wirenboard.com/debian bullseye-updates InRelease
Сущ:4 http://debian-mirror.wirenboard.com/debian bullseye-backports InRelease
Сущ:5 http://debian-mirror.wirenboard.com/debian-security bullseye-security InRelease
Пол:6 http://deb.wirenboard.com/wb8/bullseye testing InRelease [3 943 B]
Чтение списков пакетов… Готово
E: Файл Release для http://debian-mirror.wirenboard.com/debian/dists/bullseye/InRelease пока не действителен (недостоверный ещё 236д 21ч 41мин 58с). Обновление этого репозитория производиться не будет.
E: Файл Release для http://debian-mirror.wirenboard.com/debian/dists/bullseye-updates/InRelease пока не действителен (недостоверный ещё 368д 17ч 12мин 3с). Обновление этого репозитория производиться не будет.
E: Файл Release для http://debian-mirror.wirenboard.com/debian/dists/bullseye-backports/InRelease пока не действителен (недостоверный ещё 368д 17ч 12мин 2с). Обновление этого репозитория производиться не будет.
E: Файл Release для http://debian-mirror.wirenboard.com/debian-security/dists/bullseye-security/InRelease пока не действителен (недостоверный ещё 368д 19ч 17мин 59с). Обновление этого репозитория производиться не будет.
E: Файл Release для http://deb.wirenboard.com/wb8/bullseye/dists/testing/InRelease пока не действителен (недостоверный ещё 368д 21ч 14мин 39с). Обновление этого репозитория производиться не будет.
root@wirenboard-AFHCBGVX:~# curl -X GET https://104.22.5.26:443 -v
Note: Unnecessary use of -X or --request, GET is already inferred.
*   Trying 104.22.5.26:443...
* Connected to 104.22.5.26 (104.22.5.26) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*  CAfile: /etc/ssl/certs/ca-certificates.crt
*  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS alert, handshake failure (552):
* error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure
* Closing connection 0
curl: (35) error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure
root@wirenboard-AFHCBGVX:~#

А какое время выставлено на контроллере?

время верное “сейчас”, вероятно была проблема, что после перезапуска не сразу пришло время от моего локального ntp. Хотя я же точно настраивал rtc, но сейчас в rtc нули…

В общем тема из топика решена, контроллер больше не зависает, все работает более менее стабильно. Буду ждать обновлений в стабильном релизе и ставить в шкаф.

Спасибо большое за поддержку!

1 лайк

Попробую воспроизвести, установлю RTC в неверное и проверю. Пожалуйста, рад помочь. Приятно общаться со специалистом и благодарю за помощь в отладке нового контроллера.

Добрый день, скажите, а когда фиксы по этому тикету (зависание устройства) поедут в stable?

Бэкпорт сделан, так что уже примерно неделю как в стабильном.

1 лайк