Кажется wb-mqtt-serial не работал после перезагрузки контроллера. Логов нет, оборудование утром не включилось. Помог перезапуск сервисов.
Это не первая такая проблема Wb-mqt-serial потерял связь с MQTT
Прошу обратить внимание.
Oct 17 00:35:41 IQ311000 wb-mqtt-serial[2057]: INFO: [mqtt] subscription succeeded (message id 3563)
Oct 17 00:35:41 IQ311000 wb-mqtt-serial[2057]: INFO: [mqtt] subscription succeeded (message id 3570)
Oct 17 00:35:41 IQ311000 wb-mqtt-serial[2057]: INFO: [mqtt] subscription succeeded (message id 3577)
Oct 17 00:35:41 IQ311000 wb-mqtt-serial[2057]: INFO: [mqtt] subscription succeeded (message id 3584)
Oct 17 00:35:41 IQ311000 wb-mqtt-serial[2057]: INFO: [mqtt] subscription succeeded (message id 3585)
Oct 17 00:35:41 IQ311000 wb-mqtt-serial[2057]: INFO: [mqtt] subscription succeeded (message id 3586)
Oct 17 05:21:55 IQ311000 systemd[1]: Stopping MQTT Driver for serial devices...
Oct 17 05:23:25 IQ311000 systemd[1]: wb-mqtt-serial.service: State 'stop-sigterm' timed out. Killing.
Oct 17 05:23:25 IQ311000 systemd[1]: wb-mqtt-serial.service: Killing process 2057 (wb-mqtt-serial) with signal SIGKILL.
Oct 17 05:23:25 IQ311000 systemd[1]: wb-mqtt-serial.service: Main process exited, code=killed, status=9/KILL
Oct 17 05:23:25 IQ311000 systemd[1]: Stopped MQTT Driver for serial devices.
Oct 17 05:23:25 IQ311000 systemd[1]: wb-mqtt-serial.service: Unit entered failed state.
Oct 17 05:23:25 IQ311000 systemd[1]: wb-mqtt-serial.service: Failed with result 'timeout'.
Oct 17 05:24:04 IQ311000 systemd[1]: Started MQTT Driver for serial devices.
Oct 17 05:24:16 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] Default host and port detected, checking if UNIX socket exists on /var/run/mosquitto/mosquitto.sock
Oct 17 05:24:16 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] UNIX socket not found, falling back to TCP connection
Oct 17 05:24:17 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] connection estabilished with code "0" <success>
Oct 17 05:24:17 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] subscription succeeded (message id 1)
Oct 17 05:24:17 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] subscription succeeded (message id 2)
Oct 17 05:24:18 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] subscription succeeded (message id 846)
Oct 17 05:24:19 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] subscription succeeded (message id 847)
Oct 17 05:24:22 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] subscription succeeded (message id 879)
Oct 17 05:24:22 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] subscription succeeded (message id 887)
Oct 17 05:24:22 IQ311000 wb-mqtt-serial[11696]: INFO: [mqtt] subscription succeeded (message id 895)
Так, что я вижу из лога.
Был запущен процесс wb-mqtt-serial с id 2057,
Сообщение в логе от него, судя по количеству должно быть больше:
Oct 17 00:35:41 IQ311000 wb-mqtt-serial[2057]: INFO: [mqtt] subscription succeeded (message id 3586)
который в 05:21:55 останавливается systemd
Процесс не отреагировал и был убит
За интересующий промежуток в брокере:
Oct 17 00:34:19 IQ311000 systemd[1]: Starting Mosquitto MQTT v3.1/v3.1.1 Broker...
Oct 17 00:34:20 IQ311000 mosquitto[916]: Warning: Error resolving bridge address: Name or service not known.
Oct 17 00:34:20 IQ311000 systemd[1]: Started Mosquitto MQTT v3.1/v3.1.1 Broker.
Oct 17 00:36:31 IQ311000 mosquitto[916]: Error creating bridge: Protocol not supported.
wb-mqtt-serial=2.68.6-wb106
Актуальный для 2207 2.68.6-wb109 но в нем каких-то исправлений (значимых) не вижу
Сама сеть на контроллере была и mosquitto в 5 утра (по UTC) работал. Возможно при загрузке были какие-то проблемы с сетью, так как у нас в начале загружаются 2 симки и проверяется на каждой связь. Скорее всего поэтому mosquitto не может запустить мост в это время. Может быть это приводит к каким то проблемам на стороне wb-mqtt-serial.
Нет, сам брокер раюотал, это видно из логов прочих служб.
Возможно, что-то еще есть в /var/log/mosquitto/
Такое впечатление что сервис просто повис.
А почему не обновитесь до актуального релиза?
Сначала нужно хорошо протестировать, затем обновиться. Пол года назад только перешли на 2207. Переход на 2307 планируем в течении ближайших месяцев. Нам нужно проверить как будет работать новая прошивка с нашим софтом на всех версиях контроллеров начиная с 6.5.
В предыдущей теме, где не получилось собрать достаточно логов для отладки, я заходил на контроллер в момент, когда wb-mqtt-serial завис с теми же симптомами. Было видно, что сам процесс wb-mqtt-serial был. При этом все другие сервисы связынные с MQTT работали корректно.
У меня настроен monit на wb-mqtt-serial, правило следующее, что если wb-mqtt-serial не запущен в течении некоторого времени, wb-mqtt-serial перезапускается. Но когда сам процесс есть, но по факту ничего не происходит, monit не срабатывает, что логично.
Да. И это довольно сложновоспроизводимое поведение, у меня воспроизвести не получалось. Я, кстати, пробовал и без запущенного брокера запускать wb-mqtt-serial, и ронять брокер когда процесс запущен - пока не удается добиться чтобы процесс просто висел без ругани в лог и перезапуска.
Если для свежих релизов можно в качестве контроля периодически давать сервису команды по RPC (отсутствие ответа - ошибка, сервис не работает) то в 2207 такого нет.
Включить на каком-либо устройстве опрос времени работы, если топик не меняется дольше нескольких секунд - то или это устройство отвалилось или сам сервис. Но все ж обновиться до актуального лучше.
Спасибо за идею!
До 2307 обновляться однозначно будем, но на это уйдет больше времени чем на мониторинг wb-mqtt-serial, а бага не факт, что там отсутствует. Так что одно не отменяет другое.
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5373)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5380)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5387)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5394)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5401)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5408)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5415)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5422)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5429)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5430)
Oct 31 00:36:01 IQ311000 wb-mqtt-serial[2055]: INFO: [mqtt] subscription succeeded (message id 5431)
Oct 31 04:47:53 IQ311000 systemd[1]: Stopping MQTT Driver for serial devices...
Oct 31 04:49:23 IQ311000 systemd[1]: wb-mqtt-serial.service: State 'stop-sigterm' timed out. Killing.
Oct 31 04:49:23 IQ311000 systemd[1]: wb-mqtt-serial.service: Killing process 2055 (wb-mqtt-serial) with signal SIGKILL.
Oct 31 04:49:23 IQ311000 systemd[1]: wb-mqtt-serial.service: Main process exited, code=killed, status=9/KILL
Oct 31 04:49:23 IQ311000 systemd[1]: Stopped MQTT Driver for serial devices.
Oct 31 04:49:23 IQ311000 systemd[1]: wb-mqtt-serial.service: Unit entered failed state.
Oct 31 04:49:23 IQ311000 systemd[1]: wb-mqtt-serial.service: Failed with result 'timeout'.
Oct 31 04:50:02 IQ311000 systemd[1]: Started MQTT Driver for serial devices.
Oct 31 04:50:14 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] Default host and port detected, checking if UNIX socket exists on /var/run/mosquitto/mosquitto.sock
Oct 31 04:50:14 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] UNIX socket not found, falling back to TCP connection
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] connection estabilished with code "0" <success>
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] subscription succeeded (message id 1)
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] subscription succeeded (message id 2)
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] subscription succeeded (message id 31)
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] subscription succeeded (message id 39)
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] subscription succeeded (message id 238)
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] subscription succeeded (message id 245)
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] subscription succeeded (message id 252)
Oct 31 04:50:15 IQ311000 wb-mqtt-serial[8863]: INFO: [mqtt] subscription succeeded (message id 259)