Не понятно чем занимается wb-connection-manager

Добрый день!
Недавно приобрел и установил в WB7 модем WBC-4G v.2.
Некоторое время все было хорошо, затем контроллер начал чем-то нагружаться.

Контроллер: WB7

Версия ПО: testing (обновлена на 29.09.2023)

Что работает не так?

приложен диагностический архив, доступен только сотрудникам поддержки
(358,7 КБ)
log_20230929T122522.log (28,6 КБ)

Сегодня, к примеру, лог забит таким хотя моде вообще не трогается у него низкий приоритет, интернет есть, поводов трогать модем - нет

2023-09-29T09:25:22.026Z [wb-connection-manager] Found 0 lesser GSM connections
2023-09-29T09:25:21.941Z [wb-connection-manager] Connection Megafon is GSM: True
2023-09-29T09:25:21.857Z [wb-connection-manager] Deactivating lesser GSM connections
2023-09-29T09:25:21.856Z [wb-connection-manager] Current connection wb-eth0 is most preferred and has connectivity
2023-09-29T09:25:21.855Z [wb-connection-manager] Connectivity via eth0 is True
2023-09-29T09:25:21.854Z [wb-connection-manager] Payload is NetworkManager is online
2023-09-29T09:25:21.727Z [wb-connection-manager] interfaces for wb-eth0: eth0
2023-09-29T09:25:21.620Z [wb-connection-manager] checking currently active connection wb-eth0
2023-09-29T09:25:21.620Z [wb-connection-manager] checking tier high
2023-09-29T09:25:21.617Z [wb-connection-manager] check(): starting iteration
2023-09-29T09:25:16.611Z [wb-connection-manager] Found 0 lesser GSM connections
2023-09-29T09:25:16.541Z [wb-connection-manager] Connection Megafon is GSM: True
2023-09-29T09:25:16.490Z [wb-connection-manager] Deactivating lesser GSM connections
2023-09-29T09:25:16.490Z [wb-connection-manager] Current connection wb-eth0 is most preferred and has connectivity
2023-09-29T09:25:16.488Z [wb-connection-manager] Connectivity via eth0 is True
2023-09-29T09:25:16.488Z [wb-connection-manager] Payload is NetworkManager is online
2023-09-29T09:25:16.381Z [wb-connection-manager] interfaces for wb-eth0: eth0
2023-09-29T09:25:16.239Z [wb-connection-manager] checking currently active connection wb-eth0
2023-09-29T09:25:16.239Z [wb-connection-manager] checking tier high
2023-09-29T09:25:16.233Z [wb-connection-manager] check(): starting iteration
2023-09-29T09:25:11.227Z [wb-connection-manager] Found 0 lesser GSM connections
2023-09-29T09:25:11.148Z [wb-connection-manager] Connection Megafon is GSM: True
2023-09-29T09:25:11.082Z [wb-connection-manager] Deactivating lesser GSM connections
2023-09-29T09:25:11.082Z [wb-connection-manager] Current connection wb-eth0 is most preferred and has connectivity
2023-09-29T09:25:11.080Z [wb-connection-manager] Connectivity via eth0 is True
2023-09-29T09:25:11.080Z [wb-connection-manager] Payload is NetworkManager is online
2023-09-29T09:25:10.973Z [wb-connection-manager] interfaces for wb-eth0: eth0
2023-09-29T09:25:10.833Z [wb-connection-manager] checking currently active connection wb-eth0
2023-09-29T09:25:10.833Z [wb-connection-manager] checking tier high
2023-09-29T09:25:10.829Z [wb-connection-manager] check(): starting iteration
2023-09-29T09:25:05.823Z [wb-connection-manager] Found 0 lesser GSM connections
2023-09-29T09:25:05.740Z [wb-connection-manager] Connection Megafon is GSM: True

Добрый день.
Пришлите диагностический архив.

Что вас здесь смущает? Уберите галочку “Включить отладочные сообщения”.

Как вы определили, что контроллер чем-то нагружен?

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

29-09-2023 09:36:44.536 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:40.336 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:39.721 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:37.328 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:37.328 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:36.721 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:35.068 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:34.383 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:29.985 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:29.370 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:26.967 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:26.347 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:24.916 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:24.354 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:24.354 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:19.934 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:19.335 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:36:16.907 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:36:07.978 [wb-mqtt-serial]	WARNING: [modbus] failed to read 1 input(s) @ 1003 of device modbus:10: Serial protocol error: request timed out
29-09-2023 09:35:46.207 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:35:44.806 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:34:44.502 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:34:40.128 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:33:39.816 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:33:39.816 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:33:37.329 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:32:37.033 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:32:35.627 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:31:35.323 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:31:30.908 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:30:30.607 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:30:28.386 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)
29-09-2023 09:29:28.076 [ModemManager]	<info>  [modem75] mobile equipment request to activate context (cid 8)
29-09-2023 09:29:26.650 [ModemManager]	<info>  [modem75] mobile equipment request to deactivate context (cid 8)

Ну и по прежнему непонятно, зачем дергать модем если с текущим соединением все в порядке?
Это жде не “бесплатная операция”, но если с более приоритетным соединением все в порядке - бесполезная. Т.е. контроллер ею нагружен.

Больший объем лога вроде бы получилось сделать
log_20230929T133038.log (2,4 МБ)

А вот за этой фразой диагностический архив не скрывается разве?

Вот еще один

diag_output_AMFACU7_2023-09-29-09.26.40.zip (358,7 КБ)

Похоже, нашел проблему появления записей в логе

[modem75] mobile equipment request to activate context (cid 8)

Это мой скрипт опрашивает SMS сообщения.

Как-то можно отключить эти сообщения?
Опрос производится раз в минуту, записей получается довольно много…

1 Like

На то мне кажется и логирование, чтоб подобные действия фиксировать.
Плюс они исходят от ModemManager. Соответственно, как отключить данное сообщение понятия не имею.

Чем вас смущает большое количество записей?

Добрый день! Можете показать скрипт?

Хочется в логе видеть полезную информацию, в идеале- только ту что заказывал или ту на которую нужно как-то реагировать.
К примеру о том что сериал драйвер не смог получить какие-то данные от какого-то из устройств.

А здесь непонятного свойства информация, с непонятным содержимом, нужно на нее как-то реагировать или нет - абсолютно непонятно…

Можно отключить вывод этих сообщений командой mmcli -G WARN

Вот скрипт, с ним не все в порядке.

SMSManager.js (6,0 КБ)

У меня в модеме одно входящее SMS, по идее виртуальное устройство должно только его и показывать. Однако отрисовывается сложная “структура” из которой можно сделать вывод, что данные этого SMS добавлялись несколько раз с одинаковыми именами контролов, при этом wb-rules не смог найти их по имени среди существующих.
Вот скрин, внизу окно отладки в него выводятся те имена контролов которые удалось найти во время старта

К сожалению, наш портал не позволяет прикрепить js файлы. Можете запаковать его в архив и прикрепить?

Вот

SMSManager.rar (1,5 КБ)

1 Like

Предлагаю отключить логи, как я писал выше.

Не сразу увидел сообщение. Спасибо! Отключил

Отличный по-моему скрипт.
Да, доработка нужна - но вполне хорошо написан.

Спасибо!
Сможете подсказать, что нуждается в доработке?

Из того что бросатся в глаза:

mmcli --modem wbc --messaging-list-sms --output-keyvalue

и парсинг.

А можно элегантно:

mmcli --modem wbc --messaging-list-sms --output-json    
{"modem.messaging.sms":["/org/freedesktop/ModemManager1/SMS/4","/org/freedesktop/ModemManager1/SMS/3","/org/freedesktop/ModemManager1/SMS/2","/org/freedesktop/ModemManager1/SMS/1","/org/freedesktop/ModemManager1/SMS/0"]}

И сразу JSON.parse - получаем объект который тривиально перебирается.

1 Like

Спасибо! Так и правда красивше получится :slight_smile:

Эта тема была автоматически закрыта через 7 дней после последнего ответа. В ней больше нельзя отвечать.