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 です。
解決方法はご存知ないでしょうか?

コメント

佐藤です。

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

後藤です。

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

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

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

佐藤です。

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

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

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

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

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

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

後藤です。

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

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

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

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

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

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

後藤です。

> アプリケーションで異常を検知して再起動する処理は入れていますが
> アプリーケーションの再起動のみ実施しており、証拠も残すようにしています
> 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 ---> <= こちらを先に無効にする。
------------------------------

以上です。

佐藤です。

いただいた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プログラムに問題がないか確認してみるとよいかもしれません。

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

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

佐藤です。

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

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

後藤です。

> 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 が出力されている
時間がズレているので、議論している再起動問題とは別問題の気がします。

以上です。

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

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

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

後藤です。

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

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

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

溝渕です。

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

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

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

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

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

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

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

溝渕です。

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

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

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

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

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

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

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

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

佐藤です。

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

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

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

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

佐藤です。

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

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

カーネル4.9を試してみる方向で進んでおり、カーネルを作成し、デバイスツリーをカスタマイズしたのですが
追加したgpioが/sys/class/gpio下に作成されません
デバイスツリーの設定値はカーネル3.14で設定していたものを転用しているのですが
設定値が間違っていないでしょうか、ご教授ください
添付armadillo_x1.dtsの277行以下に追記しています
ハードウェアはカーネル3.14で動作していたものです

ファイル ファイルの説明
armadillo_x1.dts

at_akihito.irie

2020年8月6日 11時17分

入江です。

いくつか確認させてください。

> カーネル4.9を試してみる方向で進んでおり、カーネルを作成し、デバイスツリーをカスタマイズしたのですが
> 追加したgpioが/sys/class/gpio下に作成されません
これは起動時に自動的に/sys/class/gpio下にgpioディレクトリが作成されることを想定されていますか?
それとも起動後に手動でexportして作成されることを想定されていますか?

> デバイスツリーの設定値はカーネル3.14で設定していたものを転用しているのですが
> 設定値が間違っていないでしょうか、ご教授ください
添付いただいたデバイスツリーはカーネル3.14では想定通りの動作はしましたでしょうか?

3.14時と同じようにgpio下に起動時に自動で策定されることを想定していました
3.14時には作成されていましたが
3.14ではiomuxc.imx7d-sdb.pinctrl_hog_1.{fsl,pins}内に記述し、
4.9ではiomuxc.armadillo-iotg-g3.pinctrl_hog.{fsl,pins}内に記述してあります
3.14では起動時に設定されたgpioファイルが作成されていました

at_akihito.irie

2020年8月6日 16時13分

入江です。

弊社が標準で提供しているカーネル3.14と4.9は、どちらもデバイスツリーに
記述したGPIOを自動的に/sys/class/gpio下にgpioディレクトリを生成するよ
うになっておりません。

お客様がカーネル3.14をお使いの際にユーザーランドでexportする処理を行っ
ていた可能性が考えられますので、ご確認いただけますでしょうか。

大変失礼しました
スタートアップ時にexportしていました
お騒がせし、もうしわけありません