masaya_yoshitomi
2024年5月30日 20時45分
-----------------------------------------------------------------------------------
■背景
------------------------------------------------------------------------------------
以下フォーラムに記載の問題が発生しRebootした場合にどのようなログが残るかを知りたい
https://armadillo.atmark-techno.com/forum/armadillo/19509
https://armadillo.atmark-techno.com/news/software-errata/x1/20240328
------------------------------------------------------------------------------------
■質問内容
------------------------------------------------------------------------------------
【動作環境】
・OS：Debian GNU/Linux 10 (buster)
・Boot：u-boot-x1-at23.bin
・カーネル：uImage-x1-v4.9-at26
・DTB：armadillo_iotg_g3_m1-v4.9-at26.dtb
・ファイルシステム：debian-buster-armhf_aiotg3_20221118.tar.gz(fixupにて独自変更を加えています)
■質問
フォーラムにて記載されているDRAM化けによるReboot問題に類似した事象が発生しております。
DRAM化けによるReboot問題が発生した場合、何かしらのログファイルに必ずXXXのようなログが出力されますなど
問題事象が発生したのかどうかを見分ける手段があればご教授頂けないでしょうか？
なお、こちらでログを見た感じ、突然Rebootする際は以下のように
UTF8の文字コードU+0000(見た目空白)がずらっと並んだ後に、
armadillo kernel: Booting Linux on physical CPU 0x0が出力されます。
自分で電源OFF→ONしたときも同じようなログを出力しており、Terminalからrebootコマンド投入して再起動させた場合は
UTF8の文字コードU+0000(見た目空白)は出力されていませんでした。
以下、一例です。「」は出力されません。
「Mar 18 08:01:52 armadillo kernel: Booting Linux on physical CPU 0x0」
イメージ伝わりにくいため以下も連携します。
https://armadillo.atmark-techno.com/forum/armadillo/19509
の添付資料「/var/log/kern.log」からの引用になりますが
kern.log\kern.log.1内1866行目のような出力です。
正常時は同じログの382行目のように出力されます。
コメント
at_shinya.koga
2024年5月31日 12時09分
アットマークテクノの古賀です。
masaya_yoshitomiさん：
>■質問
>フォーラムにて記載されているDRAM化けによるReboot問題に類似した事象が発生しております。
>DRAM化けによるReboot問題が発生した場合、何かしらのログファイルに必ずXXXのようなログが出力されますなど
>問題事象が発生したのかどうかを見分ける手段があればご教授頂けないでしょうか？
問題事象の発生時に必ずログに出力されるメッセージというのは、ありません。
問題事象において、DRAM から Read するデータが化けてウォッチドッグタイマーによるリセットが発生する場合、Linux カーネルやユーザーランドに対して、動作中に電源 OFF->ON したのと同様な効果を生みます。
ウォッチドッグタイマーによるリセットが発生する直前は、割り込みハンドラの実行中に、データ化けによる不正命令ないし不正データアクセスの CPU 例外が発生して再度割り込みハンドラ先頭に実行が移り、割り込みハンドラ実行中に CPU 例外が発生して・・・という繰り返しとなり、カーネルがハングアップする状態となっているようです。
>なお、こちらでログを見た感じ、突然Rebootする際は以下のように
>UTF8の文字コードU+0000(見た目空白)がずらっと並んだ後に、
>armadillo kernel: Booting Linux on physical CPU 0x0が出力されます。
>自分で電源OFF→ONしたときも同じようなログを出力しており、Terminalからrebootコマンド投入して再起動させた場合は
>UTF8の文字コードU+0000(見た目空白)は出力されていませんでした。
/var/log/kern.log の出力内容だけからは、動作中に電源が切れて電源復旧したのか、問題事象によるウォッチドッグタイマーリセットが起きたのかを区別するのは難しいです。
>動作環境】
> ・OS：Debian GNU/Linux 10 (buster)
> ・Boot：u-boot-x1-at23.bin
> ・カーネル：uImage-x1-v4.9-at26
> ・DTB：armadillo_iotg_g3_m1-v4.9-at26.dtb
> ・ファイルシステム：debian-buster-armhf_aiotg3_20221118.tar.gz(fixupにて独自変更を加えています)
u-boot のバージョンが、事象の発生するソフトウェアのバージョン（U-Boot v2016.07-at24以前）に該当していますね。問題事象が起きている可能性はありますので、対策版を適用してみて頂くのが良いと思います。
ログを拝見すると、
armadillo kernel: Booting Linux on physical CPU 0x0
のログが出力される直前まで、以下のログが繰り返し出力されている場合が多く、メモリ負荷の高い状況で動作中の再起動が起きている頻度が高そうです：
alloc_contig_range: [ac0a0, ac0b4) PFNs busy
https://armadillo.atmark-techno.com/forum/armadillo/3847#comment-6885
メモリ負荷の高い状況の方が事象が起きやすいと考えられるため、問題事象が発生している可能性は低くないと思います。
masaya_yoshitomi
2024年5月30日 20時48分
すみません、ログファイルを添付忘れましたので添付します。