Armadilloフォーラム

Armadillo-X1の再起動が3~6時間ごとに発生します。

k.kumasaka

2020年6月12日 16時47分

Armadillo-X1の再起動が3~6時間ごとに発生します。
使用LinuxはLinux armadillo 3.14.79-at10 #39 SMP PREEMPT Fri Dec 6 14:14:34 JST 2019 armv7l GNU/Linux です。
解決方法はご存知ないでしょうか?


コメント

at_makoto.sato

2020年6月12日 18時21分

佐藤です。

何かご自身で開発されたアプリケーションなどを動作させていますでしょうか。
/var/log/syslog や /var/log/messages などに再起動発生時のログなど出力されてますでしょうか。

k.kumasaka

2020年6月12日 18時41分

アプリケーションは動作させています。再起動ログを添付致します。

ファイル ファイルの説明
再起動.log

k.kumasaka

2020年6月12日 18時44分

アプリで障害が起こり、再起動する原因はあるのでしょうか?

ktgoto

2020年6月12日 19時35分

後藤です。

例えば、アプリケーションでソフトウェアウォッチドッグ
タイマーを使用していて、リフレッシュに失敗している
可能性は無いでしょうか?

ログですがカーネルのログ/var/log/kern.logも確認した
方が良いかもしれません。

> アプリケーションは動作させています。再起動ログを添付致します。

at_makoto.sato

2020年6月15日 17時53分

佐藤です。

ご自身で開発されたアプリケーションを動作させていなくても3〜6時間ごとに再起動しますでしょうか。

y-full

2020年6月16日 18時27分

お世話になります
k.kumasakaの代わりにアカウントy-fullがお答えします

アプリケーションは開発しています
ソフトウェアウォッチドッグタイマーとは何を指していますでしょうか、X1に実装しているウォッチドッグの操作方法がわからなかったので使用していません
また、アプリケーションはphp、bashスクリプト、c言語で30本弱動作させています

なお本日は6/16 5:27ごろに発生しました、以降は発生していません
発生頻度は不確定かと思われます

また発生時と思われるkern.logおよびsyslog.1およびdmeagを送付いたします
なにかお分かりになるようでしたら、ご助言願います

ファイル ファイルの説明
kern.log
syslog1.log
dmesg.log

ktgoto

2020年6月17日 9時58分

後藤です。

> お世話になります
> k.kumasakaの代わりにアカウントy-fullがお答えします
>
> アプリケーションは開発しています
> ソフトウェアウォッチドッグタイマーとは何を指していますでしょうか、X1に実装しているウォッチドッグの操作方法がわからなかったので使用していません
> また、アプリケーションはphp、bashスクリプト、c言語で30本弱動作させています

ソフトウェアウォッチドッグタイマーは、CPUのウォッチドッグタイマーとは別にカーネルが提供するソフトウェアによるウォッチドッグタイマーです。
カーネルのコンフィギュレーションで CONFIG_SOFT_WATCHDOG を有効にすると使用可能で、リフレッシュに失敗するとリセットではなく再起動が行われます。

> なお本日は6/16 5:27ごろに発生しました、以降は発生していません
> 発生頻度は不確定かと思われます
>
> また発生時と思われるkern.logおよびsyslog.1およびdmeagを送付いたします
> なにかお分かりになるようでしたら、ご助言願います

ログの添付ありがとうございます。内容確認してみます。

確認なんですが、アプリケーションの機能として異常を検知して再起動するような処理は特に実装していないにも関わらず、意図しない再起動が行われるという理解で合っていまでしょうか?

y-full

2020年6月17日 15時10分

お世話になります
アプリケーションで異常を検知して再起動する処理は入れていますが
アプリーケーションの再起動のみ実施しており、証拠も残すようにしています
OSまで再起動するような機能は入れておりません
以上、よろしくお願いいたします

at_makoto.sato

2020年6月17日 15時51分

佐藤です。

いただいたkern.logの中に以下のような箇所があります。
-----
(省略)
Jun 14 14:09:50 armadillo kernel: Kernel BUG at 800c2bc8 [verbose debug info unavailable]
Jun 14 14:09:50 armadillo kernel: Internal error: Oops - BUG: 0 [#1] PREEMPT SMP ARM
Jun 14 14:09:50 armadillo kernel: Modules linked in:
Jun 14 14:09:50 armadillo kernel: CPU: 0 PID: 22977 Comm: soilrecv Not tainted 3.14.79-at10 #39
(省略)
-----

soilrecvというアプリケーションが原因のようにみえますが、これはご自身で開発されたアプリケーションでしょうか。
もし、そうであれば、今一度soilrecvプログラムに問題がないか確認してみるとよいかもしれません。

y-full

2020年6月17日 16時51分

soilrecvはこちらで作成したアプリケーションですが
おそらくノイズによるもので、改修済みにしているのですが
まだ、なにかあるのかしれませんので調査してみます、これが理由でOSが再起動しているということでしょうか
ちなみにtaintedメッセージの後にあるのはスタックとレースと、バックログが記述されているといことでよろしいでしょうか

再起動している時間とずれているような気がするのですが
どのような因果関係が考えられるか、ご教授願えますでしょうか

at_makoto.sato

2020年6月17日 17時30分

佐藤です。

> ちなみにtaintedメッセージの後にあるのはスタックとレースと、バックログが記述されているといことでよろしいでしょうか
はい、ご認識とのとおりです。

また、カーネルのバージョンを 4.9 に上げて動作確認いただくことは可能でしょうか。

y-full

2020年6月17日 18時27分

お世話になります
古川です
カーネルバージョンをを上げるのは検討してみます
メジャーバージョンを上げることになるかと思うのですが(3.14->4.9?)、
その間のバージョンは見当たらなく、変更履歴も探せませんでした
(コミュニティでカーネルの履歴を見ればいいとういことでしょうか、
もしある程度お分かりになるのであれば、ざっくりで教えていただけると幸いです)

カーネルの変更によって今回の関連事象として、何かしら避けられる事象があるので
あればご教授いただけないでしょうか

ktgoto

2020年6月17日 18時27分

後藤です。

> アプリケーションで異常を検知して再起動する処理は入れていますが
> アプリーケーションの再起動のみ実施しており、証拠も残すようにしています
> OSまで再起動するような機能は入れておりません

ご説明ありがとうございます。

@tの佐藤様が kern.log に関してコメントされていますが、kern.log に関して別の観点でコメント致します。

kern.log に以下のログが出力されており、カーネルのマジック SysRq キーが動いた形跡がありました。

| Jun 16 12:42:59 armadillo kernel: SysRq : HELP : loglevel(0-9) reboot(b) crash(c) terminate-all-tasks(e) memory-full-oom-kill(f) kill-all-tasks(i) thaw-filesystems(j) sak(k) show-backtrace-all-active-cpus(l) show-memory-usage(m) nice-all-RT-tasks(n) poweroff(o) show-registers(p) show-all-timers(q) unraw(r) sync(s) show-task-states(t) unmount(u) show-blocked-tasks(w)

マジック SysRq キーの詳細は下記の URL をご参照ください。

http://archive.linux.or.jp/JF/JFdocs/Remote-Serial-Console-HOWTO/securi…
https://www.kernel.org/doc/html/latest/admin-guide/sysrq.html

Armadillo-X1 では、シリアルコンソールにブレークを送信後、対応する文字を書き込むことでマジック SysRq キーを利用でき、再起動等の操作ができます。未対応の文字を書き込むと上記のような HELP が出力されます。

意図的にマジック SysRq キーを使用したということでなければ、アプリが意図せずマジック SysRq キーで再起動操作と認識されるような文字シーケンスをシリアルコンソールに書き込んでしまっている可能性があるかもしれません。

マジック SysRq キーは、カーネルのコンフィギュレーションで無効にできますので、マジック SysRq キーを無効にした状態で評価してみるのは如何でしょうか?

----- メニューコンフィグ -----
Kernel hacking --->
[ ] Magic SysRq key
[ ] KGDB: kernel debugger ---> <= こちらを先に無効にする。
------------------------------

以上です。

y-full

2020年6月17日 18時30分

お世話になります
古川です
カーネルコンフィグレーションを変更するのは可能ですので
試してみます

ktgoto

2020年6月17日 19時52分

後藤です。

> soilrecvはこちらで作成したアプリケーションですが
> おそらくノイズによるもので、改修済みにしているのですが
> まだ、なにかあるのかしれませんので調査してみます、

kern.logに出力されていたカーネルの Oops ですが、soilrecvの
問題ではなく3.14カーネルのUARTドライバdrivers/tty/serial/imx.c
の不具合っぽいです。

UARTドライバにimx_uart_dma_init()というDMA転送の初期化を
行う関数があり、この関数内でDMA転送用の領域を確保しています
が、領域の確保に失敗した際に後処理として呼び出している
imx_uart_dma_exit()で確保していない領域をfreeしてしまって
いるようです。

4.9カーネルでは対策されているようですが、3.14カーネルでずっと
評価をされており簡単にバージョンアップできないということであれば、
@tさんにパッチをリリースしてもらうのが良いかもしれません。

> これが理由でOSが再起動しているということでしょうか
> ちなみにtaintedメッセージの後にあるのはスタックとレースと、バックログが記述されているといことでよろしいでしょうか
>
> 再起動している時間とずれているような気がするのですが
> どのような因果関係が考えられるか、ご教授願えますでしょうか

カーネル Oops が出力された後、再起動したかどうかは kern.log から
は判断できませんでした。

ただ、記載されているよう再起動時間とカーネル Oops が出力されている
時間がズレているので、議論している再起動問題とは別問題の気がします。

以上です。

y-full

2020年6月18日 13時16分

お世話になります
古川です
場違いな質問かもしれませんが、もしご存じでしたら教えてください
稼働中のメモリの使用量が減り続けているのですが
キャッシュクリーンアップやphpのガーベージが間に合ってないのかもしれません
もしメモリが足りなくなった時の3系カーネルの挙動はどうなるでしょうか、ログを吐いたりはしないでしょうか

at_mizo

2020年6月18日 13時29分

溝渕です。

> 稼働中のメモリの使用量が減り続けているのですが
> キャッシュクリーンアップやphpのガーベージが間に合ってないのかもしれません
> もしメモリが足りなくなった時の3系カーネルの挙動はどうなるでしょうか、ログを吐いたりはしないでしょうか

状況によります。ログを吐ける場合もあります。

まずどのメモリが減っているか次第なのですが、Linuxは未使用メモリをCache
に使うので、稼動時間が長くなるとほぼ100%のメモリを使うはずです。この場
合、実際にはメモリは枯渇していません。

Cache等一時的に使われる以外のメモリが不足した場合、アプリケーションは
メモリの確保に失敗します。この場合にログを吐くかどうかはアプリケーショ
ン次第です。

Over Commitしているメモリが使えないにメモリが枯渇している場合や、
kernel内でメモリの確保ができない場合はOOM-Killerが走るなどすると思いま
す。この場合はほぼログが吐かれます。

y-full

2020年6月18日 13時48分

お世話になっております
古川です

メモリの件承知しました
原則意図的なメモリ確保は行っていませんが
PHP常駐プロセス等はプロセスが死ぬ程度だという認識で大丈夫でしょうか
この場合プロセス管理をしていますので、アプリケーションの再起動を行いますので
メモリが減ったぐらいではOS再起動まではいかないということですね

at_mizo

2020年6月18日 13時56分

溝渕です。

> PHP常駐プロセス等はプロセスが死ぬ程度だという認識で大丈夫でしょうか

OOM-Killerが終了させるプロセスはメモリの確保に失敗したプロセスではあり
ません。確かメモリを多く使っているプロセスが終了の対象になったと思いま
す。

余談ですが、procから任意のプロセスをOOM-Killerの対象外にしたり、終了さ
せられる優先度の変更等ができたと思います。

> この場合プロセス管理をしていますので、アプリケーションの再起動を行いますので
> メモリが減ったぐらいではOS再起動まではいかないということですね

絶対に大丈夫とは言えないのですが、OSの基本的なポリシーとして自身が動作
できなくなることは極力避けるようにします。

y-full

2020年6月22日 5時00分

お世話になります
古川です

kern.logを見ていて気になったことがあります
勝手に再起動した時の時刻が1/1 9:00(おそらく電源投入時の初期値だと思います)になっているのですが
起動時刻が初期値になる条件は電源投入以外で考えられるでしょうか
もしかしたらハードウェアの電源周りが原因なのではとも思っています
なお、今回使用しているシステムには電池バックアップ等は入っておりませんので
瞬停でも再起動するような気がします

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

at_makoto.sato

2020年6月22日 9時30分

佐藤です。

> 勝手に再起動した時の時刻が1/1 9:00(おそらく電源投入時の初期値だと思います)になっているのですが
> 起動時刻が初期値になる条件は電源投入以外で考えられるでしょうか
rebootコマンドなどによる再起動でも起動時刻は初期値になります。

y-full

2020年6月23日 12時29分

お世話になります
古川です

こちらで確認したところ、rebootコマンド一行では時計の初期化がされていないようなのですが
rebootコマンド実行後再起動で時計の初期化をする条件を教えていただけないでしょうか
よろしくお願いいたします

y-full

2020年6月29日 14時52分

お世話になります
アルマジロX1においてどのプロセスがrebootを実行したかわかるようなログ等はないでしょうか
shudownスクリプトを組んで何かしら残すしかないでしょうか

at_makoto.sato

2020年6月29日 15時34分

佐藤です。

> shudownスクリプトを組んで何かしら残すしかないでしょうか
組んだshutdownスクリプトの中でpstreeコマンドを実行して出力するとよいかもしれません。

ktgoto

2020年6月30日 9時57分

後藤です。

> カーネルコンフィグレーションを変更するのは可能ですので
> 試してみます

こちらの件ですが、状況改善されましたでしょうか?

y-full

2020年6月30日 16時02分

古川です
申し訳ありません
社内で検討中で作業が先に進んでいません
なにかありましたら連絡させていただきます