Armadilloフォーラム

Armadillo IoT G3(Debian12 bookworm)でSIMを使ってデータ通信ができない

satoshi.sa.aoki

2024年8月2日 18時31分

お世話になっております。

以下の手順にて、Debian12のルートファイルシステムを使ってAPN設定をしてSIM通信をしようとしたのですが、nmcli c upコマンドでアクティベーション失敗になりました。原因をご教授いただけませんか?

root@armadillo:~# nmcli connection add type gsm ifname ttyUSB3 apn {apn} user {user} password {pass}
Connection 'gsm-ttyUSB3' (2c5232da-af2d-4116-a260-e9540097855f) successfully added.
root@armadillo:~# nmcli c up gsm-ttyUSB3
Error: Connection activation failed: No suitable device found for this connection (device eth0 not available because profile is not compatible with device (mismatching interface name)).
root@armadillo:~# nmcli c
NAME                UUID                                  TYPE      DEVICE
Buffalo-A-DE68      cebbb017-0fb9-4b64-b56c-34a47f54dd45  wifi      wlan0
lo                  143b8004-3d27-4ed5-b8ed-643e65abefd3  loopback  lo
Wired connection 1  f4162f87-a5b0-3204-ac70-1f05ed6ea4d5  ethernet  --
gsm-ttyUSB3         2c5232da-af2d-4116-a260-e9540097855f  gsm       --

Debian10(buster)の時には、上記手順にて以下のように上手くいっております。

root@armadillo:~# nmcli c
NAME                UUID                                  TYPE      DEVICE
gsm-ttyUSB3         1de56941-3bec-4bc0-8dd4-ad0c38573f1b  gsm       ttyUSB3
Wired connection 1  704ec41e-d702-38a5-8c39-f3ac9707e681  ethernet  --
 
root@armadillo:~# nmcli c up gsm-ttyUSB3
Connection successfully activated (D-Bus active path: /org/freedesktop/NetworkManager/ActiveConnection/7)

https://armadillo.atmark-techno.com/faq/aiotg-g3-m1-3g-doesnt-work
上記の確認項目の情報は以下になります。

*確認項目一覧
■確認項目1. microSIMが正しく認識されているか → OK
→電話番号を表示確認できている

root@armadillo:~# mmcli -m 0 | grep Number

  Numbers  |                  own: 080********

■確認項目2. microSIMがアクティベーションされているか → OK
→他のSIMフリー端末(Androidスマホ)を使用してmicroSIMで通信できたのでアクティベーション済

■確認項目3. アンテナが接続されているか → OK

■確認項目4. 十分な電波強度があるか → NG
→Armadillo-IoT G3 M1の設置環境に問題がないことは確認済。
→他のSIMフリー端末(Androidスマホ)では同じ場所で問題なく電波が5本立っている。

root@armadillo:~# mmcli -m 0 | grep "signal quality"
           |       signal quality: 0% (cached)

■確認項目5. 正しいAPN情報を設定しているか → OK
→他のSIMフリー端末(Androidスマホ)で通信できているのでAPN情報に間違いない。

■確認項目6. microSIMが閉域網であるか → OK (閉域網ではない)

■確認項目7. 通信事業者への問い合わせ
・契約切れや通信制限が無いか
・サポートエリア内か
・通信障害/メンテナンス中ではないか
→ いずれも他のSIMフリー端末(Androidスマホ)で通信できているのでAPN情報に間違いない。

■確認項目8. 弊社への問い合わせ

root@armadillo:~# uname -a
Linux armadillo 4.9.133-at28 #2 SMP PREEMPT Thu Jan 26 17:35:01 JST 2023 armv7l GNU/Linux
root@armadillo:~# dpkg -l | grep atmark-x1-base
ii  atmark-x1-base                  4.0.0-1                                 armhf        Atmark Techno X1 platform base software
root@armadillo:~# dpkg -l | grep modemmanager
ii  modemmanager                    1.20.4-1atmark1                         armhf        D-Bus service for managing modems
root@armadillo:~# dpkg -l | grep ec25-utils
ii  ec25-utils                      1.2.0                                   all          Utilities for Quectel EC25 on Armadillo board

syslogの該当箇所は以下になってます。

2024-08-02T18:12:13.841286+09:00 armadillo NetworkManager[4120]: <info>  [1722589933.8392] audit: op="connection-add" uuid="2c5232da-af2d-4116-a260-e9540097855f" name="gsm-ttyUSB3" pid=5350 uid=0 result="success"
2024-08-02T18:12:24.041647+09:00 armadillo NetworkManager[4120]: <info>  [1722589944.0401] agent-manager: agent[0f34e05698700694,:1.52/nmcli-connect/0]: agent registered
2024-08-02T18:12:24.048532+09:00 armadillo NetworkManager[4120]: <info>  [1722589944.0480] audit: op="connection-activate" uuid="2c5232da-af2d-4116-a260-e9540097855f" name="gsm-ttyUSB3" result="fail" reason="No suitable device found for this connection (device eth0 not available because profile is not compatible with device (mismatching interface name))."

よろしくお願いします。

コメント

at_mitsuhiro.yoshida

2024年8月5日 8時01分

吉田です。

Debian 12 より 3G/LTE のデバイス名の初期値を ttyCommModem に変更しております。

Armadillo 製品アップデートのお知らせ (2024年2月/Armadillo-IoT G3対象)
https://armadillo.atmark-techno.com/news/20240228/software-update-aiotg3
にその旨を記載しております。

ttyUSB2 (またはそれ以降)を使用される際は、製品マニュアル「3G/LTE のネットワークデバイス名に ttyUSB2 を利用する」を
参照ください。
https://manual.atmark-techno.com/armadillo-iot-g3/armadillo-iotg-g3_pro…

お手数おかけしますが、ご対応よろしくお願いします。

satoshi.sa.aoki

2024年8月5日 16時10分

お世話になっております。
ご回答頂いた通り対応した所、SIM動作するようになりました。
ありがとうございました。

satoshi.sa.aoki

2024年8月5日 23時48分

お世話になっております。

すみません。物理的にSIMを抜き差ししていたらSIM通信ができなくなってしまいました。
1分程度待っていたのですが、SIM通信が復活しないので、以下を再度実行してみたのですが、エラーなってしまいました。

root@armadillo:~# nmcli connection up gsm-ttyCommModem
Error: Connection activation failed: No carrier could be established
Hint: use 'journalctl -xe NM_CONNECTION=628d359b-fb75-43c8-bd87-d1c41c26329a + NM_DEVICE=ttyCommModem' to get more details.

SIMカードが壊れていないか再度スマホでチェックしたのですが、通信に問題なかったです。
mmcli -m 0のコマンドを実行したところ以下のように信号強度が0%でした。原因は何が考えられますか?

  --------------------------------
  General  |                 path: /org/freedesktop/ModemManager1/Modem/0
           |            device id: f0089cde66e6fa6fb82e3d2a61224abae59bea47
  --------------------------------
  Hardware |         manufacturer: Quectel
           |                model: EC25
           |    firmware revision: EC25JFAR06A03M4G_SBK
           |            supported: gsm-umts, lte
           |              current: gsm-umts, lte
           |         equipment id: 861107039126959
  --------------------------------
  System   |               device: /sys/devices/soc0/soc/30800000.aips-bus/30b30000.usb/ci_hdrc.1/usb2/2-1/2-1.2
           |              drivers: option
           |               plugin: quectel-ec25
           |         primary port: ttyCommModem
           |                ports: ttyCommModem (at), ttyUSB1 (ignored), ttyUSB2 (gps),
           |                       ttyUSB4 (at)
  --------------------------------
  Numbers  |                  own: 080********
  --------------------------------
  Status   |       unlock retries: sim-pin (3), sim-puk (10), sim-pin2 (3), sim-puk2 (10)
           |                state: searching
           |          power state: on
           |       signal quality: 0% (cached)
  --------------------------------
  Modes    |            supported: allowed: 2g, 3g, 4g; preferred: none
           |              current: allowed: 2g, 3g, 4g; preferred: none
  --------------------------------
  Bands    |            supported: utran-1, utran-8, eutran-1, eutran-3, eutran-8, eutran-26,
           |                       eutran-41, utran-19
           |              current: eutran-41
  --------------------------------
  IP       |            supported: ipv4, ipv6, ipv4v6
  --------------------------------
  3GPP     |                 imei: 8*******************
           |         registration: searching
           | packet service state: detached
  --------------------------------
  3GPP EPS | ue mode of operation: csps-2
  --------------------------------
  SIM      |     primary sim path: /org/freedesktop/ModemManager1/SIM/0
  --------------------------------
  Bearer   |                paths: /org/freedesktop/ModemManager1/Bearer/2
           |                       /org/freedesktop/ModemManager1/Bearer/1
           |                       /org/freedesktop/ModemManager1/Bearer/0

at_mitsuhiro.yoshida

2024年8月6日 13時38分

吉田です。

SIM カードは認識できているようですので、他の LTE アンテナなど物理的な構成を確認いただけますでしょうか。

また、他の SIM の入れ替えている場合は、製品マニュアル「3G/LTE モジュールの初期化手順」
https://manual.atmark-techno.com/armadillo-iot-g3/armadillo-iotg-g3_pro…
にて接続できるようになる可能性はあります。

satoshi.sa.aoki

2024年8月6日 17時31分

ありがとうございます。

色々と試している感じでは、同一のSIMを起動中に抜いて挿し直すと、頂いた「3G/LTE モジュールの初期化手順」を実施しても通信が復活できなかったです。なんどか、ModemManagerのサービスを再起動していると、データ通信の復帰ができなくなったりしました。通信できたりできなくなったりと条件がわからず悩んでいます。

例えば、特定のSIMのAPN設定を事前に行ったArmadillo IoT G3と特定のSIMをセットでお客様にお渡ししてセットアップして頂くといったケースを想定していますが、
SIMの抜き差しなどについて注意点などございますか?
以下のような条件などございますか?

①電源OFF時にSIMは差さなければならない(電源ON時に挿してもOKだが再起動が必要?)
②SIMを抜くときには電源OFF時でなければならない
③SIMを抜き差ししたら電源OFF・ONが必要である

よろしくお願いします。

satoshi.sa.aoki

2024年8月7日 20時54分

ありがとうございます。SIM活線挿抜が未対応は理解しました。

たびたびすみません。
SIMを挿したまま動作させているのですが、接続・切断を定期的に繰り返している状況です。
添付ファイルにsyslogを添付しました。原因を教えて頂けますか?

syslogの2024-08-07T20:32:45.760660+09:00あたりで一度接続してその後また接続が切れてます。

root@armadillo:~# nmcli c
NAME                UUID                                  TYPE      DEVICE
lo                  08de5166-595b-4c61-87ac-345ebed4b1d1  loopback  lo
Wired connection 1  f4162f87-a5b0-3204-ac70-1f05ed6ea4d5  ethernet  --
gsm-ttyCommModem    628d359b-fb75-43c8-bd87-d1c41c26329a  gsm       --
root@armadillo:~# usb 2-1.2: USB disconnect, device number 6
option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
option 2-1.2:1.0: device disconnected
option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
option 2-1.2:1.1: device disconnected
option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
option 2-1.2:1.2: device disconnected
option1 ttyUSB4: GSM modem (1-port) converter now disconnected from ttyUSB4
option 2-1.2:1.3: device disconnected
usb 2-1.2: new high-speed USB device number 7 using ci_hdrc
option 2-1.2:1.0: GSM modem (1-port) converter detected
usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB1
option 2-1.2:1.1: GSM modem (1-port) converter detected
usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB2
option 2-1.2:1.2: GSM modem (1-port) converter detected
usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB3
option 2-1.2:1.3: GSM modem (1-port) converter detected
usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB4
IPVS: Creating netns size=912 id=4
IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
 
root@armadillo:~# nmcli c
NAME                UUID                                  TYPE      DEVICE     >
gsm-ttyCommModem    628d359b-fb75-43c8-bd87-d1c41c26329a  gsm       ttyCommMode>
lo                  08de5166-595b-4c61-87ac-345ebed4b1d1  loopback  lo         >
Wired connection 1  f4162f87-a5b0-3204-ac70-1f05ed6ea4d5  ethernet  --         >
root@armadillo:~#

よろしくお願いします。

ファイル ファイルの説明
syslog.txt

at_mitsuhiro.yoshida

2024年8月8日 14時24分

吉田です。

標準イメージで動作している LTE 再接続サービスは 120 秒周期で ping 導通確認を実施し、
ping 導通が NG であれば、再接続を実施しています。

再接続の周期が 2 ~ 4 分程度の短い間隔であれば、
ping 導通確認先の IP アドレスが到達できないアドレスになっている可能性もありますので、

製品マニュアル 「3G/LTE再接続サービス」や
https://manual.atmark-techno.com/armadillo-iot-g3/armadillo-iotg-g3_pro…
「クローズドネットワークを使用する場合の再接続サービス設定変更」
https://manual.atmark-techno.com/armadillo-iot-g3/armadillo-iotg-g3_pro…
を参考の上設定値の調整をお願いします。

再接続の周期が 24 時間などの場合は、
プロバイダーの仕様で一定時間接続していると一旦切断されている可能性もあります。

satoshi.sa.aoki

2024年8月19日 16時38分

ありがとうございます。

頂いた情報を参考に、3G/LTE再接続サービス(connection-recover)のサービスを停止しました。
すると、SIMのデータ通信が安定しているようです。
なお、3G/LTE再接続サービス(connection-recover)を有効にしたときの接続・切断を繰り返す周期は24時間とかではなく、数分くらいだったと思います。

また、3G/LTE再接続サービス(connection-recover)のサービスを無効にした場合には、どんな影響がありますか?
3G/LTE再接続サービス(connection-recover)がないと不意に切れた場合等は再接続しなくなるということでしょうか?電源OFF/ONが必要になるとか。

よろしくお願いします。

satoshi.sa.aoki

2024年8月22日 15時27分

上記ご回答お待ちしております。

お忙しいところ恐縮ですがよろしくお願いします。

at_dominique.m…

2024年8月22日 15時57分

satoshi.sa.aokiさん

返事が遅くなってすみません、
吉田さんの代わりに返事させていただきます。マルティネです。

> 頂いた情報を参考に、3G/LTE再接続サービス(connection-recover)のサービスを停止しました。
> すると、SIMのデータ通信が安定しているようです。
> なお、3G/LTE再接続サービス(connection-recover)を有効にしたときの接続・切断を繰り返す周期は24時間とかではなく、数分くらいだったと思います。

いただいた syslog を確認したところ確かにリスタートが多いようにみえます。
接続されている状態に、設定されていつ ping 対象 (コンフィグファイルの PING_DEST_IP) を ping でいることを確認していただけますか?
例えば、IP が 8.8.8.8 の場合は以下のコマンドを試してください。

root@armadillo:~# ping -s 1 -c 2 -w 10 -I ppp0 8.8.8.8

このコマンドで問題なければ、出力が多くなりますが「bash -x /usr/bin/connection-recoverd」でサービスを数分実行してみてその出力を添付していただければ大変助かります。(「> /tmp/log 2>&1」などで出力をファイルに保存できます)

> また、3G/LTE再接続サービス(connection-recover)のサービスを無効にした場合には、どんな影響がありますか?
> 3G/LTE再接続サービス(connection-recover)がないと不意に切れた場合等は再接続しなくなるということでしょうか?電源OFF/ONが必要になるとか。

電源切断などの後には特に影響ないですが、モデムが変な状態に固まった場合に強制的にリセットして接続を復帰させるサービスですので、何かの理由で接続が切れた場合は対応されなくなります。
そういう問題は電波状態などにもよりますので、実際に試して長い時間で問題なければサービス無効化でもいいと思いますが、安全のためにはサービスが正常に動いてない理由を確認して修正した方がいいと考えています。

よろしくお願いします。

satoshi.sa.aoki

2024年8月23日 15時44分

ご返信ありがとうございます。

まず1点気になった点を確認させてください。設定を確認したところ、以下の通り、gsm-ttyUSB2_connection-recover.confってなっていて、デバイス名はttyCommModemを使っているので、これが原因していたりしますか?

root@armadillo:~# ls /etc/connection-recover/gsm-tty
gsm-ttyACM0_connection-recover.conf  gsm-ttyUSB2_connection-recover.conf
gsm-ttyACM3_connection-recover.conf

例えば、gsm-ttyUSB2_connection-recover.confの中身の記述は以下になっています。

#!/bin/bash
 
PRODUCT_NAME="Armadillo-IoT Gateway G3 M1 Board","Armadillo-IoT Gateway G3 W2 Boo
ard"
PING_DEST_IP=8.8.8.8
DEVICE=ttyUSB2
TYPE=gsm
NETWORK_IF=ppp0
FORCE_REBOOT=FALSE
SYMLINKDEVICE=ttyCommModem
SYMLINK_MM_PARAM=quectel-ec25-symlink
REBOOT_IF_SIM_NOT_FOUND=FALSE
WWAN_FORCE_RESTART_COUNT=1

よろしくお願いします。

satoshi.sa.aoki

2024年8月23日 15時55分

依頼頂いたコマンド「bash -x /usr/bin/connection-recoverd」を実行してみました。
実行結果は以下になります(途中で切れた現象まで取れてます)。何か原因わかりそうでしょうか?
よろしくお願いします。

root@armadillo:~# bash -x /usr/bin/connection-recoverd
+ LANG=C
+ PING_COUNT=2
+ CHECK_INTERVAL_SEC=120
+ FORCE_RECONNECT_PING_NG_COUNT=2
+ FORCE_REBOOT_PING_NG_COUNT=4
+ CONFIG_FILE_EXT=_connection-recover.conf
+ CONFIG_FILE_DIR=/etc/connection-recover/
+ SYMLINK_CONF_FILE=/etc/ModemManager/symlink.conf
+ NMCLI_UP_TIMEOUT_SEC=150
+ RESTART_SIM_NOT_FOUND_COUNT=2
+ REGEX_GSM_TTY='^gsm-tty'
+ load_config
+ OLD_IFS='
'
+ IFS='
'
++ find /etc/connection-recover/ -name '*_connection-recover.conf'
+ for CONFIG_FILE in `find ${CONFIG_FILE_DIR} -name "*${CONFIG_FILE_EXT}"`
+ clear_config
+ PRODUCT_NAME=
+ PING_DEST_IP=
+ DEVICE=
+ TYPE=
+ NETWORK_IF=
+ SYMLINKDEVICE=
+ SYMLINK_MM_PARAM=
+ WWAN_FORCE_RESTART_COUNT=
+ REBOOT_IF_SIM_NOT_FOUND=
+ read_config_file
+ . /etc/connection-recover/gsm-ttyUSB2_connection-recover.conf
++ PRODUCT_NAME='Armadillo-IoT Gateway G3 M1 Board,Armadillo-IoT Gateway G3 W2 Board'
++ PING_DEST_IP=8.8.8.8
++ DEVICE=ttyUSB2
++ TYPE=gsm
++ NETWORK_IF=ppp0
++ FORCE_REBOOT=FALSE
++ SYMLINKDEVICE=ttyCommModem
++ SYMLINK_MM_PARAM=quectel-ec25-symlink
++ REBOOT_IF_SIM_NOT_FOUND=FALSE
++ WWAN_FORCE_RESTART_COUNT=1
+ '[' '!' -n 'Armadillo-IoT Gateway G3 M1 Board,Armadillo-IoT Gateway G3 W2 Board' ']'
+ '[' '!' -n 8.8.8.8 ']'
+ '[' '!' -n ttyUSB2 ']'
+ '[' '!' -n gsm ']'
+ '[' '!' -n ppp0 ']'
+ '[' '!' -n FALSE ']'
+ OLD_IFS='
'
+ IFS=,
+ for CHECK_PRODUCT in $PRODUCT_NAME
+ grep 'Armadillo-IoT Gateway G3 M1 Board' /proc/device-tree/model -q -w
+ '[' 0 -eq 0 ']'
+ IFS='
'
+ return 0
+ IFS='
'
+ return
+ PING_NG_COUNT=0
+ SIM_NOT_FOUND_COUNT=0
+ WWAN_RESTART_COUNT=0
+ '[' -z 1 ']'
+ DEFAULT_DEVICE=ttyUSB2
+ true
+ sleep 120
+ check_use_symlink_device
+ '[' '!' -L /dev/ttyCommModem ']'
+ '[' '!' -e /etc/ModemManager/symlink.conf ']'
+ '[' -z ttyCommModem ']'
+ '[' -z quectel-ec25-symlink ']'
+ check_symlink_conf_line
+ read line
++ echo quectel-ec25-symlink
++ sed 's/ //g'
+ line=quectel-ec25-symlink
+ '[' quectel-ec25-symlink = quectel-ec25-symlink ']'
+ return 0
+ return 0
+ '[' 0 -eq 0 ']'
+ DEVICE=ttyCommModem
++ basename /etc/connection-recover/gsm-ttyUSB2_connection-recover.conf _connection-recover.conf
+ CONNECTION=gsm-ttyUSB2
+ [[ -z gsm-ttyUSB2 ]]
+ [[ gsm-ttyUSB2 =~ ^gsm-tty ]]
+ CONNECTION=gsm-ttyCommModem
+ '[' -z gsm-ttyCommModem ']'
+ active_connection_exist
+ nmcli -f NAME connection
+ grep -x -q gsm-ttyCommModem
+ sed -e 's/ *$//'
+ '[' 0 -eq 0 ']'
+ return 0
+ '[' 0 -eq 0 ']'
+ PING_STATUS=1
++ get_connection_status
++ nmcli -f DEVICE,STATE device
++ grep ttyCommModem
+ STATUS='ttyCommModem  connected              '
+ case ${STATUS} in
+ SIM_NOT_FOUND_COUNT=0
+ is_connect
+ ping -s 1 -c 2 -w 10 -I ppp0 8.8.8.8
+ '[' 0 -eq 0 ']'
+ return 0
+ PING_STATUS=0
+ '[' 0 -ne 0 ']'
+ WWAN_RESTART_COUNT=0
+ '[' 0 -ne 0 ']'
+ PING_NG_COUNT=0
+ true
+ sleep 120
+ check_use_symlink_device
+ '[' '!' -L /dev/ttyCommModem ']'
+ '[' '!' -e /etc/ModemManager/symlink.conf ']'
+ '[' -z ttyCommModem ']'
+ '[' -z quectel-ec25-symlink ']'
+ check_symlink_conf_line
+ read line
++ echo quectel-ec25-symlink
++ sed 's/ //g'
+ line=quectel-ec25-symlink
+ '[' quectel-ec25-symlink = quectel-ec25-symlink ']'
+ return 0
+ return 0
+ '[' 0 -eq 0 ']'
+ DEVICE=ttyCommModem
++ basename /etc/connection-recover/gsm-ttyUSB2_connection-recover.conf _connection-recover.conf
+ CONNECTION=gsm-ttyUSB2
+ [[ -z gsm-ttyUSB2 ]]
+ [[ gsm-ttyUSB2 =~ ^gsm-tty ]]
+ CONNECTION=gsm-ttyCommModem
+ '[' -z gsm-ttyCommModem ']'
+ active_connection_exist
+ nmcli -f NAME connection
+ grep -x -q gsm-ttyCommModem
+ sed -e 's/ *$//'
+ '[' 0 -eq 0 ']'
+ return 0
+ '[' 0 -eq 0 ']'
+ PING_STATUS=1
++ get_connection_status
++ nmcli -f DEVICE,STATE device
++ grep ttyCommModem
+ STATUS='ttyCommModem  connecting (prepare)   '
+ case ${STATUS} in
+ SIM_NOT_FOUND_COUNT=0
+ continue
+ true
+ sleep 120

at_dominique.m…

2024年8月23日 16時15分

マルティネです。

> 設定を確認したところ、以下の通り、gsm-ttyUSB2_connection-recover.confってなっていて、デバイス名はttyCommModemを使っているので、これが原因していたりしますか?

こちらについては大丈夫だと思います。
いただいた syslog を確認したところ、connection-recover はちゃんと ttyCommModem を使っていて、networkmanager のコネクション名も gsm-ttyCommModem で一致していますので大丈夫です。

ログを日本語に翻訳すると:

2024-08-07T20:04:31.341082+09:00 armadillo pppd[28160]: Connect time 6.2 minutes.
^ 理由無しで LTE の接続が切れました。

2024-08-07T20:08:28.800275+09:00 armadillo connection-recover: ttyCommModem reconnect start...
^ 数分経って、connection-recover が接続の問題に気づいて接続しなおそうとします

2024-08-07T20:09:06.765039+09:00 armadillo NetworkManager[20591]: [1723028946.7596] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-07T20:09:06.779165+09:00 armadillo connection-recover: ttyCommModem reconnect fail: 4
^ 「nmcli connection up gsm-ttyCommModem」で接続しようとしても失敗しました

それが何回か繰り替えして、
2024-08-07T20:17:46.340247+09:00 armadillo connection-recover: exec wwan-force-restart
でモデムを強制的に再起動させて、接続ができるようになりました:
2024-08-07T20:19:02.444203+09:00 armadillo NetworkManager[2516]: [1723029542.4436] manager: NetworkManager state is now CONNECTED_GLOBAL

なので、いただいたログとしては、connection-recover 自体に問題がなく、接続をすでに失った後に頑張って復帰させただけですね。
(切断の理由はログに書いてないということは、connection-recoverによる切断ではないはずです)

ping も、おそらく接続ができている状態ではちゃんと通ると思いますが、「3G/LTE再接続サービス(connection-recover)を有効にしたときの接続・切断を繰り返す周期は24時間とかではなく、数分くらいだったと思います」のコメントをいただいたので一応確認させていただきます。
その切断は意図的に connection-recover が起こしているわけではないはずですが、connection-recover が無効な状態でこの問題が発生しなくなるということは何かあるはずですので、細かいログをいただければ何かのヒントになるかもしれません。
(もしかして、ping を定期的に送ることでモデムが何か電波悪いと気づいて自ら切断しているだけかもしれません…それであれば普通に通信しようとしても同じ結果になると思いますが、どうでしょうか。接続ができている状態で「mmcli -m 0」の「signal quality」の行を確認していただけますか?)

大変お手数ですが、今いただいた情報では原因が分かりませんので、引き続きよろしくお願いします。

at_dominique.m…

2024年8月23日 17時05分

マルティネです。

連続ですみません、二つ目の返事を気づいてなかったです。

> 依頼頂いたコマンド「bash -x /usr/bin/connection-recoverd」を実行してみました。
> 実行結果は以下になります(途中で切れた現象まで取れてます)。何か原因わかりそうでしょうか?

ログありがとうございます。

そのログでは、
- ping が正常にできています
- 2分後に接続状態を確認したところ nmcli に状態を確認したところ「connecting」になっていたので、すでに切断していた。

ということで、connection-recover がやはり切断を意図的に起こしているわけではありませんが、実行していない状態で切断しないならこの接続がただ通信に弱いなだけに見えます。

引き続きとして:
- 前回の返事で聞いた「mmcli -m 0」の signal quality の行の確認
- 確認するまでもないと思いますが、connection-recover を停止した状態に ppp0 経由に通信を定期的に実行して同じく切断するかどうか(例えば「ping -s 1 -c 2 -w 10 -I ppp0 8.8.8.8」)

よろしくお願いします。

satoshi.sa.aoki

2024年8月23日 17時31分

ありがとうございます。

信号強度は、通信できているときには100%、通信できていないときには、60%になってから、0%になります。
以下、データ通信できている状態での mmcli -m 0コマンドの実行結果になります。

  --------------------------------
  General  |                 path: /org/freedesktop/ModemManager1/Modem/0
           |            device id: f0089cde66e6fa6fb82e3d2a61224abae59bea47
  --------------------------------
  Hardware |         manufacturer: Quectel
           |                model: EC25
           |    firmware revision: EC25JFAR06A03M4G_SBK
           |            supported: gsm-umts, lte
           |              current: gsm-umts, lte
           |         equipment id: 861107039126959
  --------------------------------
  System   |               device: /sys/devices/soc0/soc/30800000.aips-bus/30b30000.usb/ci_hdrc.1/usb2/2-1/2-1.2
           |              drivers: option
           |               plugin: quectel-ec25
           |         primary port: ttyCommModem
           |                ports: ttyCommModem (at), ttyUSB1 (ignored), ttyUSB2 (gps),
           |                       ttyUSB4 (at)
  --------------------------------
  Numbers  |                  own: 0**********
  --------------------------------
  Status   |       unlock retries: sim-pin (3), sim-puk (10), sim-pin2 (3), sim-puk2 (10)
           |                state: connected
           |          power state: on
           |          access tech: lte
           |       signal quality: 100% (recent)
  --------------------------------
  Modes    |            supported: allowed: 2g, 3g, 4g; preferred: none
           |              current: allowed: 2g, 3g, 4g; preferred: none
  --------------------------------
  Bands    |            supported: utran-1, utran-8, eutran-1, eutran-3, eutran-8, eutran-26,
           |                       eutran-41, utran-19
           |              current: eutran-41
  --------------------------------
  IP       |            supported: ipv4, ipv6, ipv4v6
  --------------------------------
  3GPP     |                 imei: 8611**********
           |          operator id: 44020
           |        operator name: SoftBank SoftBank
           |         registration: home
           | packet service state: attached
  --------------------------------
  3GPP EPS | ue mode of operation: csps-2
  --------------------------------
  SIM      |     primary sim path: /org/freedesktop/ModemManager1/SIM/0
  --------------------------------
  Bearer   |                paths: /org/freedesktop/ModemManager1/Bearer/0

一方、データ通信ができていないときのmmcli -m 0のコマンドの実行結果は以下です。

root@armadillo:~# mmcli -m 0
  --------------------------------
  General  |                 path: /org/freedesktop/ModemManager1/Modem/0
           |            device id: f0089cde66e6fa6fb82e3d2a61224abae59bea47
  --------------------------------
  Hardware |         manufacturer: Quectel
           |                model: EC25
           |    firmware revision: EC25JFAR06A03M4G_SBK
           |            supported: gsm-umts, lte
           |              current: gsm-umts, lte
           |         equipment id: 861107039126959
  --------------------------------
  System   |               device: /sys/devices/soc0/soc/30800000.aips-bus/30b30000.usb/ci_hdrc.1/usb2/2-1/2-1.2
           |              drivers: option
           |               plugin: quectel-ec25
           |         primary port: ttyCommModem
           |                ports: ttyCommModem (at), ttyUSB1 (ignored), ttyUSB2 (gps),
           |                       ttyUSB4 (at)
  --------------------------------
  Numbers  |                  own: 0**********
  --------------------------------
  Status   |       unlock retries: sim-pin (3), sim-puk (10), sim-pin2 (3), sim-puk2 (10)
           |                state: connecting
           |          power state: on
           |       signal quality: 60% (recent)
  --------------------------------
  Modes    |            supported: allowed: 2g, 3g, 4g; preferred: none
           |              current: allowed: 2g, 3g, 4g; preferred: none
  --------------------------------
  Bands    |            supported: utran-1, utran-8, eutran-1, eutran-3, eutran-8, eutran-26,
           |                       eutran-41, utran-19
           |              current: eutran-41
  --------------------------------
  IP       |            supported: ipv4, ipv6, ipv4v6
  --------------------------------
  3GPP     |                 imei: 8**********
           |         registration: home
           | packet service state: attached
  --------------------------------
  3GPP EPS | ue mode of operation: csps-2
  --------------------------------
  SIM      |     primary sim path: /org/freedesktop/ModemManager1/SIM/0
  --------------------------------
  Bearer   |                paths: /org/freedesktop/ModemManager1/Bearer/1
           |                       /org/freedesktop/ModemManager1/Bearer/0

信号強度が60%になった後、以下のように0%になりました。

  --------------------------------
  General  |                 path: /org/freedesktop/ModemManager1/Modem/0
           |            device id: f0089cde66e6fa6fb82e3d2a61224abae59bea47
  --------------------------------
  Hardware |         manufacturer: Quectel
           |                model: EC25
           |    firmware revision: EC25JFAR06A03M4G_SBK
           |            supported: gsm-umts, lte
           |              current: gsm-umts, lte
           |         equipment id: 861107039126959
  --------------------------------
  System   |               device: /sys/devices/soc0/soc/30800000.aips-bus/30b30000.usb/ci_hdrc.1/usb2/2-1/2-1.2
           |              drivers: option
           |               plugin: quectel-ec25
           |         primary port: ttyCommModem
           |                ports: ttyCommModem (at), ttyUSB1 (ignored), ttyUSB2 (gps),
           |                       ttyUSB4 (at)
  --------------------------------
  Numbers  |                  own: 0**********
  --------------------------------
  Status   |       unlock retries: sim-pin (3), sim-puk (10), sim-pin2 (3), sim-puk2 (10)
           |                state: searching
           |          power state: on
           |       signal quality: 0% (cached)
  --------------------------------
  Modes    |            supported: allowed: 2g, 3g, 4g; preferred: none
           |              current: allowed: 2g, 3g, 4g; preferred: none
  --------------------------------
  Bands    |            supported: utran-1, utran-8, eutran-1, eutran-3, eutran-8, eutran-26,
           |                       eutran-41, utran-19
           |              current: eutran-41
  --------------------------------
  IP       |            supported: ipv4, ipv6, ipv4v6
  --------------------------------
  3GPP     |                 imei: 8**********
           |         registration: searching
           | packet service state: detached
  --------------------------------
  3GPP EPS | ue mode of operation: csps-2
  --------------------------------
  SIM      |     primary sim path: /org/freedesktop/ModemManager1/SIM/0
  --------------------------------
  Bearer   |                paths: /org/freedesktop/ModemManager1/Bearer/2
           |                       /org/freedesktop/ModemManager1/Bearer/1
           |                       /org/freedesktop/ModemManager1/Bearer/0

再度connection-recoverを起動している状態の接続・切断のsyslogを取ってみたのですが何か原因おわかりになりますか?

root@armadillo:~# tail -f /var/log/syslog
2024-08-23T17:09:35.562077+09:00 armadillo systemd[3396]: Startup finished in 2.564s.
2024-08-23T17:09:36.616216+09:00 armadillo ricoh-iot-gateway.AppImage[3465]: [3465:0823/170936.611379:ERROR:gpu_memory_buffer_support_x11.cc(49)] dri3 extension not supported.
2024-08-23T17:09:36.677198+09:00 armadillo ricoh-iot-gateway.AppImage[3348]: [3348:0823/170936.674896:ERROR:command_buffer_proxy_impl.cc(128)] ContextResult::kTransientFailure: Failed to send GpuControl.CreateCommandBuffer.
2024-08-23T17:09:38.329366+09:00 armadillo systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
2024-08-23T17:09:42.017524+09:00 armadillo systemd[1]: systemd-hostnamed.service: Deactivated successfully.
2024-08-23T17:09:57.260385+09:00 armadillo pppd[3168]: IPV6CP: timeout sending Config-Requests
2024-08-23T17:09:57.261379+09:00 armadillo NetworkManager[3168]: IPV6CP: timeout sending Config-Requests
2024-08-23T17:09:58.167391+09:00 armadillo systemd-timesyncd[1338]: Contacted time server 45.76.211.39:123 (2.debian.pool.ntp.org).
2024-08-23T17:09:58.168251+09:00 armadillo systemd-timesyncd[1338]: Initial clock synchronization to Fri 2024-08-23 17:09:57.882896 JST.
2024-08-23T17:10:01.205465+09:00 armadillo CRON[3861]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:11:01.337797+09:00 armadillo CRON[3915]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:12:01.470210+09:00 armadillo CRON[3979]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:13:01.604178+09:00 armadillo CRON[4025]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:14:01.742142+09:00 armadillo CRON[4090]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:15:01.875153+09:00 armadillo CRON[4136]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:15:12.529209+09:00 armadillo pppd[3168]: LCP terminated by peer
2024-08-23T17:15:12.530334+09:00 armadillo pppd[3168]: nm-ppp-plugin: status 8 / phase 'network'
2024-08-23T17:15:12.531080+09:00 armadillo NetworkManager[3168]: LCP terminated by peer
2024-08-23T17:15:12.531555+09:00 armadillo NetworkManager[3168]: Connect time 5.8 minutes.
2024-08-23T17:15:12.532007+09:00 armadillo NetworkManager[3168]: Sent 23696 bytes, received 23821 bytes.
2024-08-23T17:15:12.532763+09:00 armadillo pppd[3168]: Connect time 5.8 minutes.
2024-08-23T17:15:12.533521+09:00 armadillo pppd[3168]: Sent 23696 bytes, received 23821 bytes.
2024-08-23T17:15:12.540234+09:00 armadillo systemd-networkd[325]: ppp0: Link DOWN
2024-08-23T17:15:12.541630+09:00 armadillo systemd-networkd[325]: ppp0: Lost carrier
2024-08-23T17:15:12.563409+09:00 armadillo pppd[3168]: nm-ppp-plugin: status 5 / phase 'establish'
2024-08-23T17:15:12.572055+09:00 armadillo pppd[3168]: Modem hangup
2024-08-23T17:15:12.573039+09:00 armadillo pppd[3168]: nm-ppp-plugin: status 11 / phase 'disconnect'
2024-08-23T17:15:12.573805+09:00 armadillo NetworkManager[3168]: Modem hangup
2024-08-23T17:15:12.574369+09:00 armadillo NetworkManager[3168]: Connection terminated.
2024-08-23T17:15:12.574987+09:00 armadillo pppd[3168]: Connection terminated.
2024-08-23T17:15:12.578377+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.5767] device (ppp0): state change: disconnected -> unmanaged (reason 'connection-assumed', sys-iface-state: 'external')
2024-08-23T17:15:12.627171+09:00 armadillo ModemManager[2562]: <info>  [modem0] mobile equipment forced PS detach: all contexts have been deactivated
2024-08-23T17:15:12.628020+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer0] explicitly disconnected
2024-08-23T17:15:12.628734+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (home -> registering)
2024-08-23T17:15:12.672561+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.6702] device (ttyCommModem): state change: activated -> failed (reason 'ppp-disconnect', sys-iface-state: 'managed')
2024-08-23T17:15:12.673595+09:00 armadillo NetworkManager[3168]: Terminating on signal 15
2024-08-23T17:15:12.677674+09:00 armadillo pppd[3168]: Terminating on signal 15
2024-08-23T17:15:12.681796+09:00 armadillo [3168]: nm-ppp-plugin: status 1 / phase 'dead'
2024-08-23T17:15:12.683387+09:00 armadillo pppd[3168]: Exit.
2024-08-23T17:15:12.689066+09:00 armadillo [3168]: nm-ppp-plugin: cleaning up
2024-08-23T17:15:12.692667+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.6750] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:15:12.702445+09:00 armadillo NetworkManager[2564]: <warn>  [1724400912.6909] device (ttyCommModem): Activation: failed for connection 'gsm-ttyCommModem'
2024-08-23T17:15:12.706099+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:15:12.716108+09:00 armadillo dbus-daemon[1743]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.8' (uid=0 pid=2564 comm="/usr/sbin/NetworkManager --no-daemon")
2024-08-23T17:15:12.729070+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.7283] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:15:12.737856+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (connected -> disconnecting)
2024-08-23T17:15:12.751005+09:00 armadillo dnsmasq[2868]: no servers found in /etc/resolv.conf, will retry
2024-08-23T17:15:12.803612+09:00 armadillo systemd[1]: Starting NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service...
2024-08-23T17:15:12.804601+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.8028] policy: auto-activating connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:15:12.824936+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.8244] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:15:12.826407+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.8258] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:15:12.830305+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.8298] manager: NetworkManager state is now CONNECTING
2024-08-23T17:15:12.833190+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.8327] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:15:12.860149+09:00 armadillo NetworkManager[2564]: <info>  [1724400912.8596] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:15:12.884030+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:15:12.884828+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (4/10): wait to get fully enabled
2024-08-23T17:15:12.907903+09:00 armadillo dbus-daemon[1743]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
2024-08-23T17:15:12.912700+09:00 armadillo systemd[1]: Started NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service.
2024-08-23T17:15:13.777598+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (disconnecting -> registered)
2024-08-23T17:15:13.778479+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (5/10): wait after enabled
2024-08-23T17:15:13.779196+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer0] connection #1 finished: duration 346s
2024-08-23T17:15:13.875451+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:15:13.876256+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:15:21.922014+09:00 armadillo connection-recover: ttyCommModem ping fail
2024-08-23T17:15:21.938514+09:00 armadillo connection-recover: ttyCommModem reconnect start...
2024-08-23T17:15:22.126054+09:00 armadillo NetworkManager[2564]: <info>  [1724400922.1245] device (ttyCommModem): state change: prepare -> deactivating (reason 'user-requested', sys-iface-state: 'managed')
2024-08-23T17:15:22.127007+09:00 armadillo NetworkManager[2564]: <info>  [1724400922.1266] manager: NetworkManager state is now DISCONNECTING
2024-08-23T17:15:22.143030+09:00 armadillo NetworkManager[2564]: <error> [1724400922.1424] audit: failed to open auditd socket: Protocol not supported
2024-08-23T17:15:22.144141+09:00 armadillo NetworkManager[2564]: <info>  [1724400922.1426] audit: op="connection-deactivate" uuid="628d359b-fb75-43c8-bd87-d1c41c26329a" name="gsm-ttyCommModem" pid=4261 uid=0 result="success"
2024-08-23T17:15:22.167311+09:00 armadillo NetworkManager[2564]: <info>  [1724400922.1667] device (ttyCommModem): state change: deactivating -> disconnected (reason 'user-requested', sys-iface-state: 'managed')
2024-08-23T17:15:22.170540+09:00 armadillo NetworkManager[2564]: <info>  [1724400922.1700] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:15:27.351684+09:00 armadillo NetworkManager[2564]: <info>  [1724400927.3501] agent-manager: agent[c664485cbfe5956d,:1.29/nmcli-connect/0]: agent registered
2024-08-23T17:15:27.360612+09:00 armadillo NetworkManager[2564]: <info>  [1724400927.3601] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:15:27.364578+09:00 armadillo NetworkManager[2564]: <info>  [1724400927.3640] audit: op="connection-activate" uuid="628d359b-fb75-43c8-bd87-d1c41c26329a" name="gsm-ttyCommModem" pid=4281 uid=0 result="success"
2024-08-23T17:15:27.366862+09:00 armadillo NetworkManager[2564]: <info>  [1724400927.3663] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:15:27.372845+09:00 armadillo NetworkManager[2564]: <info>  [1724400927.3723] manager: NetworkManager state is now CONNECTING
2024-08-23T17:15:27.375723+09:00 armadillo NetworkManager[2564]: <info>  [1724400927.3752] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:15:27.385211+09:00 armadillo NetworkManager[2564]: <info>  [1724400927.3847] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:15:27.407671+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:15:27.408452+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:15:27.409162+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:15:32.281160+09:00 armadillo systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
2024-08-23T17:15:38.153485+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:15:38.154491+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:15:38.155188+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:15:48.154312+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:15:48.155228+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:15:48.155922+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:15:58.154710+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:15:58.155646+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:15:58.156650+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:16:02.009998+09:00 armadillo CRON[4308]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:16:08.139034+09:00 armadillo NetworkManager[2564]: <warn>  [1724400968.1370] modem-broadband[ttyCommModem]: failed to connect modem: Too much time waiting to get to a final packet service state
2024-08-23T17:16:08.140337+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1372] device (ttyCommModem): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
2024-08-23T17:16:08.141175+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1391] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:16:08.141934+09:00 armadillo NetworkManager[2564]: <warn>  [1724400968.1411] device (ttyCommModem): Activation: failed for connection 'gsm-ttyCommModem'
2024-08-23T17:16:08.142724+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1423] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:16:08.147019+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1447] policy: auto-activating connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:16:08.156048+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1501] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:16:08.167103+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1645] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:16:08.168901+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1665] manager: NetworkManager state is now CONNECTING
2024-08-23T17:16:08.175603+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1736] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:16:08.184877+09:00 armadillo NetworkManager[2564]: <info>  [1724400968.1843] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:16:08.195590+09:00 armadillo connection-recover: ttyCommModem reconnect fail: 4
2024-08-23T17:16:08.225304+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:16:08.226085+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:16:08.226782+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:16:11.303415+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (home -> searching)
2024-08-23T17:16:11.304368+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> searching)
2024-08-23T17:16:18.151667+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:16:18.152580+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (4/10): wait to get fully enabled
2024-08-23T17:16:18.153275+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (5/10): wait after enabled
2024-08-23T17:16:18.251417+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:16:18.313733+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (searching -> registered)
2024-08-23T17:16:18.316273+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (searching -> registering)
2024-08-23T17:16:18.317088+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:16:18.360003+09:00 armadillo ModemManager[2562]: <warn>  [modem0] couldn't load operator code: Couldn't match response
2024-08-23T17:16:18.386830+09:00 armadillo ModemManager[2562]: <warn>  [modem0] couldn't load operator name: Couldn't match response
2024-08-23T17:16:18.387913+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:16:18.388929+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:16:18.389826+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:16:18.391244+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:16:18.394002+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:16:22.411714+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer0] (quectel-ec25) Couldn't Activate PDP context: 'Unknown error'
2024-08-23T17:16:22.412829+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer0] connection attempt #2 failed: Unknown error
2024-08-23T17:16:22.414795+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer0] connection #2 finished: duration 0s
2024-08-23T17:16:22.432805+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:16:22.433797+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:16:22.435082+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:16:22.436084+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:16:22.440538+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:16:22.442200+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:16:22.537563+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer1] (quectel-ec25) Couldn't Activate PDP context: 'Unknown error'
2024-08-23T17:16:22.538450+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer1] connection attempt #1 failed: Unknown error
2024-08-23T17:16:22.539190+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:16:22.543126+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer1] connection #1 finished: duration 0s
2024-08-23T17:16:22.558337+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:16:22.559117+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:16:22.559826+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:16:22.560491+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:16:22.562697+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:16:22.564023+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:16:22.961505+09:00 armadillo ModemManager[2562]: <info>  [modem0] mobile equipment forced PS detach: all contexts have been deactivated
2024-08-23T17:16:22.962373+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer2] explicitly disconnected
2024-08-23T17:16:22.963086+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:16:22.966211+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer2] connection #1 finished: duration 0s
2024-08-23T17:16:22.966988+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (home -> idle)
2024-08-23T17:16:22.967722+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> enabled)
2024-08-23T17:16:26.442738+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (idle -> searching)
2024-08-23T17:16:26.444524+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (enabled -> searching)
2024-08-23T17:16:50.727201+09:00 armadillo ModemManager[2562]: <systemd-journald[294]: Data hash table of /run/log/journal/6ec5a7b39d134c53adf80e26bd08abd8/system.journal has a fill level at 75.0 (3398 of 4529 items, 2609152 file size, 767 bytes per hash table item), suggesting rotation.
warn>  [modem0/bearer2] connectiosystemd-journald[294]: /run/log/journal/6ec5a7b39d134c53adf80e26bd08abd8/system.journal: Journal header limits reached or header out-of-date, rotating.
n attempt #1 failed: Couldn't match response
2024-08-23T17:16:50.731475+09:00 armadillo NetworkManager[2564]: <warn>  [1724401010.7297] modem-broadband[ttyCommModem]: failed to connect modem: Too much time waiting to get to a final packet service state
2024-08-23T17:16:50.732399+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.7299] device (ttyCommModem): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
2024-08-23T17:16:50.791062+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.7318] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:16:50.792460+09:00 armadillo NetworkManager[2564]: <warn>  [1724401010.7337] device (ttyCommModem): Activation: failed for connection 'gsm-ttyCommModem'
2024-08-23T17:16:50.793459+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.7603] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:16:50.804686+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.7626] policy: auto-activating connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:16:50.805665+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.7661] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:16:50.806996+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.7668] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:16:50.807846+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.7689] manager: NetworkManager state is now CONNECTING
2024-08-23T17:16:50.808711+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.7923] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:16:50.832465+09:00 armadillo NetworkManager[2564]: <info>  [1724401010.8319] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:16:50.861499+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:16:50.862664+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (4/10): wait to get fully enabled
2024-08-23T17:16:50.863837+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (5/10): wait after enabled
2024-08-23T17:16:50.962344+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:16:51.032480+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (searching -> registered)
2024-08-23T17:16:51.033420+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (searching -> registering)
2024-08-23T17:16:51.037290+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:16:51.082386+09:00 armadillo ModemManager[2562]: <warn>  [modem0] couldn't load operator code: Couldn't match response
2024-08-23T17:16:51.109420+09:00 armadillo ModemManager[2562]: <warn>  [modem0] couldn't load operator name: Couldn't match response
2024-08-23T17:16:51.110469+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:16:51.111529+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:16:51.112375+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:16:51.113822+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:16:51.116768+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:16:51.561450+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (home -> idle)
2024-08-23T17:16:51.562842+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> enabled)
2024-08-23T17:16:55.062811+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (idle -> registering)
2024-08-23T17:16:55.196175+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:16:55.197711+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (enabled -> registered)
2024-08-23T17:16:55.255725+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer0] (quectel-ec25) Couldn't Activate PDP context: 'Unknown error'
2024-08-23T17:16:55.257205+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer0] connection attempt #3 failed: Operation was cancelled
2024-08-23T17:16:55.258863+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> disconnecting)
2024-08-23T17:16:55.263768+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (disconnecting -> registered)
2024-08-23T17:16:55.266387+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer0] connection #3 finished: duration 0s
2024-08-23T17:16:55.280443+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:16:55.281556+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:16:55.282853+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:16:55.284025+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:16:55.285209+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:16:55.286787+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:16:55.381887+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer1] (quectel-ec25) Couldn't Activate PDP context: 'Unknown error'
2024-08-23T17:16:55.383051+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer1] connection attempt #2 failed: Unknown error
2024-08-23T17:16:55.384732+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:16:55.386891+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer1] connection #2 finished: duration 0s
2024-08-23T17:16:55.406842+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:16:55.407628+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:16:55.408263+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:16:55.408923+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:16:55.409548+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:16:55.410209+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:16:55.847875+09:00 armadillo ModemManager[2562]: <info>  [modem0] mobile equipment forced PS detach: all contexts have been deactivated
2024-08-23T17:16:55.849106+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer2] explicitly disconnected
2024-08-23T17:16:55.850338+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:16:55.852397+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer2] connection #2 finished: duration 0s
2024-08-23T17:16:55.855121+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (home -> idle)
2024-08-23T17:16:55.856467+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> enabled)
2024-08-23T17:16:59.333551+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (idle -> searching)
2024-08-23T17:16:59.334481+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (enabled -> searching)
2024-08-23T17:17:01.150746+09:00 armadillo CRON[4388]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
2024-08-23T17:17:01.166473+09:00 armadillo CRON[4390]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:17:23.615208+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer2] connection attempt #2 failed: Couldn't match response
2024-08-23T17:17:23.625993+09:00 armadillo NetworkManager[2564]: <warn>  [1724401043.6174] modem-broadband[ttyCommModem]: failed to connect modem: Operation was cancelled
2024-08-23T17:17:23.630054+09:00 armadillo NetworkManager[2564]: <info>  [1724401043.6176] device (ttyCommModem): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
2024-08-23T17:17:23.634561+09:00 armadillo NetworkManager[2564]: <info>  [1724401043.6194] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:17:23.640834+09:00 armadillo NetworkManager[2564]: <warn>  [1724401043.6214] device (ttyCommModem): Activation: failed for connection 'gsm-ttyCommModem'
2024-08-23T17:17:23.643313+09:00 armadillo NetworkManager[2564]: <info>  [1724401043.6355] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:18:01.314632+09:00 armadillo CRON[4464]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:18:08.549886+09:00 armadillo connection-recover: ttyCommModem reconnect start...
2024-08-23T17:18:13.846722+09:00 armadillo NetworkManager[2564]: <info>  [1724401093.8452] agent-manager: agent[35f25d259e8a9bac,:1.33/nmcli-connect/0]: agent registered
2024-08-23T17:18:13.856560+09:00 armadillo NetworkManager[2564]: <info>  [1724401093.8560] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:18:13.858627+09:00 armadillo NetworkManager[2564]: <info>  [1724401093.8582] audit: op="connection-activate" uuid="628d359b-fb75-43c8-bd87-d1c41c26329a" name="gsm-ttyCommModem" pid=4526 uid=0 result="success"
2024-08-23T17:18:13.864270+09:00 armadillo NetworkManager[2564]: <info>  [1724401093.8603] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:18:13.865628+09:00 armadillo NetworkManager[2564]: <info>  [1724401093.8622] manager: NetworkManager state is now CONNECTING
2024-08-23T17:18:13.866838+09:00 armadillo NetworkManager[2564]: <info>  [1724401093.8636] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:18:13.875844+09:00 armadillo NetworkManager[2564]: <info>  [1724401093.8753] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:18:13.900530+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:18:13.901348+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (4/10): wait to get fully enabled
2024-08-23T17:18:13.902065+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (5/10): wait after enabled
2024-08-23T17:18:14.000063+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:18:14.060792+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (searching -> registered)
2024-08-23T17:18:14.062430+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (searching -> registering)
2024-08-23T17:18:14.063194+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:18:14.104879+09:00 armadillo ModemManager[2562]: <warn>  [modem0] couldn't load operator code: Couldn't match response
2024-08-23T17:18:14.130396+09:00 armadillo ModemManager[2562]: <warn>  [modem0] couldn't load operator name: Couldn't match response
2024-08-23T17:18:14.131153+09:00 armadillo ModemManager[2562]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:18:14.131838+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:18:14.132499+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:18:14.133249+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:18:14.138129+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:18:18.167878+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer0] (quectel-ec25) Couldn't Activate PDP context: 'Unknown error'
2024-08-23T17:18:18.168725+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer0] connection attempt #4 failed: Unknown error
2024-08-23T17:18:18.170763+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer0] connection #4 finished: duration 0s
2024-08-23T17:18:18.186821+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect started...
2024-08-23T17:18:18.187581+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:18:18.188343+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:18:18.189027+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:18:18.189680+09:00 armadillo ModemManager[2562]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:18:18.190580+09:00 armadillo ModemManager[2562]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:18:21.395062+09:00 armadillo ModemManager[2562]: <warn>  [modem0] (shared-quectel) modem reset detected, triggering reprobe
2024-08-23T17:18:21.400443+09:00 armadillo NetworkManager[2564]: <info>  [1724401101.3989] device (ttyCommModem): state change: prepare -> unmanaged (reason 'removed', sys-iface-state: 'removed')
2024-08-23T17:18:21.407222+09:00 armadillo NetworkManager[2564]: <info>  [1724401101.4039] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:18:21.417503+09:00 armadillo ModemManager[2562]: <warn>  [modem0] couldn't load network timezone from the current network
2024-08-23T17:18:21.432814+09:00 armadillo NetworkManager[2564]: <warn>  [1724401101.4322] modem-broadband[ttyCommModem]: failed to disconnect modem: GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: Object does not exist at path “/org/freedesktop/ModemManager1/Modem/0”
2024-08-23T17:18:21.456073+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer1] (quectel-ec25) Couldn't Activate PDP context: 'AT command was cancelled'
2024-08-23T17:18:21.457411+09:00 armadillo ModemManager[2562]: <warn>  [modem0/bearer1] connection attempt #3 failed: AT command was cancelled
2024-08-23T17:18:21.466065+09:00 armadillo ModemManager[2562]: <info>  [modem0/bearer1] connection #3 finished: duration 0s
2024-08-23T17:18:21.469036+09:00 armadillo connection-recover: ttyCommModem reconnect fail: 4
2024-08-23T17:18:21.482048+09:00 armadillo connection-recover: exec wwan-force-restart
2024-08-23T17:18:21.722869+09:00 armadillo /usr/bin/wwan-force-restart: start force restart ec25
2024-08-23T17:18:22.254247+09:00 armadillo ModemManager[2562]: <info>  caught signal, shutting down...
2024-08-23T17:18:22.256260+09:00 armadillo systemd[1]: Stopping ModemManager.service - Modem Manager...
2024-08-23T17:18:22.265343+09:00 armadillo NetworkManager[2564]: <info>  [1724401102.2648] modem-manager: ModemManager no longer available
2024-08-23T17:18:22.267774+09:00 armadillo ModemManager[2562]: <info>  ModemManager is shut down
2024-08-23T17:18:22.326436+09:00 armadillo systemd[1]: ModemManager.service: Deactivated successfully.
2024-08-23T17:18:22.327629+09:00 armadillo systemd[1]: Stopped ModemManager.service - Modem Manager.
usb 2-1.2: USB disconnect, device number 4
option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
2024-08-23T17:18:37.450313+09:00 option 2-1.2:1.0: device disconnected
armadillo kernel: usb 2-1.2: USB option1 ttyUSB2: GSM modem (1-port) converter now disconnected from ttyUSB2
disconnect, device number 4
2024-08-23T17:18:37.450394+09:00 armadillo kernel: option1 ttyUSB1option 2-1.2:1.1: device disconnected
: GSM modem (1-port) converter now disconnected from ttyUSB1
2024-08-23T17:18:37.457200+09:00 armadillo kernel: option 2-1.2:1.0: device disconnected
2024-08-23T17:18:37.467062+09:00 armadillo kernel: option1 ttyUSB2:option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
 GSM modem (1-port) converter now disconnected from ttyUSB2
2024-08-23T17:18:37.479261+09:00 armadillo kernel: option 2-1.2:1option 2-1.2:1.2: device disconnected
.1: device disconnected
2024-08-23T17:18:37.504274+09:00 armadioption1 ttyUSB4: GSM modem (1-port) converter now disconnected from ttyUSB4
llo kernel: option1 ttyUSB3: GSM modem (1-port) converter now disconnected from ttyUSB3
2024-08-23T17:18:37.531026+09:00 armadillo kernel: option 2-1.2:1.2: device disconnected
2024-08-2option 2-1.2:1.3: device disconnected
3T17:18:37.531121+09:00 armadillo kernel: option1 ttyUSB4: GSM modem (1-port) converter now disconnected from ttyUSB4
2024-08-23T17:18:37.554862+09:00 armadillo kernel: option 2-1.2:1.3: device disconnected
2024-08-23T17:18:39.046278+09:00 armadillo systemd[1]: Starting ModemManager.service - Modem Manager...
2024-08-23T17:18:39.522151+09:00 armadillo ModemManager[4704]: <info>  ModemManager (version 1.20.4) starting in system bus...
2024-08-23T17:18:39.624411+09:00 armadillo systemd[1]: Started ModemManager.service - Modem Manager.
2024-08-23T17:18:39.944912+09:00 armadillo NetworkManager[2564]: <info>  [1724401119.9432] modem-manager: ModemManager now available
2024-08-23T17:18:42.339856+09:00 armadillo ModemManager[4704]: <info>  [base-manager] couldn't check support for device '/sys/devices/soc0/soc/30800000.aips-bus/30b30000.usb/ci_hdrc.1/usb2/2-1/2-1.3': not supported by any plugin
2024-08-23T17:18:42.414519+09:00 armadillo ModemManager[4704]: <info>  [base-manager] couldn't check support for device '/sys/devices/soc0/soc/30800000.aips-bus/30bf0000.ethernet': not supported by any plugin
usb 2-1.2: new high-speed USB device number 5 using ci_hdrc
2024-08-23T17:18:51.053996+09:00 armadillo kernel: usb 2-1.2: new high-speed USB device number 5 using ci_hdrc
option 2-1.2:1.0: GSM modem (1-port) converter detected
usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB1
2024-08-23T17:18:51.216911+09:00 armadillo kernel: option 2-1.2:option 2-1.2:1.1: GSM modem (1-port) converter detected
1.0: GSM modem (1-port) converter detected
2024-08-23T17:18:51.216996+09:00 armadillo kernel: usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB2
usb 2-1.2: GSM modem (1-port) conoption 2-1.2:1.2: GSM modem (1-port) converter detected
verter now attached to ttyUSB1
2024-08-23T17:18:51.227939+09:00usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB3
 armadillo kernel: option 2-1.2:1option 2-1.2:1.3: GSM modem (1-port) converter detected
.1: GSM modem (1-port) converter detected
2024-08-23T17:18:51.2usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB4
49722+09:00 armadillo kernel: usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB2
2024-08-23T17:18:51.249806+09:00 armadillo kernel: option 2-1.2:1.2: GSM modem (1-port) converter detected
2024-08-23T17:18:51.268809+09:00 armadillo kernel: usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB3
2024-08-23T17:18:51.268888+09:00 armadillo kernel: option 2-1.2:1.3: GSM modem (1-port) converter detected
2024-08-23T17:18:51.280056+09:00 armadillo kernel: usb 2-1.2: GSM modem (1-port) converter now attached to ttyUSB4
2024-08-23T17:19:01.466914+09:00 armadillo CRON[4887]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:19:07.238366+09:00 armadillo ModemManager[4704]: <info>  [device /sys/devices/soc0/soc/30800000.aips-bus/30b30000.usb/ci_hdrc.1/usb2/2-1/2-1.2] creating modem with plugin 'quectel-ec25' and '4' ports
2024-08-23T17:19:07.257543+09:00 armadillo ModemManager[4704]: <info>  [base-manager] modem for device '/sys/devices/soc0/soc/30800000.aips-bus/30b30000.usb/ci_hdrc.1/usb2/2-1/2-1.2' successfully created
2024-08-23T17:19:08.215032+09:00 armadillo ModemManager[4704]: <info>  [modem0] state changed (unknown -> disabled)
2024-08-23T17:19:08.235158+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.2334] manager: (ttyCommModem): new Broadband device (/org/freedesktop/NetworkManager/Devices/13)
2024-08-23T17:19:08.254812+09:00 armadillo ModemManager[4704]: <info>  [modem0] state changed (disabled -> enabling)
2024-08-23T17:19:08.257756+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.2572] device (ttyCommModem): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
2024-08-23T17:19:08.262666+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.2622] device (ttyCommModem): modem state 'enabling'
2024-08-23T17:19:08.266105+09:00 armadillo ModemManager[4704]: <info>  [modem0] power state updated: on
2024-08-23T17:19:08.273850+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.2733] device (ttyCommModem): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:08.516233+09:00 armadillo ModemManager[4704]: <info>  [modem0] state changed (enabling -> registered)
2024-08-23T17:19:08.749699+09:00 armadillo ModemManager[4704]: <info>  [modem0] state changed (registered -> enabled)
2024-08-23T17:19:08.761188+09:00 armadillo ModemManager[4704]: <info>  [modem0] 3GPP registration state changed (unknown -> registering)
2024-08-23T17:19:08.829248+09:00 armadillo ModemManager[4704]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:19:08.830105+09:00 armadillo ModemManager[4704]: <info>  [modem0] state changed (enabled -> registered)
2024-08-23T17:19:08.929602+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.9289] agent-manager: agent[676faa638264c0f8,:1.53/nmcli-connect/0]: agent registered
2024-08-23T17:19:08.940444+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.9399] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:19:08.943436+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.9429] audit: op="connection-activate" uuid="628d359b-fb75-43c8-bd87-d1c41c26329a" name="gsm-ttyCommModem" pid=4966 uid=0 result="success"
2024-08-23T17:19:08.945466+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.9446] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:08.953194+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.9527] manager: NetworkManager state is now CONNECTING
2024-08-23T17:19:08.958544+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.9580] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:08.969519+09:00 armadillo NetworkManager[2564]: <info>  [1724401148.9687] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:08.996090+09:00 armadillo ModemManager[4704]: <info>  [modem0] simple connect started...
2024-08-23T17:19:08.996983+09:00 armadillo ModemManager[4704]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:19:08.997667+09:00 armadillo ModemManager[4704]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:19:08.998351+09:00 armadillo ModemManager[4704]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:19:08.998993+09:00 armadillo ModemManager[4704]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:19:08.999637+09:00 armadillo ModemManager[4704]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:19:09.111411+09:00 armadillo ModemManager[4704]: <info>  [modem0] state changed (connecting -> connected)
2024-08-23T17:19:09.116133+09:00 armadillo ModemManager[4704]: <info>  [modem0] simple connect state (10/10): all done
2024-08-23T17:19:09.132491+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.1286] device (ttyCommModem): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:09.134160+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.1300] modem["ttyCommModem"]: using modem-specified IP timeout: 20 seconds
2024-08-23T17:19:09.136036+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.1310] ppp-manager: starting PPP connection
2024-08-23T17:19:09.148931+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.1483] ppp-manager: pppd started with pid 4971
2024-08-23T17:19:09.188853+09:00 armadillo pppd[4971]: Plugin /usr/lib/pppd/2.4.9/nm-pppd-plugin.so loaded.
2024-08-23T17:19:09.190413+09:00 armadillo NetworkManager[4971]: Plugin /usr/lib/pppd/2.4.9/nm-pppd-plugin.so loaded.
2024-08-23T17:19:09.191816+09:00 armadillo pppd[4971]: nm-ppp-plugin: initializing
2024-08-23T17:19:09.200372+09:00 armadillo pppd[4971]: pppd 2.4.9 started by root, uid 0
2024-08-23T17:19:09.201502+09:00 armadillo pppd[4971]: nm-ppp-plugin: status 3 / phase 'serial connection'
2024-08-23T17:19:09.216054+09:00 armadillo systemd-timesyncd[1338]: Network configuration changed, trying to establish connection.
2024-08-23T17:19:09.239278+09:00 armadillo pppd[4971]: Using interface ppp0
2024-08-23T17:19:09.240207+09:00 armadillo NetworkManager[4971]: Using interface ppp0
2024-08-23T17:19:09.240745+09:00 armadillo NetworkManager[4971]: Connect: ppp0 <--> /dev/ttyUSB4
2024-08-23T17:19:09.242378+09:00 armadillo pppd[4971]: nm-ppp-plugin: status 5 / phase 'establish'
2024-08-23T17:19:09.243579+09:00 armadillo pppd[4971]: Connect: ppp0 <--> /dev/ttyUSB4
2024-08-23T17:19:09.248791+09:00 armadillo pppd[4971]: nm-ppp-plugin: status 6 / phase 'authenticate'
2024-08-23T17:19:09.251996+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.2502] manager: (ppp0): new Ppp device (/org/freedesktop/NetworkManager/Devices/14)
2024-08-23T17:19:09.253553+09:00 armadillo pppd[4971]: nm-ppp-plugin: passwd-hook, requesting credentials...
2024-08-23T17:19:09.279630+09:00 armadillo pppd[4971]: nm-ppp-plugin: got credentials from NetworkManager
2024-08-23T17:19:09.284780+09:00 armadillo pppd[4971]: CHAP authentication succeeded
2024-08-23T17:19:09.285721+09:00 armadillo NetworkManager[4971]: CHAP authentication succeeded
2024-08-23T17:19:09.286317+09:00 armadillo NetworkManager[4971]: CHAP authentication succeeded
2024-08-23T17:19:09.287203+09:00 armadillo pppd[4971]: nm-ppp-plugin: status 8 / phase 'network'
2024-08-23T17:19:09.287923+09:00 armadillo pppd[4971]: CHAP authentication succeeded
2024-08-23T17:19:09.340932+09:00 armadillo systemd-timesyncd[1338]: Network configuration changed, trying to establish connection.
2024-08-23T17:19:09.616166+09:00 armadillo pppd[4971]: Could not determine remote IP address: defaulting to 10.64.64.64
2024-08-23T17:19:09.617085+09:00 armadillo NetworkManager[4971]: Could not determine remote IP address: defaulting to 10.64.64.64
2024-08-23T17:19:09.621848+09:00 armadillo systemd-timesyncd[1338]: Network configuration changed, trying to establish connection.
2024-08-23T17:19:09.626627+09:00 armadillo systemd-timesyncd[1338]: Network configuration changed, trying to establish connection.
2024-08-23T17:19:09.639789+09:00 armadillo systemd-timesyncd[1338]: Network configuration changed, trying to establish connection.
2024-08-23T17:19:09.647821+09:00 armadillo pppd[4971]: local  IP address 10.181.205.62
2024-08-23T17:19:09.648714+09:00 armadillo NetworkManager[4971]: local  IP address 10.181.205.62
2024-08-23T17:19:09.649213+09:00 armadillo NetworkManager[4971]: remote IP address 10.64.64.64
2024-08-23T17:19:09.649679+09:00 armadillo NetworkManager[4971]: primary   DNS address 126.211.198.40
2024-08-23T17:19:09.650122+09:00 armadillo NetworkManager[4971]: secondary DNS address 126.211.198.168
2024-08-23T17:19:09.650966+09:00 armadillo pppd[4971]: nm-ppp-plugin: status 9 / phase 'running'
2024-08-23T17:19:09.651644+09:00 armadillo pppd[4971]: remote IP address 10.64.64.64
2024-08-23T17:19:09.652312+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.6512] device (ppp0): state change: unmanaged -> unavailable (reason 'connection-assumed', sys-iface-state: 'external')
2024-08-23T17:19:09.653069+09:00 armadillo pppd[4971]: primary   DNS address 126.211.198.40
2024-08-23T17:19:09.653709+09:00 armadillo pppd[4971]: secondary DNS address 126.211.198.168
2024-08-23T17:19:09.671938+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.6563] device (ppp0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'external')
2024-08-23T17:19:09.681598+09:00 armadillo systemd-networkd[325]: ppp0: Link UP
2024-08-23T17:19:09.684678+09:00 armadillo systemd-networkd[325]: ppp0: Gained carrier
2024-08-23T17:19:09.686679+09:00 armadillo systemd-timesyncd[1338]: Network configuration changed, trying to establish connection.
2024-08-23T17:19:09.688918+09:00 armadillo pppd[4971]: nm-ppp-plugin: ip-up event
2024-08-23T17:19:09.692599+09:00 armadillo pppd[4971]: nm-ppp-plugin: sending IPv4 config to NetworkManager...
2024-08-23T17:19:09.695754+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.6833] ppp-manager: (IPv4 Config Get) reply received.
2024-08-23T17:19:09.703507+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.6893] device (ttyCommModem): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:09.706641+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.7032] policy: set 'gsm-ttyCommModem' (ppp0) as default for IPv4 routing and DNS
2024-08-23T17:19:09.730358+09:00 armadillo dnsmasq[2868]: reading /etc/resolv.conf
2024-08-23T17:19:09.734608+09:00 armadillo dnsmasq[2868]: using nameserver 126.211.198.40#53
2024-08-23T17:19:09.736466+09:00 armadillo dnsmasq[2868]: using nameserver 126.211.198.168#53
2024-08-23T17:19:09.777493+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.7669] device (ttyCommModem): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:09.779361+09:00 armadillo dbus-daemon[1743]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.8' (uid=0 pid=2564 comm="/usr/sbin/NetworkManager --no-daemon")
2024-08-23T17:19:09.816075+09:00 armadillo systemd[1]: Starting NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service...
2024-08-23T17:19:09.864142+09:00 armadillo dbus-daemon[1743]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
2024-08-23T17:19:09.865248+09:00 armadillo systemd[1]: Started NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service.
2024-08-23T17:19:09.876935+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.8758] device (ttyCommModem): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:09.877833+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.8772] device (ttyCommModem): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:19:09.879697+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.8791] manager: NetworkManager state is now CONNECTED_SITE
2024-08-23T17:19:09.881573+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.8810] device (ttyCommModem): Activation: successful, device activated.
2024-08-23T17:19:09.902466+09:00 armadillo NetworkManager[2564]: <info>  [1724401149.8982] manager: NetworkManager state is now CONNECTED_GLOBAL
2024-08-23T17:19:09.948458+09:00 armadillo /usr/bin/wwan-force-restart: end force restart ec25
2024-08-23T17:19:10.035409+09:00 armadillo exim[5000]: 2024-08-23 17:19:10 Start queue run: pid=5000 -qqf
2024-08-23T17:19:10.036471+09:00 armadillo exim[5000]: 2024-08-23 17:19:10 Cannot open main log file "/var/log/exim4/mainlog": Permission denied: euid=0 egid=113
2024-08-23T17:19:10.037379+09:00 armadillo exim[5000]: exim: could not open panic log - aborting: see message(s) above
2024-08-23T17:19:20.211070+09:00 armadillo systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
2024-08-23T17:19:39.387294+09:00 armadillo pppd[4971]: IPV6CP: timeout sending Config-Requests
2024-08-23T17:19:39.388414+09:00 armadillo NetworkManager[4971]: IPV6CP: timeout sending Config-Requests
2024-08-23T17:19:40.093312+09:00 armadillo systemd-timesyncd[1338]: Contacted time server 163.44.97.196:123 (0.debian.pool.ntp.org).

satoshi.sa.aoki

2024年8月23日 17時45分

すみません。
systemctl stop connection-recover.serviceでサービスを止めて再度確認したところ、connection-recoverサービスをstopしていても起きました。
syslogを添付します。何か原因わかりますか?

root@armadillo:~# tail -f /var/log/syslog
2024-08-23T17:33:26.107578+09:00 armadillo systemd[1]: systemd-hostnamed.service: Deactivated successfully.
2024-08-23T17:33:26.979950+09:00 armadillo pppd[6669]: IPV6CP: timeout sending Config-Requests
2024-08-23T17:33:26.980848+09:00 armadillo NetworkManager[6669]: IPV6CP: timeout sending Config-Requests
2024-08-23T17:34:01.607902+09:00 armadillo CRON[6832]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:35:01.741155+09:00 armadillo CRON[6879]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:36:01.874880+09:00 armadillo CRON[6925]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:36:53.935947+09:00 armadillo crontab[6966]: (root) BEGIN EDIT (root)
2024-08-23T17:37:02.004991+09:00 armadillo CRON[6976]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:37:51.577323+09:00 armadillo crontab[6966]: (root) END EDIT (root)
2024-08-23T17:38:01.138686+09:00 armadillo CRON[7022]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:39:01.277021+09:00 armadillo CRON[7079]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:39:02.510223+09:00 armadillo pppd[6669]: LCP terminated by peer
2024-08-23T17:39:02.511258+09:00 armadillo pppd[6669]: nm-ppp-plugin: status 8 / phase 'network'
2024-08-23T17:39:02.511909+09:00 armadillo NetworkManager[6669]: LCP terminated by peer
2024-08-23T17:39:02.512295+09:00 armadillo NetworkManager[6669]: Connect time 6.1 minutes.
2024-08-23T17:39:02.512695+09:00 armadillo NetworkManager[6669]: Sent 24541 bytes, received 24490 bytes.
2024-08-23T17:39:02.513258+09:00 armadillo pppd[6669]: Connect time 6.1 minutes.
2024-08-23T17:39:02.526876+09:00 armadillo pppd[6669]: Sent 24541 bytes, received 24490 bytes.
2024-08-23T17:39:02.535873+09:00 armadillo systemd-networkd[325]: ppp0: Link DOWN
2024-08-23T17:39:02.549964+09:00 armadillo systemd-networkd[325]: ppp0: Lost carrier
2024-08-23T17:39:02.552585+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.5304] device (ppp0): state change: disconnected -> unmanaged (reason 'connection-assumed', sys-iface-state: 'external')
2024-08-23T17:39:02.554820+09:00 armadillo pppd[6669]: nm-ppp-plugin: status 5 / phase 'establish'
2024-08-23T17:39:02.596561+09:00 armadillo pppd[6669]: Modem hangup
2024-08-23T17:39:02.606134+09:00 armadillo pppd[6669]: Connection terminated.
2024-08-23T17:39:02.607065+09:00 armadillo pppd[6669]: nm-ppp-plugin: status 11 / phase 'disconnect'
2024-08-23T17:39:02.609167+09:00 armadillo NetworkManager[6669]: Modem hangup
2024-08-23T17:39:02.612072+09:00 armadillo NetworkManager[6669]: Connection terminated.
2024-08-23T17:39:02.624723+09:00 armadillo ModemManager[6318]: <info>  [modem0] mobile equipment forced PS detach: all contexts have been deactivated
2024-08-23T17:39:02.628931+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.6060] device (ttyCommModem): state change: activated -> failed (reason 'ppp-disconnect', sys-iface-state: 'managed')
2024-08-23T17:39:02.634749+09:00 armadillo ModemManager[6318]: <info>  [modem0/bearer0] explicitly disconnected
2024-08-23T17:39:02.640266+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.6082] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:39:02.642206+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (home -> registering)
2024-08-23T17:39:02.650652+09:00 armadillo NetworkManager[6579]: <warn>  [1724402342.6118] device (ttyCommModem): Activation: failed for connection 'gsm-ttyCommModem'
2024-08-23T17:39:02.665447+09:00 armadillo dbus-daemon[1743]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.97' (uid=0 pid=6579 comm="/usr/sbin/NetworkManager --no-daemon")
2024-08-23T17:39:02.681022+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.6526] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:39:02.682585+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:39:02.697162+09:00 armadillo dnsmasq[2868]: no servers found in /etc/resolv.conf, will retry
2024-08-23T17:39:02.699106+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (connected -> disconnecting)
2024-08-23T17:39:02.738827+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.7382] policy: auto-activating connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:39:02.746115+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.7456] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:39:02.748059+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.7462] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:39:02.752946+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.7511] manager: NetworkManager state is now CONNECTING
2024-08-23T17:39:02.756626+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.7547] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:39:02.775299+09:00 armadillo NetworkManager[6579]: <info>  [1724402342.7743] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:39:02.784824+09:00 armadillo pppd[6669]: nm-ppp-plugin: status 1 / phase 'dead'
2024-08-23T17:39:02.785959+09:00 armadillo pppd[6669]: nm-ppp-plugin: cleaning up
2024-08-23T17:39:02.786648+09:00 armadillo pppd[6669]: Exit.
2024-08-23T17:39:02.804980+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:39:02.805741+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (4/10): wait to get fully enabled
2024-08-23T17:39:02.815086+09:00 armadillo systemd[1]: Starting NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service...
2024-08-23T17:39:02.879927+09:00 armadillo dbus-daemon[1743]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
2024-08-23T17:39:02.880681+09:00 armadillo systemd[1]: Started NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service.
2024-08-23T17:39:03.742510+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (disconnecting -> registered)
2024-08-23T17:39:03.743335+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (5/10): wait after enabled
2024-08-23T17:39:03.746575+09:00 armadillo ModemManager[6318]: <info>  [modem0/bearer0] connection #1 finished: duration 369s
2024-08-23T17:39:03.843076+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:39:03.843860+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:39:13.193138+09:00 armadillo systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
2024-08-23T17:39:14.162685+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:39:14.163801+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:39:14.164850+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:39:24.155708+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:39:24.156650+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:39:24.157349+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:39:34.151846+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:39:34.152951+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:39:34.153777+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:39:44.137722+09:00 armadillo NetworkManager[6579]: <warn>  [1724402384.1361] modem-broadband[ttyCommModem]: failed to connect modem: Too much time waiting to get to a final packet service state
2024-08-23T17:39:44.138741+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1363] device (ttyCommModem): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
2024-08-23T17:39:44.139550+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1382] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:39:44.143194+09:00 armadillo NetworkManager[6579]: <warn>  [1724402384.1401] device (ttyCommModem): Activation: failed for connection 'gsm-ttyCommModem'
2024-08-23T17:39:44.149676+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1461] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:39:44.155463+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1533] policy: auto-activating connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:39:44.162299+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1607] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:39:44.163640+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1621] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:39:44.171910+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1714] manager: NetworkManager state is now CONNECTING
2024-08-23T17:39:44.175988+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1754] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:39:44.186664+09:00 armadillo NetworkManager[6579]: <info>  [1724402384.1861] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:39:44.206819+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:39:44.207596+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:39:44.208308+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:39:54.162340+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:39:54.163235+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:39:54.164041+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:39:59.358435+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (home -> searching)
2024-08-23T17:39:59.359337+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> searching)
2024-08-23T17:40:01.410828+09:00 armadillo CRON[7241]: (root) CMD (for i in `seq 0 5 59`;do (sleep ${i}; bash netstat.sh) & done;)
2024-08-23T17:40:04.156881+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:40:04.157856+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (4/10): wait to get fully enabled
2024-08-23T17:40:04.158470+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (5/10): wait after enabled
2024-08-23T17:40:04.256698+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:40:04.318935+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (searching -> registered)
2024-08-23T17:40:04.321781+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (searching -> registering)
2024-08-23T17:40:04.323462+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:40:04.369116+09:00 armadillo ModemManager[6318]: <warn>  [modem0] couldn't load operator code: Couldn't match response
2024-08-23T17:40:04.397403+09:00 armadillo ModemManager[6318]: <warn>  [modem0] couldn't load operator name: Couldn't match response
2024-08-23T17:40:04.399013+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:40:04.400443+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:40:04.404433+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:40:04.406976+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:40:08.423386+09:00 armadillo ModemManager[6318]: <warn>  [modem0/bearer1] (quectel-ec25) Couldn't Activate PDP context: 'Unknown error'
2024-08-23T17:40:08.426142+09:00 armadillo ModemManager[6318]: <warn>  [modem0/bearer1] connection attempt #1 failed: Unknown error
2024-08-23T17:40:08.427014+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:40:08.428245+09:00 armadillo ModemManager[6318]: <info>  [modem0/bearer1] connection #1 finished: duration 0s
2024-08-23T17:40:08.445111+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:40:08.446292+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:40:08.447380+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:40:08.449412+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:40:08.450563+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:40:08.452828+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:40:08.862584+09:00 armadillo ModemManager[6318]: <info>  [modem0] mobile equipment forced PS detach: all contexts have been deactivated
2024-08-23T17:40:08.865231+09:00 armadillo ModemManager[6318]: <info>  [modem0/bearer2] explicitly disconnected
2024-08-23T17:40:08.867167+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:40:08.868306+09:00 armadillo ModemManager[6318]: <info>  [modem0/bearer2] connection #1 finished: duration 0s
2024-08-23T17:40:08.870587+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (home -> idle)
2024-08-23T17:40:08.872701+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> enabled)
2024-08-23T17:40:12.346065+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (idle -> searching)
2024-08-23T17:40:12.349178+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (enabled -> searching)
2024-08-23T17:40:36.631954+09:00 armadillo ModemManager[6318]: <warn>  [modem0/bearer2] connection attempt #1 failed: Couldn't match response
2024-08-23T17:40:36.637106+09:00 armadillo NetworkManager[6579]: <warn>  [1724402436.6346] modem-broadband[ttyCommModem]: failed to connect modem: Too much time waiting to get to a final packet service state
2024-08-23T17:40:36.640422+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6347] device (ttyCommModem): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
2024-08-23T17:40:36.644745+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6366] manager: NetworkManager state is now DISCONNECTED
2024-08-23T17:40:36.649539+09:00 armadillo NetworkManager[6579]: <warn>  [1724402436.6409] device (ttyCommModem): Activation: failed for connection 'gsm-ttyCommModem'
2024-08-23T17:40:36.652358+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6512] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:40:36.654697+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6535] policy: auto-activating connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:40:36.660634+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6565] device (ttyCommModem): Activation: starting connection 'gsm-ttyCommModem' (628d359b-fb75-43c8-bd87-d1c41c26329a)
2024-08-23T17:40:36.663641+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6571] device (ttyCommModem): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:40:36.669990+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6590] manager: NetworkManager state is now CONNECTING
2024-08-23T17:40:36.682413+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6606] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:40:36.686540+09:00 armadillo NetworkManager[6579]: <info>  [1724402436.6809] device (ttyCommModem): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
2024-08-23T17:40:36.703770+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:40:36.705349+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (4/10): wait to get fully enabled
2024-08-23T17:40:36.706492+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (5/10): wait after enabled
2024-08-23T17:40:36.804893+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:40:36.871792+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (searching -> registered)
2024-08-23T17:40:36.875597+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (searching -> registering)
2024-08-23T17:40:36.876369+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:40:36.918703+09:00 armadillo ModemManager[6318]: <warn>  [modem0] couldn't load operator code: Couldn't match response
2024-08-23T17:40:36.945134+09:00 armadillo ModemManager[6318]: <warn>  [modem0] couldn't load operator name: Couldn't match response
2024-08-23T17:40:36.945894+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:40:36.946560+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:40:36.947293+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:40:36.947948+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:40:36.951370+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:40:37.451338+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (home -> idle)
2024-08-23T17:40:37.452772+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> enabled)
2024-08-23T17:40:40.897854+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (idle -> registering)
2024-08-23T17:40:41.032529+09:00 armadillo ModemManager[6318]: <info>  [modem0] 3GPP registration state changed (registering -> home)
2024-08-23T17:40:41.033412+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (enabled -> registered)
2024-08-23T17:40:41.092012+09:00 armadillo ModemManager[6318]: <warn>  [modem0/bearer0] (quectel-ec25) Couldn't Activate PDP context: 'Unknown error'
2024-08-23T17:40:41.093218+09:00 armadillo ModemManager[6318]: <warn>  [modem0/bearer0] connection attempt #2 failed: Operation was cancelled
2024-08-23T17:40:41.094731+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> disconnecting)
2024-08-23T17:40:41.101720+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (disconnecting -> registered)
2024-08-23T17:40:41.103817+09:00 armadillo ModemManager[6318]: <info>  [modem0/bearer0] connection #2 finished: duration 0s
2024-08-23T17:40:41.119126+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:40:41.120499+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:40:41.121953+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:40:41.123130+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:40:41.124260+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:40:41.125757+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> connecting)
2024-08-23T17:40:41.222064+09:00 armadillo ModemManager[6318]: <warn>  [modem0/bearer1] (quectel-ec25) Couldn't Activate PDP context: 'Unknown error'
2024-08-23T17:40:41.223484+09:00 armadillo ModemManager[6318]: <warn>  [modem0/bearer1] connection attempt #2 failed: Unknown error
2024-08-23T17:40:41.225012+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (connecting -> registered)
2024-08-23T17:40:41.228436+09:00 armadillo ModemManager[6318]: <info>  [modem0/bearer1] connection #2 finished: duration 0s
2024-08-23T17:40:41.244255+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect started...
2024-08-23T17:40:41.245523+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (6/10): register
2024-08-23T17:40:41.250384+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (7/10): wait to get packet service state attached
2024-08-23T17:40:41.251401+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (8/10): bearer
2024-08-23T17:40:41.252203+09:00 armadillo ModemManager[6318]: <info>  [modem0] simple connect state (9/10): connect
2024-08-23T17:40:41.253022+09:00 armadillo ModemManager[6318]: <info>  [modem0] state changed (registered -> connecting)

at_dominique.m…

2024年8月23日 18時01分

マルティネです。

> 信号強度は、通信できているときには100%、通信できていないときには、60%になってから、0%になります。

確認ありがとうございます。そういう問題ではなさそうですね。

> 再度connection-recoverを起動している状態の接続・切断のsyslogを取ってみたのですが何か原因おわかりになりますか?

原因が書いてなさそうですね:

2024-08-23T17:09:57.260385+09:00 armadillo pppd[3168]: IPV6CP: timeout sending Config-Requests
2024-08-23T17:15:12.529209+09:00 armadillo pppd[3168]: LCP terminated by peer

「LCP terminated by peer」ということは向こう側が切断したということですので、何か原因があると思いますがこのログだけでは分かりません。

また試していただく形ですみませんが、いくつか確認していただければ助かります:

1/ connection-recover が動いてない状態で切断していないということですので、connection-recover が停止している状態で10分以上待った後に「logger -t connection-test ping; ping -s 1 -c 2 -w 10 -I ppp0 8.8.8.8」 を何回か実行してみて、切断されるかどうか、切断された場合に syslog の 「connection-test: ping」の行と切断の時間を確認したいです。
この二つ目のテストは複数の確認を重ねて:connection-recover がない状態で切断しないこと、切断の原因がやはり ping であるかどうか、ping でしたらどれぐらいの時間で反応するか。

2/ ログの時間で考えると関係ないと思いますが、ipv6 の接続ができてなさそうですので「nmcli con mod gsm-ttyCommModem ipv6.method ignore」で ipv6 を無効化してみて再び「nmcli con up gsm-ttyCommModem」で再接続してみてください。
(ps aux | grep ppp で「noipv6」が出力されるはずです)

よろしくお願いします。

at_dominique.m…

2024年8月23日 18時08分

すみませんまた返事を全て把握しないで返事してしまった。

connection-recover なしで際限するということで、 ipv6 の無効化だけ(2/)を試していただければと思います。

月曜日にまた何か聞くかもしれませんが、ひとまずそれでお願いします。

よろしくお願いします。

satoshi.sa.aoki

2024年8月25日 11時29分

迅速なサポートありがとうございます。

ipv6の件、'nmcli con mod gsm-ttyCommModem ipv6.method ignore'を実行して長時間動かして試しています。

2024-08-23T21:06:00.754394+09:00 armadillo NetworkManager[6579]: <info>  [1724411
4760.7494] audit: op="connection-update" uuid="628d359b-fb75-43c8-bd87-d1c41c2633
29a" name="gsm-ttyCommModem" args="ipv6.method,connection.timestamp" pid=17129 uu
id=0 result="success"

上記の設定反映後は、安定しているようにみえています。ipv6の設定が接続に関係していそうでしょうか?

root@armadillo:/var/log# grep "Modem hangup" syslog syslog.1
syslog.1:2024-08-23T14:06:57.625061+09:00 armadillo pppd[3328]: Modem hangup
syslog.1:2024-08-23T14:06:57.625921+09:00 armadillo NetworkManager[3328]: Modem hangup
syslog.1:2024-08-23T14:17:01.746703+09:00 armadillo NetworkManager[4652]: Modem hangup
syslog.1:2024-08-23T14:17:01.747814+09:00 armadillo pppd[4652]: Modem hangup
syslog.1:2024-08-23T15:15:59.745688+09:00 armadillo pppd[14508]: Modem hangup
syslog.1:2024-08-23T15:15:59.773792+09:00 armadillo NetworkManager[14508]: Modem hangup
syslog.1:2024-08-23T15:37:36.919420+09:00 armadillo pppd[17758]: Modem hangup
syslog.1:2024-08-23T15:37:36.920368+09:00 armadillo NetworkManager[17758]: Modem hangup
syslog.1:2024-08-23T15:49:54.927051+09:00 armadillo pppd[19229]: Modem hangup
syslog.1:2024-08-23T15:49:54.928822+09:00 armadillo NetworkManager[19229]: Modem hangup
syslog.1:2024-08-23T17:15:12.572055+09:00 armadillo pppd[3168]: Modem hangup
syslog.1:2024-08-23T17:15:12.573805+09:00 armadillo NetworkManager[3168]: Modem hangup
syslog.1:2024-08-23T17:25:17.768981+09:00 armadillo pppd[4971]: Modem hangup
syslog.1:2024-08-23T17:25:17.790797+09:00 armadillo NetworkManager[4971]: Modem hangup
syslog.1:2024-08-23T17:39:02.596561+09:00 armadillo pppd[6669]: Modem hangup
syslog.1:2024-08-23T17:39:02.609167+09:00 armadillo NetworkManager[6669]: Modem hangup
grep: syslog.1: binary file matches
 
root@armadillo:/var/log# grep "LCP terminated by peer" syslog syslog.1
syslog.1:2024-08-23T14:06:57.527312+09:00 armadillo pppd[3328]: LCP terminated by peer
syslog.1:2024-08-23T14:06:57.534859+09:00 armadillo NetworkManager[3328]: LCP terminated by peer
syslog.1:2024-08-23T14:17:01.685085+09:00 armadillo pppd[4652]: LCP terminated by peer
syslog.1:2024-08-23T14:17:01.696804+09:00 armadillo NetworkManager[4652]: LCP terminated by peer
syslog.1:2024-08-23T15:15:59.685871+09:00 armadillo pppd[14508]: LCP terminated by peer
syslog.1:2024-08-23T15:15:59.688048+09:00 armadillo NetworkManager[14508]: LCP terminated by peer
syslog.1:2024-08-23T15:37:36.875624+09:00 armadillo pppd[17758]: LCP terminated by peer
syslog.1:2024-08-23T15:37:36.876970+09:00 armadillo NetworkManager[17758]: LCP terminated by peer
syslog.1:2024-08-23T15:49:54.849032+09:00 armadillo pppd[19229]: LCP terminated by peer
syslog.1:2024-08-23T15:49:54.850308+09:00 armadillo NetworkManager[19229]: LCP terminated by peer
syslog.1:2024-08-23T17:15:12.529209+09:00 armadillo pppd[3168]: LCP terminated by peer
syslog.1:2024-08-23T17:15:12.531080+09:00 armadillo NetworkManager[3168]: LCP terminated by peer
syslog.1:2024-08-23T17:25:17.702673+09:00 armadillo pppd[4971]: LCP terminated by peer
syslog.1:2024-08-23T17:25:17.712091+09:00 armadillo NetworkManager[4971]: LCP terminated by peer
syslog.1:2024-08-23T17:39:02.510223+09:00 armadillo pppd[6669]: LCP terminated by peer
syslog.1:2024-08-23T17:39:02.511909+09:00 armadillo NetworkManager[6669]: LCP terminated by peer
grep: syslog.1: binary file matches
 
root@armadillo:/var/log# grep "ppp0: Link DOWN" syslog syslog.1
syslog.1:2024-08-23T14:06:57.539304+09:00 armadillo systemd-networkd[324]: ppp0: Link DOWN
syslog.1:2024-08-23T14:17:01.700808+09:00 armadillo systemd-networkd[324]: ppp0: Link DOWN
syslog.1:2024-08-23T15:15:59.696434+09:00 armadillo systemd-networkd[324]: ppp0: Link DOWN
syslog.1:2024-08-23T15:37:36.885671+09:00 armadillo systemd-networkd[324]: ppp0: Link DOWN
syslog.1:2024-08-23T15:49:54.878923+09:00 armadillo systemd-networkd[324]: ppp0: Link DOWN
syslog.1:2024-08-23T17:15:12.540234+09:00 armadillo systemd-networkd[325]: ppp0: Link DOWN
syslog.1:2024-08-23T17:25:17.717068+09:00 armadillo systemd-networkd[325]: ppp0: Link DOWN
syslog.1:2024-08-23T17:39:02.535873+09:00 armadillo systemd-networkd[325]: ppp0: Link DOWN
syslog.1:2024-08-23T21:06:13.404228+09:00 armadillo systemd-networkd[325]: ppp0: Link DOWN

at_mitsuhiro.yoshida

2024年8月26日 14時43分

吉田です。

> 上記の設定反映後は、安定しているようにみえています。ipv6の設定が接続に関係していそうでしょうか?

「IPV4 と IPV6」 または 「IPV6 のみ」で接続しようとしなくなりますので、
IPV6 を使用しない環境であれば接続が安定する可能性はあります。