Здравствуйте!
Помогите побороть отвал 4G-соединения. Работает несколько минут (иногда десятков минут), потом отваливается. Помогает только ручной запуск/перезапуск ModemManager и wb-gsm.
приложен диагностический архив, доступен только сотрудникам поддержки
Есть подозрение, что происходит какой-то конфликт с MasterPLC (MasterSCADA)
Добрый день.
Загрузите пожалуйста архив снова - не выкачивается.
приложен диагностический архив, доступен только сотрудникам поддержки
(265,2 КБ)
Так, смотрю - вижу нескоько раз:
Apr 12 09:38:27 wirenboard-APRSER2R kernel: rndis_host 3-1:1.0 usb0: unregister 'rndis_host' usb-1c1c000.usb-1, RNDIS device
Apr 12 09:38:27 wirenboard-APRSER2R kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Apr 12 09:38:27 wirenboard-APRSER2R kernel: option 3-1:1.2: device disconnected
Apr 12 09:38:27 wirenboard-APRSER2R kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Apr 12 09:38:27 wirenboard-APRSER2R kernel: option 3-1:1.4: device disconnected
Apr 12 09:38:27 wirenboard-APRSER2R kernel: option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Apr 12 09:38:27 wirenboard-APRSER2R kernel: option 3-1:1.5: device disconnected
Apr 12 09:38:27 wirenboard-APRSER2R kernel: option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
Apr 12 09:38:27 wirenboard-APRSER2R kernel: option 3-1:1.3: device disconnected
Apr 12 09:38:44 wirenboard-APRSER2R kernel: usb 3-1: new high-speed USB device number 34 using ehci-platform
Apr 12 09:38:44 wirenboard-APRSER2R kernel: usb 3-1: USB disconnect, device number 34
Apr 12 09:38:50 wirenboard-APRSER2R kernel: usb 3-1: new high-speed USB device number 35 using ehci-platform
Apr 12 09:38:50 wirenboard-APRSER2R kernel: rndis_host 3-1:1.0 usb0: register 'rndis_host' at usb-1c1c000.usb-1, RNDIS device, 1a:fc:cd:ff:6d:9e
Apr 12 09:38:50 wirenboard-APRSER2R kernel: option 3-1:1.2: GSM modem (1-port) converter detected
Apr 12 09:38:50 wirenboard-APRSER2R kernel: usb 3-1: GSM modem (1-port) converter now attached to ttyUSB0
Apr 12 09:38:50 wirenboard-APRSER2R kernel: option 3-1:1.4: GSM modem (1-port) converter detected
Apr 12 09:38:50 wirenboard-APRSER2R kernel: usb 3-1: GSM modem (1-port) converter now attached to ttyUSB1
Apr 12 09:38:50 wirenboard-APRSER2R kernel: option 3-1:1.5: GSM modem (1-port) converter detected
Apr 12 09:38:50 wirenboard-APRSER2R kernel: usb 3-1: GSM modem (1-port) converter now attached to ttyUSB2
Apr 12 09:38:50 wirenboard-APRSER2R kernel: option 3-1:1.3: GSM modem (1-port) converter detected
Apr 12 09:38:50 wirenboard-APRSER2R kernel: usb 3-1: GSM modem (1-port) converter now attached to ttyUSB3
То есть связь рвется, затем - поднимается, автоматически.
Даже несколько раз (три) за время с сомента перезапуска, 2024-04-09 07:39:13 MSK
Кстати, логи с 10 числа и есть. А что было в логах после перезапуска?
После перезапуска выглядит всё ОК. Но через несколько минут или десятков минут модем отваливается:
root@wirenboard-APRSER2R /m/d/root# service ModemManager status
● ModemManager.service - Modem Manager
Loaded: loaded (/lib/systemd/system/ModemManager.service; enabled; vendor preset: enabled)
Drop-In: /usr/lib/systemd/system/ModemManager.service.d
└─override.conf
Active: active (running) since Fri 2024-04-12 14:20:00 MSK; 2 days ago
Main PID: 22944 (ModemManager)
Tasks: 3 (limit: 2354)
Memory: 3.7M
CPU: 4min 6.609s
CGroup: /system.slice/ModemManager.service
└─22944 /usr/sbin/ModemManager
Apr 15 08:08:41 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0] port ttyUSB1 timed out 5 consecutive times
Apr 15 08:08:44 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0] port ttyUSB1 timed out 6 consecutive times
Apr 15 08:08:47 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
Apr 15 08:08:47 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0] port ttyUSB1 timed out 7 consecutive times
Apr 15 08:08:50 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
Apr 15 08:08:50 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0] port ttyUSB1 timed out 8 consecutive times
Apr 15 08:08:55 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
Apr 15 08:08:55 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0] port ttyUSB1 timed out 9 consecutive times
Apr 15 08:09:00 wirenboard-APRSER2R ModemManager[22944]: <warn> [modem0/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
Apr 15 08:09:00 wirenboard-APRSER2R ModemManager[22944]: <error> [modem0] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
root@wirenboard-APRSER2R /m/d/root#
Попробовал сейчас перезапустить mplc4, модем сразу отвалился:
root@wirenboard-APRSER2R /m/d/root# service mplc4 restart
root@wirenboard-APRSER2R /m/d/root# service ModemManager status
● ModemManager.service - Modem Manager
Loaded: loaded (/lib/systemd/system/ModemManager.service; enabled; vendor preset: enabled)
Drop-In: /usr/lib/systemd/system/ModemManager.service.d
└─override.conf
Active: inactive (dead) since Mon 2024-04-15 16:34:45 MSK; 10s ago
Process: 4406 ExecCondition=/usr/lib/wb-configs/detect_legacy_modem_config.sh (code=exited, status=0/SUCCESS)
Process: 4409 ExecStart=/usr/sbin/ModemManager (code=exited, status=0/SUCCESS)
Main PID: 4409 (code=exited, status=0/SUCCESS)
CPU: 9.864s
Apr 15 16:34:43 wirenboard-APRSER2R ModemManager[4409]: <info> [modem0] state changed (connected -> disabling)
Apr 15 16:34:43 wirenboard-APRSER2R systemd[1]: Stopping Modem Manager...
Apr 15 16:34:43 wirenboard-APRSER2R ModemManager[4409]: <info> [modem0] mobile equipment request to deactivate context (cid 2)
Apr 15 16:34:43 wirenboard-APRSER2R ModemManager[4409]: <info> [modem0/bearer0] explicitly disconnected
Apr 15 16:34:44 wirenboard-APRSER2R ModemManager[4409]: <info> [modem0/bearer0] connection #1 finished: duration 8049s
Apr 15 16:34:45 wirenboard-APRSER2R ModemManager[4409]: <info> [modem0] 3GPP registration state changed (home -> unknown)
Apr 15 16:34:45 wirenboard-APRSER2R ModemManager[4409]: <info> ModemManager is shut down
Apr 15 16:34:45 wirenboard-APRSER2R systemd[1]: ModemManager.service: Succeeded.
Apr 15 16:34:45 wirenboard-APRSER2R systemd[1]: Stopped Modem Manager.
Apr 15 16:34:45 wirenboard-APRSER2R systemd[1]: ModemManager.service: Consumed 9.864s CPU time.
root@wirenboard-APRSER2R /m/d/root [3]#
А если остановить (и отключить запуск) сервис - соединение устойчиво?
остановил на ночь службу выключенной - разрыва не было. Но через минуту после того как зашёл в консоль - снова отвал.
В логах ничего не намекает на причину:
|16-04-2024 08:19:58.843 [NetworkManager]|<info> [1713244798.8387] device (ttyUSB1): state change: activated -> unmanaged (reason 'removed', sys-iface-state: 'removed')|
|---|---|
|16-04-2024 08:19:58.837 [ModemManager]|<error> [modem1] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid|
|16-04-2024 08:19:58.834 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:55.836 [ModemManager]|<warn> [modem1] port ttyUSB1 timed out 9 consecutive times|
|16-04-2024 08:19:55.833 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:52.831 [ModemManager]|<warn> [modem1] port ttyUSB1 timed out 8 consecutive times|
|16-04-2024 08:19:50.632 [wb-mqtt-db.service]|WARNING: [dblogger] Group data limit is reached: group all, row count 102001, limit 100000|
|16-04-2024 08:19:49.839 [ModemManager]|<warn> [modem1] port ttyUSB1 timed out 7 consecutive times|
|16-04-2024 08:19:49.833 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:49.833 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:46.831 [ModemManager]|<warn> [modem1] port ttyUSB1 timed out 6 consecutive times|
|16-04-2024 08:19:43.833 [ModemManager]|<warn> [modem1] port ttyUSB1 timed out 5 consecutive times|
|16-04-2024 08:19:43.831 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:38.841 [ModemManager]|<warn> [modem1] port ttyUSB1 timed out 4 consecutive times|
|16-04-2024 08:19:38.833 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:33.836 [ModemManager]|<warn> [modem1] port ttyUSB1 timed out 3 consecutive times|
|16-04-2024 08:19:33.833 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:28.837 [ModemManager]|<warn> [modem1] port ttyUSB1 timed out 2 consecutive times|
|16-04-2024 08:19:28.834 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:28.834 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:19:23.831 [ModemManager]|<warn> [modem1/bearer0] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out|
|16-04-2024 08:18:23.705 [init.scope]|Started Session c13 of user root.|
|16-04-2024 08:18:23.701 [init.scope]|Started User Manager for UID 0.|
|16-04-2024 08:18:23.700 [user@0]|Startup finished in 1.098s.|
|16-04-2024 08:18:23.699 [user@0]|Reached target Main User Target.|
|16-04-2024 08:18:23.695 [user@0]|Reached target Basic System.|
|16-04-2024 08:18:23.694 [user@0]|Reached target Timers.|
|16-04-2024 08:18:23.693 [user@0]|Reached target Sockets.|
|16-04-2024 08:18:23.692 [user@0]|Reached target Paths.|
|16-04-2024 08:18:23.692 [user@0]|Reached target Paths.|
|16-04-2024 08:18:23.690 [user@0]|Queued start job for default target Main User Target.|
|16-04-2024 08:18:23.690 [user@0]|Queued start job for default target Main User Target.|
|16-04-2024 08:18:22.530 [user@0]|pam_unix(systemd-user:session): session opened for user root(uid=0) by (uid=0)|
|16-04-2024 08:18:22.467 [init.scope]|Starting User Manager for UID 0...|
|16-04-2024 08:18:22.448 [init.scope]|Finished User Runtime Directory /run/user/0.|
|16-04-2024 08:18:22.401 [systemd-logind]|New session c13 of user root.|
|16-04-2024 08:18:22.385 [init.scope]|Starting User Runtime Directory /run/user/0...|
|16-04-2024 08:18:22.375 [init.scope]|Created slice User Slice of UID 0.|
|16-04-2024 08:18:22.336 [ssh]|pam_unix(sshd:session): session opened for user root(uid=0) by (uid=0)|
|16-04-2024 08:18:22.315 [ssh]|Accepted password for root from 172.16.1.58 port 63430 ssh2|
|16-04-2024 08:18:09.620 [wb-mqtt-db.service]|WARNING: [dblogger] Group data limit is reached: group all, row count 102001, limit 100000|
|16-04-2024 08:18:09.620 [wb-mqtt-db.service]|WARNING: [dblogger] Group data limit is reached: group all, row count 102001, limit 100000|
|16-04-2024 08:18:06.409 [ssh]|error: This private key will be ignored.|
|16-04-2024 08:18:06.408 [ssh]|error: It is required that your private key files are NOT accessible by others.|
|16-04-2024 08:18:06.408 [ssh]|error: Permissions 0644 for '/etc/ssh/ssh_host_ed25519_key' are too open.|
|16-04-2024 08:18:06.407 [ssh]|error: @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
|16-04-2024 08:18:06.406 [ssh]|error: @ WARNING: UNPROTECTED PRIVATE KEY FILE! @|
|16-04-2024 08:18:06.400 [ssh]|error: @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
|16-04-2024 08:17:35.883 [mosquitto]|1713244655: New client connected from ::ffff:172.16.1.58:63355 as wb-mqtt-homeui-pUWZX5RLzH (p2, c1, k60).|
|16-04-2024 08:17:02.075 [cron]|pam_unix(cron:session): session closed for user root|
|16-04-2024 08:17:02.051 [cron]|(root) CMD ( cd / && run-parts --report /etc/cron.hourly)|
|16-04-2024 08:17:02.051 [cron]|(root) CMD ( cd / && run-parts --report /etc/cron.hourly)|
|16-04-2024 08:17:02.030 [cron]|pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)|
Заметил, что перезапуск mplc4 приводит к остановке ModemManager:
16-04-2024 11:02:35.326 Starting MasterPLC... OK
16-04-2024 11:02:34.992 unlink_ports: Unlinked: /dev/ttyGSM /dev/ttyGSM0 /dev/ttyGSM1
16-04-2024 11:02:34.382 probe_usb_ports: Answered to 'AT':
16-04-2024 11:02:34.289 test_connection: (port:/dev/ttyUSB3(/dev/ttyUSB3); timeout:2) => 137
16-04-2024 11:02:32.268 expect (OK)
16-04-2024 11:02:32.242 send (AT^M)
16-04-2024 11:02:32.240 abort on (BUSY)
16-04-2024 11:02:32.239 abort on (ERROR)
16-04-2024 11:02:32.237 timeout set to 2 seconds
16-04-2024 11:02:30.044 expect (OK)
16-04-2024 11:02:30.044 expect (OK)
16-04-2024 11:02:30.024 send (AT^M)
16-04-2024 11:02:30.022 abort on (BUSY)
16-04-2024 11:02:30.021 abort on (ERROR)
16-04-2024 11:02:30.014 timeout set to 2 seconds
16-04-2024 11:02:27.830 expect (OK)
16-04-2024 11:02:27.816 send (AT^M)
16-04-2024 11:02:27.815 abort on (BUSY)
16-04-2024 11:02:27.815 abort on (ERROR)
16-04-2024 11:02:27.799 timeout set to 2 seconds
16-04-2024 11:02:27.799 timeout set to 2 seconds
16-04-2024 11:02:25.619 expect (OK)
16-04-2024 11:02:25.591 send (AT^M)
16-04-2024 11:02:25.591 abort on (BUSY)
16-04-2024 11:02:25.591 abort on (ERROR)
16-04-2024 11:02:25.588 timeout set to 2 seconds
16-04-2024 11:02:21.802 expect (OK)
16-04-2024 11:02:21.775 send (AT^M)
16-04-2024 11:02:21.774 abort on (BUSY)
16-04-2024 11:02:21.774 abort on (ERROR)
16-04-2024 11:02:21.774 abort on (ERROR)
16-04-2024 11:02:21.771 timeout set to 2 seconds
16-04-2024 11:02:19.563 expect (OK)
16-04-2024 11:02:19.536 send (AT^M)
16-04-2024 11:02:19.535 abort on (BUSY)
16-04-2024 11:02:19.535 abort on (ERROR)
16-04-2024 11:02:19.532 timeout set to 2 seconds
16-04-2024 11:02:17.352 expect (OK)
16-04-2024 11:02:17.328 send (AT^M)
16-04-2024 11:02:17.328 abort on (BUSY)
16-04-2024 11:02:17.328 abort on (BUSY)
16-04-2024 11:02:17.327 abort on (ERROR)
16-04-2024 11:02:17.321 timeout set to 2 seconds
16-04-2024 11:01:56.552 handle_mm: Implicit call detected; stopping ModemManager to provide compatibility
16-04-2024 11:01:56.449 handle_mm: wb-gsm is becoming deprecated. Use ModemManager instead
16-04-2024 11:01:53.689 gsm_check_present: Modem is enabled in DT (/soc/usb@1c1c000/wbc-modem@1)
16-04-2024 11:01:53.526 guess_of_node: Got of_gsm_node: /soc/usb@1c1c000/wbc-modem@1
16-04-2024 11:01:52.277 Stopping MasterPLC... OK
Так…
Собственно - служба может влиять на модем двумя способами. Первый - занимать сам порт модема, что довольно просто определить с помощью банального fuser. Ну и симптомы будут чуть другие, тут порты не заняты.
Но тут меня есть явное подозрение что модем именно выключается.
Возьмем, к примеру:
Apr 10 14:43:16 wirenboard-APRSER2R kernel: usb 3-1: USB disconnect, device number 19
Apr 10 14:43:16 wirenboard-APRSER2R kernel: rndis_host 3-1:1.0 usb0: unregister 'rndis_host' usb-1c1c000.usb-1, RNDIS device
Apr 10 14:43:16 wirenboard-APRSER2R kernel: option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
Apr 10 14:43:16 wirenboard-APRSER2R kernel: option 3-1:1.2: device disconnected
Apr 10 14:43:16 wirenboard-APRSER2R kernel: option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
Apr 10 14:43:16 wirenboard-APRSER2R kernel: option 3-1:1.4: device disconnected
Apr 10 14:43:16 wirenboard-APRSER2R kernel: option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
Apr 10 14:43:16 wirenboard-APRSER2R kernel: option 3-1:1.5: device disconnected
Apr 10 14:43:16 wirenboard-APRSER2R kernel: option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
Apr 10 14:43:16 wirenboard-APRSER2R kernel: option 3-1:1.3: device disconnected
При этом в логе wb-gsm:
Apr 10 14:43:07 wirenboard-APRSER2R systemd[1]: Stopping Power on GSM modem...
Apr 10 14:43:24 wirenboard-APRSER2R wb-gsm[1238]: mm_off: Waiting for modem to stop
Apr 10 14:43:24 wirenboard-APRSER2R systemd[1]: wb-gsm.service: Succeeded.
Apr 10 14:43:24 wirenboard-APRSER2R systemd[1]: Stopped Power on GSM modem.
Apr 10 14:43:24 wirenboard-APRSER2R systemd[1]: wb-gsm.service: Consumed 5.358s CPU time.
То есть сначала “что-то” останавливает службу wb-gsm, та, естественно, выключает модем - и связь разрывается.
Попробовал поставить mlpc, в чистом виде. Подобного поведения нет.
Советую проверить исполняемый проект на работу со службами.
При перезапуске mplc4 ModemManager стабильно умирает.
Если я пришлю конфиг - можете проверить его у себя?
Я недостаточно компетентен в разработке под скаду.
Использовал готовый Программирование контроллера Wiren Board с помощью MasterSCADA 4D — Wiren Board
Советую проверить на нем. Если проблема не воспроизводится - то дело в проекте.