Armadilloフォーラム

Armadillo-IoT A6E でLTE通信の再接続のログの見方について

na_rumi

2024年5月24日 10時36分

Armadillo-Iot A6E Cat.M1モデル でLTE再接続の動作を確認しています。
connection-recover.conf はデフォルトの状態で、
connection-recoverを5/23 19:40にスタートさせました。
5/24 9:00に /var/log/messages を ”connection-recover” の文字列で確認したところ、
4回「connection-recover: ttyCommModem ping fail」の文字列が確認できました。

このログは、「120秒周期の監視で10回のping導通に失敗し、モデムの再起動を4回した」ということを表しているのでしょうか?
また、120秒周期の監視ping導通が正常だった場合は、ログにはなにも出力されないという認識でよろしいでしょうか?

May 23 20:56:52 armadillo user.notice connection-recover: ttyCommModem ping fail
May 23 20:56:52 armadillo user.notice connection-recover: ttyCommModem reconnect start...
May 23 20:57:00 armadillo user.notice connection-recover: ttyCommModem reconnect success
May 24 01:43:29 armadillo user.notice connection-recover: ttyCommModem ping fail
May 24 01:43:29 armadillo user.notice connection-recover: ttyCommModem reconnect start...
May 24 01:43:37 armadillo user.notice connection-recover: ttyCommModem reconnect success
May 24 05:10:51 armadillo user.notice connection-recover: ttyCommModem ping fail
May 24 05:10:51 armadillo user.notice connection-recover: ttyCommModem reconnect start...
May 24 05:11:00 armadillo user.notice connection-recover: ttyCommModem reconnect success
May 24 08:40:19 armadillo user.notice connection-recover: ttyCommModem ping fail
May 24 08:40:19 armadillo user.notice connection-recover: ttyCommModem reconnect start...
May 24 08:40:27 armadillo user.notice connection-recover: ttyCommModem reconnect success

■LTE再接続サービスの状態

armadillo:/var/log# rc-status | grep connection-recover
 connection-recover                                                [  started  ]
armadillo:/var/log#

■connection-recover.conf

#!/bin/sh
# SPDX-License-Identifier: MIT
 
CHECK_INTERVAL_SEC=120
PING_DEST_IP=8.8.8.8
FORCE_REBOOT=FALSE
REBOOT_IF_SIM_NOT_FOUND=FALSE
WWAN_FORCE_RESTART_COUNT=10

以下のトピックを参考にCat.M1 モデル連続動作の運用のため、
製品マニュアル「LTE モデム EMS31-J 省電力などの設定 (Cat.M1 モデル)」
https://manual.atmark-techno.com/armadillo-iot-a6e/armadillo-iotg-a6e_p
の suspend、psm、edrx の設定を disable にするという設定を行っています。
https://armadillo.atmark-techno.com/forum/armadillo/18701

ファイル ファイルの説明
messages_20240523-20240524.txt 20240523-20240524 /var/log/message
コメント

at_mitsuhiro.yoshida

2024年5月24日 14時30分

吉田です。

May 23 20:56:52 armadillo user.notice connection-recover: ttyCommModem ping fail
May 23 20:56:52 armadillo user.notice connection-recover: ttyCommModem reconnect start... 
May 23 20:57:00 armadillo user.notice connection-recover: ttyCommModem reconnect success

これは、ping 導通確認に失敗し LTE の再接続を実施したログです。
Network Manager の nmcli connection down → up により接続が復旧しております。

LTE モジュールを再起動させた場合、ログに wwan-force-restart の文字列が含まれます。

> また、120秒周期の監視ping導通が正常だった場合は、ログにはなにも出力されないという認識でよろしいでしょうか?

はい、何も出力しません。

こちらのフォーラムを見て、
再度BaseOsのバージョンを3.19.2-at.5に上げてLTE再接続サービスの動作確認をしています。
https://armadillo.atmark-techno.com/forum/armadillo/18701

REBOOT_IF_SIM_NOT_FOUND=TRUEに設定しているのですが、
Armadilloの再起動が実行されません。ほかに何か必要な設定はありますでしょうか。

設定ファイルは以下の設定にしています。

#!/bin/sh
# SPDX-License-Identifier: MIT
 
CHECK_INTERVAL_SEC=60
PING_DEST_IP=8.8.8.8
FORCE_REBOOT=TRUE
REBOOT_IF_SIM_NOT_FOUND=FALSE
WWAN_FORCE_RESTART_COUNT=5

connection-recover.logは以下になります。

Jul 02 20:07:05 armadillo connection-recover[10369]: start.
Jul 02 20:08:05 armadillo connection-recover[10369]: connection status: disconnected
Jul 02 20:08:05 armadillo connection-recover[10369]: ttyCommModem reconnect start...
Jul 02 20:09:31 armadillo connection-recover[10369]: ttyCommModem reconnect fail: 4
Jul 02 20:10:32 armadillo connection-recover[10369]: connection status: disconnected
Jul 02 20:10:32 armadillo connection-recover[10369]: ttyCommModem reconnect start...
Jul 02 20:11:58 armadillo connection-recover[10369]: ttyCommModem reconnect fail: 4
Jul 02 20:11:58 armadillo connection-recover[10369]: exec wwan-restart
Jul 02 20:11:58 armadillo wwan-force-restart[10921]: goto airplane mode: ems31
Jul 02 20:11:59 armadillo wwan-force-restart[10921]: sleep 10 seconds
Jul 02 20:12:09 armadillo wwan-force-restart[10921]:  wakeup from airplane mode: ems31
Jul 02 20:14:31 armadillo connection-recover[10369]: connection status: connecting
Jul 02 20:15:31 armadillo connection-recover[10369]: connection status: connecting
Jul 02 20:16:32 armadillo connection-recover[10369]: connection status: connecting
Jul 02 20:16:32 armadillo connection-recover[10369]: exec wwan-force-restart cause device ttyCommModem connecting
Jul 02 20:16:32 armadillo wwan-force-restart[11370]: start force restart ems31
Jul 02 20:18:24 armadillo wwan-force-restart[11370]: end force restart ems31
Jul 02 20:19:25 armadillo connection-recover[10369]: connection status: connecting
Jul 02 20:20:26 armadillo connection-recover[10369]: connection status: connecting
Jul 02 20:21:26 armadillo connection-recover[10369]: connection status: connecting
Jul 02 20:21:26 armadillo connection-recover[10369]: exec wwan-force-restart cause device ttyCommModem connecting
Jul 02 20:21:26 armadillo wwan-force-restart[12066]: start force restart ems31
Jul 02 20:23:19 armadillo wwan-force-restart[12066]: end force restart ems31
Jul 02 20:24:20 armadillo connection-recover[10369]: connection status: connecting
Jul 02 20:25:20 armadillo connection-recover[10369]: connection status: connecting

at_mitsuhiro.yoshida

2024年7月3日 7時49分

吉田です。

SIM Not Found の状態になっていないので Armadillo の再起動は実施されません。
connection status が unavailable になった場合に SIM Not Found と判定しております。

conneting 状態が 4 分程度継続すると自動的に LTE モジュールの再起動を実施します。

すみません。記載を誤りました。
TRUEにしているのは、FORCE_REBOOTです。

FORCE_REBOOT=TRUE

動作確認の状況としては、Armadilloからアンテナを外し、
電波遮断袋に入れて動作確認をしています。
上記の状態で、シリアル接続したArmadilloのターミナル上で、
8.8.8.8 にPINGを打ち、PINGが通らないことは確認しています

期待値としては、PING導通に失敗した場合に、Armadilloが再起動することです。
PING導通失敗でArmadilloの再起動を確認するためには、
以下のファイルの FORCE_REBOOT を TRUE にする以外に実施することはありますでしょうか。

#!/bin/sh
# SPDX-License-Identifier: MIT
 
CHECK_INTERVAL_SEC=60
PING_DEST_IP=8.8.8.8
FORCE_REBOOT=TRUE
REBOOT_IF_SIM_NOT_FOUND=FALSE
WWAN_FORCE_RESTART_COUNT=5

at_mitsuhiro.yoshida

2024年7月4日 16時39分

吉田です。

わかりにくく申し訳ありません。

FORCE_REBOOT は LTE 接続中で ping 導通が NG の場合に Armadillo を再起動してLTE 接続の回復をはかるオプションで、
ログが示す LTE 接続中の場合は、LTE モジュールのみの再起動を実施する動作となっております。

接続中状態で Armadillo を再起動すると Armadillo の再起動が多発する可能性があり、
そのようにはしておりません。

connecting の状態が更に長く続くようであれば Armadillo を再起動する様にするなど
対応を検討いたします。

よろしくお願いします。

> FORCE_REBOOT は LTE 接続中で ping 導通が NG の場合に Armadillo を再起動してLTE 接続の回復をはかるオプションで、
> ログが示す LTE 接続中の場合は、LTE モジュールのみの再起動を実施する動作となっております。
すみません。Armadilloが再起動される場合の、LTE接続中の状態と、
上記のログが示すLTEの接続中の状態の違いがよくわかりません。

PING導通のNGでArmadilloが再起動される状態は、アンテナを外したり、電波遮断袋に入れたりせずに、
何らかの要因でPING導通がNGとなる、かなりレアケースの状態という認識でよろしいでしょうか?

机上で再現することは難しいという認識でよろしいでしょうか?

at_mitsuhiro.yoshida

2024年7月5日 10時59分

吉田です。

説明がわかりにくかったので再度記載します。
FORCE_REBOOT が効くのは、LTE が接続済み(connected) 状態で ping 導通が NG のケースとなります。
LTE が接続中(connecting) が継続する場合は、LTE モジュールのみの再起動を実施しております。

LTE が接続済み(connected)の状態で電波遮断袋に入れると比較的再現させやすいです。
また、プロバイダーによっては接続後一定時間経過すると一旦切断することがあるのでそれでも発生します。

詳細な説明ありがとうございます。
LTE が接続中(connecting)の状態で電波遮断袋に入れて試していたので、再起動が実現しなかったことがわかりました。
LTE が接続済み(connected)の状態で電波遮断袋に入れて試してみます。

何度もすみません。
LTE が接続済み(connected)の状態でPING導通に失敗しても、Armadilloの再起動が実現しなかったので再度確認させて下さい。
2回試しています。

■1回目:
設定:LTE再接続サービスの設定は以下のようにCHECK_INTERVAL_SECを60秒、WWAN_FORCE_RESTART_COUNTを1回にしました。
結果:connection-recover.log に ttyCommModem ping fail の出力がされましたが、Armadilloの再起動はされませんでした。
1回目のLTE再接続サービスの設定ファイル

#!/bin/sh
# SPDX-License-Identifier: MIT
 
CHECK_INTERVAL_SEC=60
PING_DEST_IP=8.8.8.8
FORCE_REBOOT=TRUE
REBOOT_IF_SIM_NOT_FOUND=FALSE
WWAN_FORCE_RESTART_COUNT=1

1回目のconnection-recover.log

Jul 09 17:47:42 armadillo connection-recover[1207]: connection status: connected
Jul 09 17:48:44 armadillo connection-recover[1207]: connection status: connected
Jul 09 17:49:46 armadillo connection-recover[1207]: connection status: connected
Jul 09 17:50:48 armadillo connection-recover[1207]: connection status: connected
Jul 09 17:51:49 armadillo connection-recover[1207]: connection status: connected
Jul 09 17:52:51 armadillo connection-recover[1207]: connection status: connected
Jul 09 17:53:02 armadillo connection-recover[1207]: ttyCommModem ping fail
Jul 09 17:53:02 armadillo connection-recover[1207]: ttyCommModem reconnect start...
Jul 09 17:53:27 armadillo connection-recover[1207]: ttyCommModem reconnect success

■2回目:
設定:LTE再接続サービスの設定は以下のようにCHECK_INTERVAL_SECを10秒、WWAN_FORCE_RESTART_COUNTを3回にしました。
結果:connection-recover.log に ttyCommModem ping fail の出力が3回されましたが、Armadilloの再起動はされませんでした。
2回目のLTE再接続サービスの設定ファイル

#!/bin/sh
# SPDX-License-Identifier: MIT
 
CHECK_INTERVAL_SEC=10
PING_DEST_IP=8.8.8.8
FORCE_REBOOT=TRUE
REBOOT_IF_SIM_NOT_FOUND=FALSE
WWAN_FORCE_RESTART_COUNT=3

2回目のconnection-recover.log

Jul 09 18:04:02 armadillo connection-recover[5446]: start.
Jul 09 18:04:13 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:04:24 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:04:37 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:04:49 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:05:01 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:05:15 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:05:36 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:05:48 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:06:00 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:06:12 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:06:24 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:06:35 armadillo connection-recover[5446]: ttyCommModem ping fail
Jul 09 18:06:35 armadillo connection-recover[5446]: ttyCommModem reconnect start...
Jul 09 18:06:44 armadillo connection-recover[5446]: ttyCommModem reconnect success
Jul 09 18:06:55 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:07:06 armadillo connection-recover[5446]: ttyCommModem ping fail
Jul 09 18:07:06 armadillo connection-recover[5446]: exec wwan-restart
Jul 09 18:07:08 armadillo wwan-force-restart[6030]: goto airplane mode: ems31
Jul 09 18:07:08 armadillo wwan-force-restart[6030]: sleep 10 seconds
Jul 09 18:07:18 armadillo wwan-force-restart[6030]:  wakeup from airplane mode: ems31
Jul 09 18:07:32 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:07:43 armadillo connection-recover[5446]: ttyCommModem ping fail
Jul 09 18:07:43 armadillo connection-recover[5446]: exec wwan-restart
Jul 09 18:07:45 armadillo wwan-force-restart[6223]: goto airplane mode: ems31
Jul 09 18:07:46 armadillo wwan-force-restart[6223]: sleep 10 seconds
Jul 09 18:07:56 armadillo wwan-force-restart[6223]:  wakeup from airplane mode: ems31
Jul 09 18:09:22 armadillo connection-recover[5446]: connection status: connecting
Jul 09 18:09:32 armadillo connection-recover[5446]: connection status: connecting
Jul 09 18:09:43 armadillo connection-recover[5446]: connection status: connecting
Jul 09 18:09:43 armadillo connection-recover[5446]: exec wwan-force-restart cause device ttyCommModem connecting
Jul 09 18:09:43 armadillo wwan-force-restart[6507]: start force restart ems31
Jul 09 18:11:22 armadillo wwan-force-restart[6507]: end force restart ems31
Jul 09 18:11:33 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:11:45 armadillo connection-recover[5446]: connection status: connected
Jul 09 18:11:56 armadillo connection-recover[5446]: connection status: connected

1回目のCHECK_INTERVAL_SECを60秒、WWAN_FORCE_RESTART_COUNTを1回でArmadilloの再起動がされなかったのはなぜでしょうか。
また、以下のマニュアルで
「WWAN_FORCE_RESTART_COUNT が初期値の 10 である場合、1 から 9 回目は電波のオン・オフを実施し、10 回目はLTE モジュールの電源オン・オフを実施します。それ以降も NG が続く場合、同じく 10 回に一度 LTE モジュールの電源オン・オフを実施します。」
という記載がありますが、ここで、FORCE_REBOOT=TRUE に設定している場合は、10回目でArmadilloの再起動が行われるのでしょうか。
WWAN_FORCE_RESTART_COUNTとFORCE_REBOOTの関連性がわかりませんでした。
6.14.5.11. LTE再接続サービス
https://manual.atmark-techno.com/armadillo-iot-a6e/armadillo-iotg-a6e_p…

at_mitsuhiro.yoshida

2024年7月10日 16時08分

吉田です。

この辺り説明が不足しており申し訳ありません。
FORCE_REBOOT=TRUE だと PING 導通の確認が 4 回連続で失敗すると Armadillo が再起動します。
/etc/atmark/connection-recover.conf の
PING_DEST_IP を実在しない IP アドレスに変更しても出しやすいです。

WWAN_FORCE_RESTART_COUNT との関連はありません。

回答ありがとうございます。
FORCE_REBOOT と WWAN_FORCE_RESTART_COUNT に関連がないことを理解しました。

4回連続でPINGの導通確認に失敗するとArmadilloが再起動ということでしたが、
connection-recover.log に以下のログが出力されれば1回というカウントでよろしいでしょうか?

Jul 10 13:42:07 armadillo connection-recover[1201]: ttyCommModem ping fail

at_mitsuhiro.yoshida

2024年7月16日 12時45分

吉田です。

はい、ご記載のとおりです。

> 4回連続でPINGの導通確認に失敗するとArmadilloが再起動ということでしたが、
> connection-recover.log に以下のログが出力されれば1回というカウントでよろしいでしょうか?
>

> Jul 10 13:42:07 armadillo connection-recover[1201]: ttyCommModem ping fail
> 

回答ありがとうございます。

追加で1点質問があります。

① BaseOSのバージョン 3.19.2-at.5 にあげて LTE再接続サービスを有効にすると、connection-recover.log が出力されるようになりますが、
BaseOSのバージョンを 3.19.2-at.5 にあげてしまうと 以前のように messagesにエラーの場合だけ出力される仕様は、
オプションなどでも選べないという認識でよろしいでしょうか?

現在デフォルトの120秒周期でLTE再接続サービスを利用しようと思っています。
LTE通信が正常の場合は、120秒に1回の間隔で以下のログが出力されると思います。
/var/log/connection-recover.log 出力のために eMMC に頻回アクセスした場合にどんな影響があるか確認したいです。

connection status: connected

お世話になります。

弊社の現場環境で、LTE通信の不具合が発生したときには、
「"connecting"のまま復旧しない」+「wwanのLEDが消灯状態」、という2つの事象が発生していました。

発生時のシステムログを添付します。

Jul  7 10:21:07 armadillo daemon.info NetworkManager[1029]: <info>  [1720315267.9049] device (ttyCommModem): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')

で、"connecting"から復帰しない状況が発生しています。
翌日7/8の16時頃に現地確認を行い、wwanのLEDが消灯していることを確認しました。

> 吉田です。
>
> 説明がわかりにくかったので再度記載します。
> FORCE_REBOOT が効くのは、LTE が接続済み(connected) 状態で ping 導通が NG のケースとなります。
> LTE が接続中(connecting) が継続する場合は、LTE モジュールのみの再起動を実施しております。
>
> LTE が接続済み(connected)の状態で電波遮断袋に入れると比較的再現させやすいです。

⇒こちらの方法で、"connecting"のままになる…という事象の再現はできたのですが、
 wwanのLEDが消灯状態、の方が再現できませんでした。
 
wwanのLEDが消灯…の条件を製品マニュアルで見ると「SIM 未検出または認識中、または LTE モデム未検出」と記載があります。
発生現場は山の中で、LTE通信が繋がりにくくなることがあるようなのですが、現地調査を行ったタイミングでは、電波が70%程度とれていました。
なお、ソラコム社のsimカードを使用しているのですが、ソラコムサーバー側からはpingが通りませんでした。

LTEが使用できる状態から、"connecting"のままとなる+wwanのLEDが消灯の両方を再現する方法や条件はありますでしょうか。

詳細情報です。
 base_os 3.19.1-at.1
 AG6271

以上、よろしくお願いいたします。

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

at_mitsuhiro.yoshida

2024年7月22日 16時25分

吉田です。

情報ありがとうございます。

> 詳細情報です。
>  base_os 3.19.1-at.1
>  AG6271

connecting 状態が継続した場合に LTE モジュールを再起動する処理は 3.19.1-at.2 以降に実装されております。

> 吉田です。
>
> 情報ありがとうございます。
>
> > 詳細情報です。
> >  base_os 3.19.1-at.1
> >  AG6271
>
> connecting 状態が継続した場合に LTE モジュールを再起動する処理は 3.19.1-at.2 以降に実装されております。

吉田様

ご回答ありがとうございます。
3.19.1-at.2 以降へとOSをバージョンアップさせたうえで、再度評価の方を行ってみようと思います。

3.19.1-at.1のOSバージョンを用いていた場合に、
connecting 状態が継続した場合であって、
 ・周囲のLTE電波環境が正常であっても、connectingから復帰しない事象
 ・wwanのLEDランプが消灯状態となる事象
を再現させる方法について、なんらかの知見や参考となる情報はございませんでしょうか。

可能であれば、OSのバージョンアップ前の状態で再現をさせ、
同様の条件でも、OSのバージョンアップ後は問題なく復旧できる…ということを確認したいと考えております。

お手数をおかけしますが、よろしくお願いいたします。

at_mitsuhiro.yoshida

2024年7月25日 9時53分

吉田です。

"connecting" は何を確認されて connecting と判断されていますでしょうか?
mmcli コマンドで表示される state で判断されていますでしょうか?

WWAN LED が消灯する条件は、以下の 2 条件となります。
(1) modemanager が接続動作を継続していない状況
(2) mmcli コマンドで何も表示されない場合 (LTE モジュール再起動中など)