Проблемы с поиском устройств

Добрый день. Поиск устройств через веб-интерфейс работает через раз (или, я бы сказал, редко). Wirenboard 8.5.1, ПО wb-2507 (обновлен через apt).

Или висит индикатор загрузки, или выдает ошибку “wb-device-manager service is unavailable or outdated”.
Иногда, в момент старта поиска, в journal появляется запись вида:

Aug 25 16:35:31 wirenboard-AHXOYVVR wb-device-manager[6248]: [WARNING] '/rpc/v1/wb-device-manager/bus-scan/Start/wb-mqtt-homeui-L6UBO53Qbd' is already processing!


Добрый день!
Для диагностики проблемы пришлите, пожалуйста, архив с диагностической информацией контроллера. Создание архива описано в документации.

Добрый день!

Спасибо за сообщение о доступности архива, наши инженеры уже взяли данную проблему в работу.
Обращаю внимание, что в диагностическом архиве не собирается чувствительная информация.

Подскажите, пожалуйста, есть ли в контроллере SD-карта.
Если есть — извлеките её и проверьте работу контроллера без неё.

Сообщите, пожалуйста, результат проверки.

В контроллере отсутствует SD-карта.

Добрый день!

В логе присутствуют сообщения явно указывающи о проблеме с картой:

Aug 29 08:07:27 wirenboard-AHXOYVVR systemd[1]: Timed out waiting for device /dev/mmcblk1p1.
Aug 29 08:07:27 wirenboard-AHXOYVVR systemd[1]: Dependency failed for /mnt/sdcard.
Aug 29 08:07:27 wirenboard-AHXOYVVR systemd[1]: mnt-sdcard.mount: Job mnt-sdcard.mount/start failed with result 'dependency'.
Aug 29 08:07:27 wirenboard-AHXOYVVR systemd[1]: Dependency failed for File System Check on /dev/mmcblk1p1.

Также рекомендую проверить физическое подключение устройств.
Особое внимание обратить на устройство 132:

Aug 29 08:12:29 wirenboard-AHXOYVVR wb-mqtt-serial[13559]: WARNING: [modbus] failed to read 3 input(s) @ 400 of device modbus:132: Serial protocol error: malformed response: invalid crc

Добрый день.

132-й девайс подключен не самым лучшим кабелем, но его физическое отключение от линии не повлияло на проблему.

На сколько я понял по карте, zabbix делает запрос к ФС и триггерит автомонтирование. Полностью отключил zabbix, ошибка карты ушла, а поиск устройств сработал только один раз после перезагрузки.

Aug 29 12:36:51 wirenboard-AHXOYVVR mosquitto[1769]: 1756471011: Client wb-mqtt-homeui-BZpgXE3Tjc closed its connection.
Aug 29 12:36:51 wirenboard-AHXOYVVR mosquitto[1769]: 1756471011: New client connected from ::ffff:127.0.0.1:44074 as wb-mqtt-homeui-X8I9iNsOwm (p2, c1, k60).
Aug 29 12:36:51 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/bus-scan/Stop/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/fw-update/GetFirmwareInfo/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] Can't get firmware info for 130 (/dev/ttyRS485-2 115200 8N2): illegal data address
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] Can't get firmware info for 131 (/dev/ttyRS485-1 115200 8N2): illegal data address
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] Can't get firmware info for 1 (172.18.5.21:23): Request timeout [-32600]: Serial protocol error: request timed out
Aug 29 12:36:52 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] Can't get firmware info for 3 (172.18.5.21:23): illegal data address
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: Task exception was never retrieved
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: future: <Task finished name='Scan serial bus (long running)' coro=<BusScanner.scan_serial_bus() done, defined at /usr/lib/python3/dist-packages/wb/device_manager/bus_scan.py:94> exception=ValueError('Invalid format specifier')>
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: Traceback (most recent call last):
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:   File "/usr/lib/python3.9/asyncio/tasks.py", line 492, in wait_for
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:     fut.result()
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: asyncio.exceptions.CancelledError
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: The above exception was the direct cause of the following exception:
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: Traceback (most recent call last):
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:   File "/usr/lib/python3/dist-packages/wb/device_manager/mqtt_rpc.py", line 73, in make_rpc_call
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:     response = await asyncio.wait_for(response_f, timeout)
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:   File "/usr/lib/python3.9/asyncio/tasks.py", line 494, in wait_for
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:     raise exceptions.TimeoutError() from exc
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: asyncio.exceptions.TimeoutError
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: During handling of the above exception, another exception occurred:
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: Traceback (most recent call last):
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:   File "/usr/lib/python3/dist-packages/wb/device_manager/bus_scan.py", line 103, in scan_serial_bus
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:     ports = await self.get_ports()
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:   File "/usr/lib/python3/dist-packages/wb/device_manager/bus_scan.py", line 37, in get_ports
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:     response = await self.rpc_client.make_rpc_call(
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:   File "/usr/lib/python3/dist-packages/wb/device_manager/mqtt_rpc.py", line 79, in make_rpc_call
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]:     message=f"rpc call to {driver}/{service}/{method} -> {timeout:.2fs}: no answer",
Aug 29 12:36:54 wirenboard-AHXOYVVR wb-device-manager[1825]: ValueError: Invalid format specifier
Aug 29 12:36:54 wirenboard-AHXOYVVR mosquitto[1769]: 1756471014: New connection from /var/run/mosquitto/mosquitto.sock:0 on port 0.
Aug 29 12:36:54 wirenboard-AHXOYVVR mosquitto[1769]: 1756471014: New client connected from /var/run/mosquitto/mosquitto.sock:0 as auto-AD35F5F8-4281-F85A-D478-452CD56AA602 (p2, c1, k60).
Aug 29 12:36:54 wirenboard-AHXOYVVR mosquitto[1769]: 1756471014: Client auto-AD35F5F8-4281-F85A-D478-452CD56AA602 disconnected.
Aug 29 12:37:13 wirenboard-AHXOYVVR wb-device-manager[1825]: [WARNING] '/rpc/v1/wb-device-manager/bus-scan/Stop/wb-mqtt-homeui-X8I9iNsOwm' is already processing!
Aug 29 12:37:31 wirenboard-AHXOYVVR wb-mqtt-serial[4101]: WARNING: [modbus] failed to read 2 input(s) @ 270 of device modbus:63: Serial protocol error: malformed response: invalid crc
Aug 29 12:38:02 wirenboard-AHXOYVVR mosquitto[1769]: 1756471082: Client wb-mqtt-homeui-X8I9iNsOwm closed its connection.
Aug 29 12:38:03 wirenboard-AHXOYVVR mosquitto[1769]: 1756471083: New client connected from ::ffff:127.0.0.1:42584 as wb-mqtt-homeui-WiNgQdZJOl (p2, c1, k60).
Aug 29 12:38:06 wirenboard-AHXOYVVR mosquitto[1769]: 1756471086: New connection from /var/run/mosquitto/mosquitto.sock:0 on port 0.
Aug 29 12:38:06 wirenboard-AHXOYVVR mosquitto[1769]: 1756471086: New client connected from /var/run/mosquitto/mosquitto.sock:0 as auto-9F36BE13-4588-E70A-8B3B-43F553CB737E (p2, c1, k60).
Aug 29 12:38:06 wirenboard-AHXOYVVR mosquitto[1769]: 1756471086: Client auto-9F36BE13-4588-E70A-8B3B-43F553CB737E disconnected.

Есть ощущение, что проблема в wb-device-manager, т.к. после его рестарта поиск начинает работать.
Возможно, он уходит deadlock? Т.к. при рестарте через systemctl restart wb-device-manager система прибивает его по таймауту.

Aug 29 12:50:07 wirenboard-AHXOYVVR systemd[1]: wb-device-manager.service: State 'stop-sigterm' timed out. Killing.
Aug 29 12:50:07 wirenboard-AHXOYVVR systemd[1]: wb-device-manager.service: Killing process 1857 (wb-device-manag) with signal SIGKILL.
Aug 29 12:50:07 wirenboard-AHXOYVVR systemd[1]: wb-device-manager.service: Killing process 2281 (wb-device-manag) with signal SIGKILL.
Aug 29 12:50:07 wirenboard-AHXOYVVR systemd[1]: wb-device-manager.service: Main process exited, code=killed, status=9/KILL
Aug 29 12:50:07 wirenboard-AHXOYVVR systemd[1]: wb-device-manager.service: Failed with result 'timeout'.
Aug 29 12:50:07 wirenboard-AHXOYVVR systemd[1]: Stopped Wiren Board modbus devices manager.
Aug 29 12:50:07 wirenboard-AHXOYVVR systemd[1]: wb-device-manager.service: Consumed 1.028s CPU time.
Aug 29 12:50:07 wirenboard-AHXOYVVR systemd[1]: Started Wiren Board modbus devices manager.

Добрый день!

Потребуется некоторое время — уточню у коллег.

Добрый день!

Посовещались с коллегами, пока не пришли к единому мнению, в чём причина проблемы с поиском.
Прошу снять новый диагностический архив — возможно, удастся выявить причину.
Также могу предложить вариант с удалённым доступом к контроллеру, чтобы проверить систему напрямую.

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

1 сообщение было перенесено в новую тему: Дублирование сообщений в брокере