akihito
2024年8月16日 13時53分
発生環境：
Armadillo-IoT ゲートウェイ A6E +Di8+Ai4
ソフトウェアバージョン：
base_os 3.19.2-at.5
boot 2020.4-at24
extra_os.a6e-gw-container 2.5.2
アプリケーション：
CUI アプリケーション
コンテナ：
privileged権限付与、rootユーザで実行
コンテナbaseOS：
alpine
上記環境でコンテナトリガで間欠動作を実現しています。
コンテナ終了時に稀に スリープ（SMSあり） に移行しないことがあります。
またこの現象が発生すると、コンテナは既に終了しているため以降スリープしなくなります。（ユーザ目線ではだんまり状態）
コンテナのログ（掲載不可）と /var/log/message を比較すると、コンテナ終了の0.5秒後に★のログが出ておりました。
本件含めて2件しか発生しておらず、諸事情によりログの解析が出来る状況となったのが今回が初めてとなります。
★のログはスリープしなかったことと関係があると野ではと考えておりますが、いかがでしょうか？
本件以外で同様の現象は発生しておりますでしょうか？
ご教示のほどよろしくお願いします。
-ログ(/var/log/message)-
Aug 16 13:22:34 armadillo daemon.notice [1997]: [modem0] simple connect started...
Aug 16 13:22:34 armadillo daemon.notice [1997]: [modem0] simple connect state (6/10): register
Aug 16 13:22:34 armadillo daemon.notice [1997]: [modem0] simple connect state (7/10): wait to get packet service state attached
Aug 16 13:22:34 armadillo daemon.notice [1997]: [modem0] simple connect state (8/10): bearer
Aug 16 13:22:34 armadillo daemon.notice [1997]: [modem0] simple connect state (9/10): connect
Aug 16 13:22:34 armadillo daemon.notice [1997]: [modem0] state changed (registered -> connecting)
★Aug 16 13:22:50 armadillo kern.info kernel: [ 134.974087] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Aug 16 13:22:54 armadillo daemon.warn [1997]: [modem0/bearer0] connection attempt #4 failed: Couldn't match response
Aug 16 13:22:54 armadillo daemon.notice [1997]: [modem0] state changed (connecting -> registered)
Aug 16 13:22:54 armadillo daemon.notice [1997]: [modem0/bearer0] connection #4 finished: duration 0s
Aug 16 13:22:54 armadillo daemon.warn [1997]: [modem0] couldn't connect bearer: Couldn't match response
Aug 16 13:22:54 armadillo daemon.warn NetworkManager[1048]: [1723782174.7664] modem-broadband[ttyCommModem]: failed to connect modem: Couldn't match response
Aug 16 13:22:54 armadillo daemon.info NetworkManager[1048]: [1723782174.7669] device (ttyCommModem): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
Aug 16 13:22:54 armadillo daemon.info NetworkManager[1048]: [1723782174.7944] manager: NetworkManager state is now CONNECTED_LOCAL
Aug 16 13:22:54 armadillo daemon.warn NetworkManager[1048]: [1723782174.7987] device (ttyCommModem): Activation: failed for connection 'gsm-ttyCommModem'
Aug 16 13:22:54 armadillo daemon.info NetworkManager[1048]: [1723782174.8206] device (ttyCommModem): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
--
コメント
koga
アットマークテクノの古賀（休日モード）です。
akihitoさん：
>上記環境でコンテナトリガで間欠動作を実現しています。
>コンテナ終了時に稀に スリープ（SMSあり） に移行しないことがあります。
>またこの現象が発生すると、コンテナは既に終了しているため以降スリープしなくなります。（ユーザ目線ではだんまり状態）
>コンテナのログ（掲載不可）と /var/log/message を比較すると、コンテナ終了の0.5秒後に★のログが出ておりました。
>本件含めて2件しか発生しておらず、諸事情によりログの解析が出来る状況となったのが今回が初めてとなります。
>★のログはスリープしなかったことと関係があると野ではと考えておりますが、いかがでしょうか？
マルティネ：
>>★Aug 16 13:22:50 armadillo kern.info kernel: [ 134.974087] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
>
>このログは rootfs (Armadillo Base OS の / ファイルシステム）がリマウントされたとのことですので、おそらく何かが persist_file で何かのファイルを永続化しましたと思います。
>これでスリープしないことはないと思いますが、意図的に何かを保存してないと思いますので気になるログですね…
>
>お手数ですが、間欠動作の設定を教えていただけますでしょうか？
>
>具体的に
> - Armadillo Base OS とカーネルのバージョン「cat /etc/atmark-release」「uname -r」
>- コンテナコンフィグファイルの内容（少なくとも間欠動作に関わる hook まわり、a6e-gw-container.conf を元にした場合は念のため hooks-dir の中身も確認したいです）
>- /etc/atmark/power-utils.conf の内容（バージョンが古かった場合は /etc/conf.d/power-utils.conf )
>
>普段は間欠動作をできてますのでこれで大きい問題を見つからないと思いますが、ひとまず内容を確認してこちらで再現できるかを試したいと思います。
追加でお願いですが、もし、症状が発生した際に /var/run/power-utils.log を採取可能であれば、採取して頂けると助かります。
状況からすると、コンテナ終了をトリガとして atmark-power-utils サービスが電源状態を遷移すべきところ、状態遷移できていないようです。
コンテナ終了通知を受けて電源状態を遷移しようとした際に、atmark-power-utils サービス内でエラーが起きていれば、/var/run/power-utils.log にエラーログが出ていると思います。その内容を見ることで、手がかりを得られるかも知れません。
akihito
アットマークテクノ 古賀さん
お世話になっております。
返信ありがとうございます。
> 追加でお願いですが、もし、症状が発生した際に /var/run/power-utils.log を採取可能であれば、採取して頂けると助かります。
> 状況からすると、コンテナ終了をトリガとして atmark-power-utils サービスが電源状態を遷移すべきところ、状態遷移できていないようです。
→ /var/run/power-utils.log の内容を確認しましたが、空（から）でした。
同じ現象が発生した場合は 直ぐに/var/run/power-utils.log を確認するようにいたします。
akihito
マルティネさん
お世話になっております。
早速の返信ありがとうございます。
> このログは rootfs (Armadillo Base OS の / ファイルシステム）がリマウントされたとのことですので、おそらく何かが persist_file で何かのファイルを永続化しましたと思います。
→ 承知しました。
たしかに コンテナ終了時に/etc/atmark/power-utils.confを更新して persist_file で永続化しておりますので、そのログになりそうです。
該当ログが関係ないことが分かり、安心しました。
さて間欠動作の設定について共有します。
> - Armadillo Base OS とカーネルのバージョン「cat /etc/atmark-release」「uname -r」
■armadillo:~# cat /etc/atmark-release
3.19.2-at.5
■armadillo:~# uname -r
5.10.220-1-at
> - コンテナコンフィグファイルの内容（少なくとも間欠動作に関わる hook まわり、a6e-gw-container.conf を元にした場合は念のため hooks-dir の中身も確認したいです）
■app.conf (抜粋)
add_args --hooks-dir=/etc/containers/aiot_gw_container_hooks.d
■armadillo:~# cat /etc/containers/aiot_gw_container_hooks.d/hook.sh
#!/bin/sh
/usr/bin/pwu_notify container_stop
■armadillo:~# cat /etc/containers/aiot_gw_container_hooks.d/setting.json
{
"version": "1.0.0",
"when": { "always": true },
"hook": { "path": "/etc/containers/aiot_gw_container_hooks.d/hook.sh" },
"stages": ["poststop"]
}
> - /etc/atmark/power-utils.conf の内容（バージョンが古かった場合は /etc/conf.d/power-utils.conf )
TARGETの名称は適当なものに変更しております。
TARGET='test'
MODE='SLEEP'
WAKEUP='RTC:240','SMS'
よろしくお願いします。
at_dominique.m…
マルティネです。
> さて間欠動作の設定について共有します。
情報ありがとうございます。
コードを確認したところいくつかの可能性があります：
* SMS で wake up して、再び sleep する時にまだ前回の RTC タイマーが切れてない場合は、再び RTC のタイマーを設定できないことでエラーします
* /run が full になった際（コンテナも起動できなくなりますし、そうならないのは動作の条件になりますが、power-utils.log のサイズに制限がないところは引っかかりました。full になるまではもの凄く時間かかりそうですが、一応制限を追加した方がいいと感じました）
他に問題があるかもしれませんので、再び発生した際にログを確認していただければ幸いです。
とりあえず一つ目のが怪しいと思いますので、それでしたらログではっきり分かります:
sh: write error: Resource busy aiot-set-wake-trigger failed for rtc.
修正の納期は約束できませんが、とりあえずのワークアラウンドとしてはリトライを足せばこの問題を回避できると思いますので、
/usr/bin/aiot-set-wake-trigger にこういう変更を加えたら再現しなくなるはずです：
--- a/aiot-set-wake-trigger
+++ b/aiot-set-wake-trigger
@@ -83,7 +83,9 @@ alarm_timer () {
*) usage;;
esac
- echo "$1" > /sys/class/rtc/rtc0/wakealarm
+ while ! echo "$1" > /sys/class/rtc/rtc0/wakealarm; do
+ sleep 10;
+ done
}
alarm_timer_off () {(最終の修正は違う形になると思いますが、この問題だと確認できたら使ってみてください）
よろしくお願いします。
at_dominique.m…
akihito
akihito
アットマークテクノ 古賀さん、マルティネさん
概ね再現手順が判明しました。
コンテナ終了によるスリープの直前で例えば、シリアルコンソールにてEnterキーを連続入力するとスリープしませんでした。
この際に /var/run/power-utils.log を取得しましたが空（から）となっておりました。
-ログ-
armadillo:~# cat /var/run/power-utils.log
armadillo:~# cat /etc/atmark/power-utils.conf
TARGET='test'
MODE='SLEEP'
WAKEUP='RTC:420', 'SMS'
armadillo:~#
ひとまず上記再現手順であれば、運用で起こることはないのですが、他のトリガ（何らかの割込み）でも発生しそうな気がしております。
何か分かりますでしょうか？
必要なログ等がありましたら、取得しますので返信頂けると助かります。
at_shinya.koga
アットマークテクノの古賀です。
akihitoさん：
>概ね再現手順が判明しました。
>コンテナ終了によるスリープの直前で例えば、シリアルコンソールにてEnterキーを連続入力するとスリープしませんでした。
>
>この際に /var/run/power-utils.log を取得しましたが空（から）となっておりました。
>
>-ログ-
>armadillo:~# cat /var/run/power-utils.log
>armadillo:~# cat /etc/atmark/power-utils.conf
>
> TARGET='test'
> MODE='SLEEP'
> WAKEUP='RTC:420', 'SMS'
> armadillo:~#
こちらで同様の手順を試してみているのですが、再現できません。
>ひとまず上記再現手順であれば、運用で起こることはないのですが、他のトリガ（何らかの割込み）でも発生しそうな気がしております。
>何か分かりますでしょうか？
>必要なログ等がありましたら、取得しますので返信頂けると助かります。
要因切り分けのため、次の二点を試してみて頂けると助かります：
1.) power-utils.conf の起床要因設定（WAKEUP）から 'SMS' を除外した場合、上記再現手順でスリープしない症状は変わりなく起きるでしょうか？
2.) 上記再現手順を行わずにコンテナが終了してスリープした場合も、起床後に /var/run/power-utils.log は空のままでしょうか？
(2) については、SMS を起床要因にしてスリープした場合、/var/run/power-utils.log には次のようなログが出力されるはずなのです：
AT^SIND="message",0 ^SIND: message,0,0 OK AT^SIND="message",1 ^SIND: message,1,0 OK
以上、ひとまずのコメントです。お手数をかけますが、どうぞ宜しくお願いします。
at_dominique.m…
2024年8月16日 14時44分
akihitoさん
お世話になっています、
マルティネです。
> ★Aug 16 13:22:50 armadillo kern.info kernel: [ 134.974087] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
このログは rootfs (Armadillo Base OS の / ファイルシステム）がリマウントされたとのことですので、おそらく何かが persist_file で何かのファイルを永続化しましたと思います。
これでスリープしないことはないと思いますが、意図的に何かを保存してないと思いますので気になるログですね…
お手数ですが、間欠動作の設定を教えていただけますでしょうか？
具体的に
- Armadillo Base OS とカーネルのバージョン「
cat /etc/atmark-release」「uname -r」- コンテナコンフィグファイルの内容（少なくとも間欠動作に関わる hook まわり、a6e-gw-container.conf を元にした場合は念のため hooks-dir の中身も確認したいです）
- /etc/atmark/power-utils.conf の内容（バージョンが古かった場合は /etc/conf.d/power-utils.conf )
普段は間欠動作をできてますのでこれで大きい問題を見つからないと思いますが、ひとまず内容を確認してこちらで再現できるかを試したいと思います。
よろしくお願いします。