Множественные ошибки Can't get firmware info for

Имею многострадальный ESP-domofon (Slave Id 137) висящий на шине RS-485-1. Висит он там один. Все остальные реле живут на шине 2. На что сегодня обратил внимание:
Зашел в настройки Serial устройств, немного поиграл с настройками реле на второй шине, после чего перешел в логи и заметил множество ошибок

INFO: [serial device] device modbus:137 is connected
[WARNING] Can't get firmware info for 137 (/dev/ttyRS485-1 9600 8N2): Request timeout [-32600]: Serial protocol error: request timed out
[WARNING] Can't get firmware info for 137 (/dev/ttyRS485-1 9600 8N2): Request timeout [-32600]: Serial protocol error: request timed out
...
[WARNING] Can't get firmware info for 137 (/dev/ttyRS485-1 9600 8N2): Request timeout [-32600]: Serial protocol error: request timed out
WARNING: [modbus] failed to read 1 coil(s) @ 1 of device modbus:137: Serial protocol error: request timed out
WARNING: [modbus] failed to read 7 coil(s) @ 4 of device modbus:137: Serial protocol error: request timed out
WARNING: [modbus] failed to read 1 holding(s) @ 11 of device modbus:137: Serial protocol error: malformed response: invalid data size
WARNING: [serial device] device modbus:137 is disconnected
INFO: [serial device] device modbus:137 is connected

После непродолжительного наблюдения отключил шину номер 1, ошибки больше не появлялись.

Выявил следующую закономерность. Если включить шину или чтение устройства, затем покинуть страницу “настройки Serial устройств”, то ошибки в логах нет, устройство, вроде как, работает. Но как только я возвращаюсь на страницу “настройки Serial устройств”, а затем обратно в логи, логи начинают засоряться сообщениями, как выше. В чем может быть причина?
Прикладываю диагностический архив

Шина 1 настроена с параметрами для ESPDomofon, скорость 9600 бод, 8 битов, без битов четности, два стоп бита

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

Добрый день.

Сервис пытается прочитать из устройства его версию.
Так как у устройства нет соответствующих регистров - то ему это не удается о чем и написано в логе.
А какого поведения ожидаете?

Зачем он это делает так часто? Там же по 10 сообщений каждые 5 секунд, есть вариант это отключить для устройства?

потому что устройство не отвечает. Точнее - оно гененрует ошибки

Dec 15 19:34:30 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: INFO: [serial device] device modbus:137 is connected
Dec 15 19:34:32 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 1 holding(s) @ 120 of device modbus:137: Serial protocol error: request timed out
Dec 15 19:34:32 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 1 coil(s) @ 1 of device modbus:137: Serial protocol error: request timed out
Dec 15 19:34:33 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 7 coil(s) @ 4 of device modbus:137: Serial protocol error: malformed response: invalid data size
Dec 15 19:34:33 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [serial device] device modbus:137 is disconnected
Dec 15 19:34:34 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: INFO: [serial device] device modbus:137 is connected
Dec 15 19:34:36 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 1 coil(s) @ 1 of device modbus:137: Serial protocol error: request timed out
Dec 15 19:34:36 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 7 coil(s) @ 4 of device modbus:137: Serial protocol error: request timed out
Dec 15 19:34:37 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 1 holding(s) @ 11 of device modbus:137: Serial protocol error: malformed response: invalid data size
Dec 15 19:34:37 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [serial device] device modbus:137 is disconnected
Dec 15 19:34:38 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: INFO: [serial device] device modbus:137 is connected
Dec 15 19:34:40 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 7 coil(s) @ 4 of device modbus:137: Serial protocol error: request timed out
Dec 15 19:34:40 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 1 holding(s) @ 11 of device modbus:137: Serial protocol error: request timed out
Dec 15 19:34:41 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [modbus] failed to read 1 holding(s) @ 110 of device modbus:137: Serial protocol error: malformed response: invalid data size
Dec 15 19:34:41 wirenboard-A7IGKSOX wb-mqtt-serial[3633053]: WARNING: [serial device] device modbus:137 is disconnected

практически постоянно. То есть - ошибок столько что “переподключается”. Событие переподключения - вызывает новую попытку чтения версии.
То есть на подключенном устройстве без ошибок попытка чтения версии только одна.
Оптимально - все ж настроить порт (само устройство) на работу без ошибок, думаю.

1 Like

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

Потом, прошли почти сутки, у меня открыта только страница с логами (Системный журнал) и всего 7 предупреждений по устройству с довольно высоким интервалом, не то что бы прям устройство совсем не корректно работает. Да, предупреждений больше, чем по другим устройствам, но не выглядит как большая проблема.

Прикладываю еще один диагностический архив

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

Включите пожалуйста debug для wb-mqtt-serial.
После запуска - подождите 5-7 минут и зайдите в настройки. Ну и еще на несколько минут оставьте.
Загрузите сюда лог wb-mqtt-serial за весь период, с момента запуска с ним.

Прикладываю логи в архиве, так как ограничения на загрузку файлов 10Мб

debug-log-file.txt.zip (858,0 КБ)

Уже более понятно
То есть на запрос

вместо ожидемого ответа иногда

Dec 17 13:13:26 wirenboard-A7IGKSOX wb-mqtt-serial[1291897]: DEBUG: [port] /dev/ttyRS485-1: ReadFrame: 00
Dec 17 13:13:26 wirenboard-A7IGKSOX wb-mqtt-serial[1291897]: WARNING: [modbus] failed to read 1 holding(s) @ 120 of device modbus:137: Serial protocol error: malformed response: invalid data size
Dec 17 13:13:26 wirenboard-A7IGKSOX wb-mqtt-serial[1291897]: WARNING: [serial device] device modbus:137 is disconnected

На этой шине, первой, установлен терминатор?

За время лога, 13 минут вижу 70 событий когда драйвер считает устройство отключенным-подключенным.
И попыток опроса версии прошивки - только один, так что мое предположение не подтвердилось.

ESP-Domofon подключен коротким куском витой пары (не более 10 см) с толстыми жилами и после ESP-Domofon стоит терминатор.

Есть возможность вообще отключить опрос версии прошивки для этого устройства? На крайний случай, вообще для всех устройств, потому как с обновлением загрузчика и/или прошивки из web интерфейса у меня всегда проблема: устройства, при обновлении последнее время, всегда падают в ошибку и приходится их восстанавливать из командной строки (подключаться по ssh к контроллеру и делать это командами). Последнее время не рискую и как только вижу новую версию, обновляю руками

Я вообще не видел в приложенном логе опроса версии.
В шаблоне нет “signature” - поэтому для него это, опрос версии и неактуален.

Ну и ошибок вида “Can’t get firmware info” для устройства 137 тоже в логе нет.

Сейчас собрал логи в debug режиме опять. Действительно, сейчас предупреждений нет, но завал логов сообщениями не в debug режиме всё еще есть. При включении debug’а количество предупреждений уменьшается.

Делал следующим образом: зашел на страницу “Настройка драйвера Serial-устройств”, в настройки ESP-Domofon, вернулся в логи, увидел предупреждения, вернулся и включил debug, сидел на странице ESP-Domofon. Логи прилагаю. Если выключить debug, спама в логах нет, но как только ухожу на страницу ESP-Domofon опять начинается

debug-log-file-2.txt (6,4 МБ)

Для полноценного анализа еще бы время знать, в которое происходит что-то неожиданное.
Лог начинается в 14:55:30 и заканчивается в 14:59:37

Какой сервис пишет в лог? Подозреваю что wb-device-manager.
Покажите его лог тоже.

Первый лог собирал командой

journalctl --no-pager -u wb-mqtt-serial --since "2025-12-18 14:55:33" --until "2025-12-18 15:00:00" >> /tmp/debug-log-file-2.txt

Прикладываю лог

journalctl --no-pager -u wb-device-manager --since "2025-12-18 14:55:33" --until "2025-12-18 15:00:00" >> /tmp/debug-log-device-manager.txt

собирал в течении 5 минут почти как вчера, только там немного другой сценарий был

debug-log-device-manager.txt (42,5 КБ)

Пытаюсь воспроизвести.
Для этого сконфигурировал устройство но не поключал.
Вижу:

Dec 18 10:37:39 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:37:59 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:38:19 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:38:39 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:38:59 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:39:19 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:39:39 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:39:59 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:39:59 wirenboard-AC4U5OVN systemd[1]: Starting Cleanup of Temporary Directories...
Dec 18 10:39:59 wirenboard-AC4U5OVN systemd[1]: systemd-tmpfiles-clean.service: Succeeded.
Dec 18 10:39:59 wirenboard-AC4U5OVN systemd[1]: Finished Cleanup of Temporary Directories.
Dec 18 10:40:19 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:40:39 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:40:50 wirenboard-AC4U5OVN wb-device-manager[64909]: [WARNING] Can't get firmware info for slave id: 112, /dev/ttyRS485-1 9600 8N2: Request timeout [-32600]: Serial protocol error: request timed out
Dec 18 10:40:59 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:41:19 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:41:39 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:41:59 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors
Dec 18 10:42:19 wirenboard-AC4U5OVN wb-mqtt-serial[2426110]: WARNING: </dev/ttyRS485-1 9600 8 N 2>: closed due to repetitive errors

Одну попытку запроса.
Если устройство подключаю - то при смене его статуса на “подключенное” - еще одну попытку запроса, успешную.
В общем - проблема в том что устройство периодически перестает отвечать.

Хорошо, есть проблема с железкой, допустим. Но основная то проблема не в железке, она работает, пусть даже кидает предупреждения (с моего вчерашнего сообщения и до сейчас всего 3 предупреждения в логах, не так много). Проблема в том, что как только я посещаю страницу “Настройка драйвера Serial-устройств” в логах множество предупреждений по устройству. Раньше такого не было, почему я и создал тему. ESP-domofon у меня подключен больше полугода точно и ранее такой проблемы не наблюдал

Да, wb-device-manager пробует читать

Dec 18 14:58:37 wirenboard-A7IGKSOX wb-device-manager[1796]: [WARNING] Can't get firmware info for 137 (/dev/ttyRS485-1 9600 8N2): Request timeout [-32600]: Serial protocol error: request timed out
Dec 18 14:58:42 wirenboard-A7IGKSOX wb-device-manager[1796]: [WARNING] Can't get firmware info for 137 (/dev/ttyRS485-1 9600 8N2): Request timeout [-32600]: Serial protocol error: request timed out
Dec 18 14:58:42 wirenboard-A7IGKSOX wb-device-manager[1796]: [WARNING] Can't get firmware info for 137 (/dev/ttyRS485-1 9600 8N2): Request timeout [-32600]: Serial protocol error: request timed out

Но это ведь не рабочий режим?
В общем - опишу, конечно, как багу.

Что значит “Не рабочий режим”? Данная проблема возникала с отключенным debug режимом, но логи собирал в debug режиме

Это значит что открытое (активное) окно настроек - существует только при изменении этих настроек. Открывается для изменений.
То есть никак не влияет на обычную работу контроллера.
И, как уже писал - воспроизведу и опишу поведение для коллег. Не могу самостоятельно решить - баг ли это, поскольку поведение не противоречит документации.

Исправлено, уже в testing.
Думаю в следующем стабильном будет.