koma
2017年8月27日 13時19分
800EVAを使用しています。
ETHERNETのドライバ(ETHERCAT)を作成し、
1ms周期で通信しているのですが、
１日に数回 作成したソフトが約6分間(358秒)停止します。
この間TERATERMのモニタもできません。
約6分停止後、再度通常の動作、モニタが可能になります。
必ず約6分(357～358秒)なのですが、
6分停止する理由想定できるものありますでしょうか？
これ以外のソフトは実行しておらず、処理時間も
100μSEC以下/1msecです。
コメント
koma
> 齊藤と申します。
> 誰も応答しないので、雑な推論を申し上げます。
>
> > ETHERNETのドライバ(ETHERCAT)を作成し、
> > 1ms周期で通信しているのですが、
>
> この「1msごと」のソフトウェアロジックが間違っていて
> カーネルモードでの6分間のロック(とかループ)が
> 発生している、というのが一つ疑われます。
>
> 358秒はだいたい 100×512×7 ミリ秒ですね。
>
> 外部からの割り込み信号で強制的にパニックを起こさせるなどで
> スタックトレースが取れればどこの命令コードを実行して止まってるか
> わかるのですが。800EVAってその辺の機能は無かったでしたっけ？
>
・停止している箇所は、
添付 ICE停止時画面.PNGのproc-v7.sの割込待ち（ENTRY cpu_v7_do_idle）です。
wfi命令で待ち、約６分後に抜けてきます。
この間、teraterm操作ができないのですが、
teratermでentを押すと、wfi部分は受け付けます。
但し、６分立つまでは、wfiで待ちになります。
通常は数msec程度でwfiを抜けてきます
また、logを見る場合、添付20171003_var_log.txtの
どのファイルをみれば良いでしょうか？
| ファイル | ファイルの説明 |
|---|---|
| 20171003_var_log.txt |
koma
komaです。
添付 ICE停止画面つけ忘れましたので送付します。
> > 齊藤と申します。
> > 誰も応答しないので、雑な推論を申し上げます。
> >
> > > ETHERNETのドライバ(ETHERCAT)を作成し、
> > > 1ms周期で通信しているのですが、
> >
> > この「1msごと」のソフトウェアロジックが間違っていて
> > カーネルモードでの6分間のロック(とかループ)が
> > 発生している、というのが一つ疑われます。
> >
> > 358秒はだいたい 100×512×7 ミリ秒ですね。
> >
> > 外部からの割り込み信号で強制的にパニックを起こさせるなどで
> > スタックトレースが取れればどこの命令コードを実行して止まってるか
> > わかるのですが。800EVAってその辺の機能は無かったでしたっけ？
> >
> ・停止している箇所は、
> 添付 ICE停止時画面.PNGのproc-v7.sの割込待ち（ENTRY cpu_v7_do_idle）です。
> wfi命令で待ち、約６分後に抜けてきます。
> この間、teraterm操作ができないのですが、
> teratermでentを押すと、wfi部分は受け付けます。
> 但し、６分立つまでは、wfiで待ちになります。
> 通常は数msec程度でwfiを抜けてきます
> また、logを見る場合、添付20171003_var_log.txtの
> どのファイルをみれば良いでしょうか？
>
>
>
>
>
>
| ファイル | ファイルの説明 |
|---|---|
| ICE_停止時画面.png |
koma
komaです。
６分停止する直前のｌｏｇをデバッカでとってみました。
６分停止する理由とそのトリガをしりたいのですが。
> komaです。
> 添付 ICE停止画面つけ忘れましたので送付します。
>
> > > 齊藤と申します。
> > > 誰も応答しないので、雑な推論を申し上げます。
> > >
> > > > ETHERNETのドライバ(ETHERCAT)を作成し、
> > > > 1ms周期で通信しているのですが、
> > >
> > > この「1msごと」のソフトウェアロジックが間違っていて
> > > カーネルモードでの6分間のロック(とかループ)が
> > > 発生している、というのが一つ疑われます。
> > >
> > > 358秒はだいたい 100×512×7 ミリ秒ですね。
> > >
> > > 外部からの割り込み信号で強制的にパニックを起こさせるなどで
> > > スタックトレースが取れればどこの命令コードを実行して止まってるか
> > > わかるのですが。800EVAってその辺の機能は無かったでしたっけ？
> > >
> > ・停止している箇所は、
> > 添付 ICE停止時画面.PNGのproc-v7.sの割込待ち（ENTRY cpu_v7_do_idle）です。
> > wfi命令で待ち、約６分後に抜けてきます。
> > この間、teraterm操作ができないのですが、
> > teratermでentを押すと、wfi部分は受け付けます。
> > 但し、６分立つまでは、wfiで待ちになります。
> > 通常は数msec程度でwfiを抜けてきます
> > また、logを見る場合、添付20171003_var_log.txtの
> > どのファイルをみれば良いでしょうか？
> >
> >
> >
> >
> >
> >
| ファイル | ファイルの説明 |
|---|---|
| 20171006_4_trace1と停止箇所_.zip |
saitoh
koma
回答ありがとうございます。
前回送付したXLSは停止直前のもののトレース結果の認識です。
PID1460(自作)->PID1467(自作)の切替が1000μSEC間隔で発生しています。
セルAの黄色部です。Ａのセル2438行目を最後に、1000μsecの
PIDの切り替えが停止しています。
PID1459(自作)からPID2230（?）の切り替えがAｾﾙ番号2506以降、
自作ｿﾌﾄには戻ってこない状態です。(定周期ｲﾍﾞﾝﾄが発生しなくなる)
その間でBIN/CATの実行やメモリアクセスが行われるのですが、
PID610 agent.netが頻繁に処理をしており、
試しにこのﾌﾟﾛｾｽをKILLすると、この数日間は６分停止現象が発生していない
という状態です。
何か６分間という固定停止する地雷を踏んでいると想像しているのですが。
> 応答が無くなった状態でログを取っても解決は難しいかと思います。
> 応答がなくなる直前に自作ドライバで何をしていたかのログが欲しいところです。
> wake_up系とsleep_on系のカーネル内ルーチン、あとタイマー関係の呼び出し記録をとって眺めてみたら分かるかも・・。
> コンピューテックスのICEでしたらリプレイデバッガ機能とかありませんでしたっけ？
at_mizo
hidetoshi-miyao
宮尾と申します。
数年前に似たような現象に嵌ったので、その時の原因と対応を参考に記載します。
Linuxでのタイマ要求は、最終的には、arch/arm/mach-shmobile/sh_cmt.c内 213行目
sh_cmt_set_next(struct sh_cmt_priv *p, unsigned long delta)
で R-Mobile SoCのタイマユニットに設定されます。
引数 deltaが ディレイ値ですが、ディレイ値はカーネル内での遅延時間を補正して設定されます。
1msecという短いタイマを多用し、かつシステムがビジーになってくると、この遅延時間が大きくなり、deltaが 0に近い値になることがあります。
sh_cmt_set_nextの中では、タイマの現在値を CMCNTレジスタから読み、deltaを加えてから、比較レジスタである CMCORに設定しますが、deltaが0に近いと、バスの状態によっては、CMCORに値を設定した時点で CMCNTが CMCORより大きくなってしまうケースが発生します。この状態になると、CMCNTがラップアラウンドして再び CMCORと一致するまで(約6分間)タイムアウトが発生しなくなります。
このときの対処としては、sh_cmt_set_nextを修正し、
・CMCORに設定後、CMCNTを再度読み、CMCOR > CMCNTで、かつタイマユニットにタイムアウトが発生していなければリトライする
・リトライしても同様の現象が発生するようであれば、ディレイ値を少し大きくして再度リトライする。以上を繰り返す
ようにしたところ、現象は発生しなくなりました。
修正後の sh_cmt_set_nextを参考添付します。
| ファイル | ファイルの説明 |
|---|---|
| sh_cmt_set_next.c |
hidetoshi-miyao
koma
koma
ありがとうございました。
３台で１週間起動テストを行い、６分停止はなくなりました。
１点だけお教えねがいたいのですが、rc.localは特別な記述をしていないのですが
/bin/sh -e/lib/udev/net.agent というプロセスが存在します。
起動しない方法または起動を自動停止させる方法を教えて頂きたいのですが？
> ありがとうございます。
> 発生している現象と一致しており、最後の砦としての対策になると思います。
> 対策を実施して改善を確認致します。本当に助かります。ありがとうございます。
> また、不具合原因は「短い定周期があるのにも関わらず
> システムをＢＵＳＹ状態にしていることが、
> ６分停止を引き起こしている」と理解します。
>
>
>
>
> > > ・CMCORに設定後、CMCNTを再度読み、CMCOR > CMCNTで、かつタイマユニットにタイムアウトが発生していなければリトライする
> >
> > 失礼、CMCOR < CMCNTでした。
hidetoshi-miyao
詳しくはわかりませんが、net.agentは udevから起動されていると思いますので、udevの起動ルール（多分、/etc/udev/rules.d/*.rules）を変更すれば起動しないようにできると思います。起動しないことによる影響の見極めは必要と思いますが、
> ありがとうございました。
> ３台で１週間起動テストを行い、６分停止はなくなりました。
> １点だけお教えねがいたいのですが、rc.localは特別な記述をしていないのですが
> /bin/sh -e/lib/udev/net.agent というプロセスが存在します。
> 起動しない方法または起動を自動停止させる方法を教えて頂きたいのですが？
saitoh
2017年8月29日 12時50分
齊藤と申します。
誰も応答しないので、雑な推論を申し上げます。
> ETHERNETのドライバ(ETHERCAT)を作成し、
> 1ms周期で通信しているのですが、
この「1msごと」のソフトウェアロジックが間違っていて
カーネルモードでの6分間のロック(とかループ)が
発生している、というのが一つ疑われます。
358秒はだいたい 100×512×7 ミリ秒ですね。
外部からの割り込み信号で強制的にパニックを起こさせるなどで
スタックトレースが取れればどこの命令コードを実行して止まってるか
わかるのですが。800EVAってその辺の機能は無かったでしたっけ？