Armadilloフォーラム

wwan-force-restart後、NetworkManagerが再起動されてしまう

anysense

2020年9月25日 11時52分

いつもお世話になっております。Anysenseです。

wwan-force-restart(モデムリセット)後、usb1デバイスの再接続処理が開始されますが
処理途中で以下のようなプロセスKILLが発生し、NetworkManagerの再起動の発生しています。
daemon warning systemd[1]: NetworkManager.service: Main process exited, code=killed, status=11/SEGV

こちらの症状なにか原因はございますでしょうか?ログを添付しますのでご確認をお願いします。
調べた限り直近1週間で30回発生したモデムリセット中、3回で発生しています。

※モデムリセットのトリガー
設定したIPアドレスにPingが届かない時間が3分継続した場合wwan-force-restart(モデムリセット)するようにしています。

ファイル ファイルの説明
syslog.txt シスログ
コメント

at_mitsuhiro.yoshida

2020年9月29日 9時55分

吉田です。

お手数おかけします。
確認したいことが幾つかあります。

(1) 以下のパッケージのバージョンを教えて頂けますでしょうか?
- modemmanager
- els31-utils
- atmark-x1-base
全て
# apt show パッケージ名
で表示可能です。

(2) カーネルのバージョン
# uname -a
で表示可能です。

(3)
> ※ モデムリセットのトリガー
> 設定したIPアドレスにPingが届かない時間が3分継続した場合
> wwan-force-restart(モデムリセット)するようにしています。

とのことですが、これは標準で動作しています、
connection-recover サービスとは別に
動作させているサービスやアプリになりますでしょうか?

また、上記が yes の場合、connection-recover サービスは
停止させていますでしょうか?

ご連絡ありがとうございます。
以下回答します。

> (1) 以下のパッケージのバージョンを教えて頂けますでしょうか?
> - modemmanager
Version: 1.6.4-1atmark5

> - els31-utils
Version: 1.1.0

> - atmark-x1-base
Version: 2.3.2-1
>
> (2) カーネルのバージョン
> # uname -a
Linux armadillo 4.9.133-at12

> (3)
> > ※ モデムリセットのトリガー
> > 設定したIPアドレスにPingが届かない時間が3分継続した場合
> > wwan-force-restart(モデムリセット)するようにしています。
>
> とのことですが、これは標準で動作しています、
> connection-recover サービスとは別に
> 動作させているサービスやアプリになりますでしょうか?
はい、ご認識の通りです。

> また、上記が yes の場合、connection-recover サービスは
> 停止させていますでしょうか?
添付させて頂いたシスログはconnection-recoverと独自サービスが両方稼働中のものです。
※connection-recoverのFORCE_REBOOTはFALSEに設定しています。

後日、独自サービスとのバッティングを疑いconnection-recoverを停止しましたが
同様な事象が発生していました。

at_mitsuhiro.yoshida

2020年9月30日 16時01分

吉田です。

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

もし、検証されていましたら確認したいのですが、

(4) 独自のサービスやアプリの ping チェック → wwan-force-restart 実行を停止し、
connection-recover だけ動作させても同様に
NetworkManager が異常終了しますでしょうか?

(5) 不具合に関連するか不明ですが、ログに以下の情報があります。

2020-09-23 11:00:51 daemon info nm-dispatcher[28092]:  run-parts: /etc/network/if-up.d/static-routes exited with return code 7

ログをみたところ、
/etc/NetworkManager/dispatcher.d/01ifupdown
から
/etc/network/if-up.d/static-routes
を実行し、エラーになっているように見受けられます。

タイミング依存で、static ルーティングの設定が失敗することがあり、
それをトリガーに異常終了する可能性があるのかもしれません。

/etc/NetworkManager/dispatcher.d/01ifupdown
/etc/network/if-up.d/static-routes
の2ファイルはどのような内容になっていますでしょうか?

ご連絡ありがとうございます。以下回答します。

> (4) 独自のサービスやアプリの ping チェック → wwan-force-restart 実行を停止し、
> connection-recover だけ動作させても同様に
> NetworkManager が異常終了しますでしょうか?
申し訳ありませんが、こちらまだ試していません。
お手数ですが、connection-recoverの簡単な仕様をご教示頂けますでしょうか。
何分Ping失敗したら何が起きるなど

(5) 不具合に関連するか不明ですが、ログに以下の情報があります。
> /etc/NetworkManager/dispatcher.d/01ifupdown
> /etc/network/if-up.d/static-routes
> の2ファイルはどのような内容になっていますでしょうか?

ご指摘いただいた、2つのファイルを添付します。
確認ください。
static-routes で/sbin/route del default eth0
で存在しないデフォルトルートを削除しようとしてretuen code7 Nosuch Processになっていると思われます。

よろしくお願いします。

ファイル ファイルの説明
files.zip /etc/NetworkManager/dispatcher.d/01ifupdown、/etc/network/if-up.d/static-routes

申し訳ありません、以下の内容ですが、製品マニュアルに記載されていましたので
回答不要です、失礼しました。
> > (4) 独自のサービスやアプリの ping チェック → wwan-force-restart 実行を停止し、
> > connection-recover だけ動作させても同様に
> > NetworkManager が異常終了しますでしょうか?
> 申し訳ありませんが、こちらまだ試していません。
> お手数ですが、connection-recoverの簡単な仕様をご教示頂けますでしょうか。
> 何分Ping失敗したら何が起きるなど

> > > (4) 独自のサービスやアプリの ping チェック → wwan-force-restart 実行を停止し、
> > > connection-recover だけ動作させても同様に
> > > NetworkManager が異常終了しますでしょうか?
期間が開いてしまい申し訳ありません。
connection-recoverのみ動作させましたが、同様の結果(NetworkManager 異常終了)になりました。
また検証中にconnection-recover内の"nmcli connection up"コマンドが終了しない事象が発生したため
一時的に"timetou 60"をnmcli connection upコマンドに追記して検証しておりました。

当時のシスログと/usr/bin/connection-recoverd を添付しますので
ご確認のほどよろしくお願いします。

ファイル ファイルの説明
syslog_connection_recover_only.txt connection-recoverのみで発生したNetworkManager 異常終了
connection-recoverd.txt /usr/bin/connection-recoverd

at_mitsuhiro.yoshida

2020年10月28日 13時41分

吉田です。

お手数おかけします。

解析状況の報告のみになります。

100回以上、ping 不通 → wwan-force-restart を繰り返してみてはいるのですが、
Network Manager が再起動する状況を作り出せておりません。

頂いたログの中にあります、

2020-10-14 22:13:01 user warning NetworkManager[832]:  g_object_notify_by_pspec: assertion 'G_IS_OBJECT (object)' failed
2020-10-14 22:13:01 daemon warning systemd[1]:  NetworkManager.service: Main process exited, code=killed, status=11/SEGV
2020-10-14 22:13:01 daemon notice systemd[1]:  NetworkManager.service: Unit entered failed state.

の箇所が Network Manager が落ちずに、

Apr 22 08:23:43 armadillo NetworkManager[709]: ((src/devices/nm-device.c:791)): assertion '' failed
Apr 22 08:23:43 armadillo NetworkManager[709]:   [1587543823.7620] device ((null)): remove_pending_action (1): 'queued-state-change-disconnected' not pending
Apr 22 08:23:43 armadillo ModemManager[720]:   Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
Apr 22 08:23:43 armadillo NetworkManager[709]: file src/devices/nm-device.c: line 11364 (): should not be reached

と進んでいきます。

お手数ですが、ログの中で

NetworkManager[***]: g_object_notify_by_pspec: assertion 'G_IS_OBJECT (object)' failed

が出力されていても Network Manager が落ちていないパターンはありますでしょうか?

それと比較して何が発生しているのか確認していくことになるかと思います。

よろしくお願いします。

解析ありがとうございました。以下回答します。

> お手数ですが、ログの中で
>
> NetworkManager[***]: g_object_notify_by_pspec: assertion 'G_IS_OBJECT (object)' failed
>
> が出力されていても Network Manager が落ちていないパターンはありますでしょうか?
>
> それと比較して何が発生しているのか確認していくことになるかと思います。

Network Managerが落ちないパターンのログを添付します。(connection_recoverのみの動作)
こちらが比較した限りですとNetwork Managerが落ちるまでのログに特に違いがなかったです。

また、関係するかは不明ですが、こちらのArmadilloはWifi接続もしておりNetworkManagerにより管理されている状態です。
以下の設定ファイルも添付します。
/etc/NetworkManager/system-connections/wifi-wlan0

大変お手数化おかけしますが、NetworkManagerでWifi接続した状態で再度解析お願いできますでしょうか?

ファイル ファイルの説明
wifi-wlan0.txt /etc/NetworkManager/system-connections/wifi-wlan0
syslog_connection_recover_only_not_kill.txt connection-recoverのみでNetworkManager 異常終了しない場合