自作関数のリエントラント性について

> この関数がメインと割り込みで競合した場合、

割り込み処理が正しく実装されてるかも疑われるべきでしょう。

fujita nozomuさん

コメントありがとうございます。
割り込み処理はA/D変換の割り込みで、コード生成ツールにより作成されたr_cg_adc_user.c内のr_adc_interrupt()関数内でユーザー定義関数を呼び出しております。

static void __near r_adc_interrupt(void)

_r_adc_interrupt@1:
c1 PUSH AX
c3 PUSH BC
c5 PUSH DE
c7 PUSH HL
8efd MOV A,ES
70 MOV X,A
8efc MOV A,CS
c1 PUSH AX
ADCint( );

fc918c00 CALL !!_ADCint
c0 POP AX
9efc MOV CS,A
60 MOV A,X
9efd MOV ES,A
c6 POP HL
c4 POP DE
c2 POP BC
c0 POP AX
61fc RETI


ネストが深く、長くなるのでADCintの中までは記載しませんが、上記でスタック退避していることから問題ないと考えております。

リエントラント性について問題はなく、割り込み関数も正常にコード化されているようですが、

> RESF=10hのリセットが発生します。

RESF の bit4 がセットされるのはウォッチドッグタイマによる内部リセットなので其方を疑うべきと思います。
mmcopy() は最適化なしでコンパイルされており 1バイトの転送に 20クロックくらい要する実行効率の良くないコードとなっており、割り込み処理の中でどのような用途で使用されているのか分かりませんが、例えば A/D 変換で入力された値をバッファに格納する際、過去に貯めた値をがばっとブロック転送している場合などではバッファのサイズにより結構な処理時間を要してしまう可能性があり、それによりウォッチドッグを叩くタイミングに遅れてしまいリセットが掛かる、というような状況は普通に考えられるのではないかと思います。割り込み処理では重い処理はさせずに先の想定ではブロック転送を止めてリングバッファを導入する等対策が必要でしょう。
ウォッチドッグタイマの設定やウォッチドッグの叩き方、割り込み処理で行っていることの内容等詳しい説明があればもう少し具体的な話に踏み込めるのではないかと思います。

fujita nozomuさん

ご回答ありがとうございます。

割り込み処理中のmmcopyはUARTポートに”：”を出力するために1byteのコピーで使用しております。
A/D割り込みではR_ADC_StopとR_ADC_Get_Result_8bitでADCRHからデータを取得する処理を行っております。
ウォッチドッグを叩くタイミングはメインループの先頭および中間に適度に叩くようにちりばめております。
発生頻度も低く、2/28以降本日までに3/4、3/12の２回のみの発生となっております。それ以外にRESF=02H(IAWRF)のリセットも3/6、3/19に発生しており、この時のOCDトレースではmmcopyが正常終了した直後4ステップ程度に起きております。症例が少ないので何とも言えませんが、付近で発生しているのでmmcopyが疑わしいと思いました。ノイズ等H/Wに起因するものとの複合的な事象と推測しております。

ウォッチドッグタイマのオーバーフロー時間は136.53ms(2^11/fIL=15kHz)です。
メインループ一周は8～24μs（オシロスコープにて実測）、A/D割り込み処理は最長5μsです。

> 割り込み処理中のmmcopyはUARTポートに”：”を出力するために1byteのコピーで使用しております。

TXDq への書き込みに mmcopy() を使用されているということでしょうか? ちょっと理解に苦しむ使い方ですがまあ問題はないんじゃないかと思います。

> ウォッチドッグを叩くタイミングはメインループの先頭および中間に適度に叩くようにちりばめております。
発生頻度も低く、2/28以降本日までに3/4、3/12の２回のみの発生となっております。

> ウォッチドッグタイマのオーバーフロー時間は136.53ms(2^11/fIL=15kHz)です。

mmcopy() の逆アセンブルを見ると [SP+0H] の値が定期的にゼロクリアされるでもなければ無限ループになる要素がないので、mmcopy() の中で無限ループとなってウォッチドッグタイマでリセットが働く可能性は相当に低いと思います。スタック上の領域をなんかで破壊して暴走しているほうが怪しく思います。

> それ以外にRESF=02H(IAWRF)のリセットも3/6、3/19に発生しており、この時のOCDトレースではmmcopyが正常終了した直後4ステップ程度に起きております。

mmcopy() からの復帰先と、不正アクセスのアドレス、不正アクセスを行った命令の内容は確認されてますでしょうか?

> 症例が少ないので何とも言えませんが、付近で発生しているのでmmcopyが疑わしいと思いました。ノイズ等H/Wに起因するものとの複合的な事象と推測しております。

月に何度も現象が起きているのであればそれほど少ない気はしません。MCU 内部の RAM 化けであれば読み出しの際にパリティエラーも半分くらいの確率で起きてて良さそうな気がしますがそれがないのであれば RAM 化けの線はとりあえず疑わなくて良いかもしれません。

コンパイラのオプションに -Onothing と -volatile が指定されているのが気になります。CC-RL はデフォルトの動作で最適化は有効であり、それを敢えて無効化していることと、-volatile も正しく書かれているソースであれば敢えて指定しなくて良い筈のオプションですが、これらはそれぞれ意図あって指定されているものでしょうか?

fujita nozomuさん

コメントありがとうございます。

> mmcopy() からの復帰先と、不正アクセスのアドレス、不正アクセスを行った命令の内容は確認されてますでしょうか?

OCDトレースの結果は
218 N_LIB.C#69 for(i=0;i<n;i++)
218 0x09ba6 +39 BC $_mmcopy+0xf
219 N_LIB.C#69 for(i=0;i<n;i++)
219 00x9ba6 +39 BC $_mmcopy+0xf
220 N_LIB.C#71 }
220 0x09baa +43 RET
_Montx;
221 r_main.c#4851 Mwp += min;
221 0x097c4 +125 RET
_Old_MX;
222 r_main.c#2749 Node_err= 0;
222 0x0638f +1479 BR $!_Old_MX+0x65c
223 r_main.c#2781 if(pp==0)
223 0x06431 +1641 BR $!_Old_MX+0x707
224 r_main.c#2826 if(sqcc==17)&&(OnetmON==0))
224 0x06508 +1856 BR $_Old_MX+0x745
225 0x00000 CMP0 X

256 cstart.asm#62 MOVW SP,#LOWW(__STACK_ADDR_START)
256 0x000d8 +0 MOVW SP,#0FE20H

となっております。
Montx、Old_MXはメインループの関数です。
IECUBEは使用しておりませんので、OCDトレースでは分岐命令しか残せないため224がIAWRFの原因かどうかは不明です。

> これらはそれぞれ意図あって指定されているものでしょうか?

-Onothingはデバッグ優先するために指定しております。本来リリースであれば指定解除すべきと思いますが、現状不具合が起きているためデバッグ優先のままとしております。

-volatileについては、RL78ではないのですが、過去AVME-148Aを使用したOS9のプログラムで-volatileを指定しないとコンパイラが同じ名前の変数を使用している場合に最適化によりロード命令が削除されることがあったため指定しております。ソースコード内でも必要な箇所にはvolatile宣言をしているので冗長かもしれません。

> 224 0x06508 +1856 BR $_Old_MX+0x745

の次、

> 225 0x00000 CMP0 X

で既に暴走したかで 0 番地のリセットベクタの値を命令として実行していて、

> 256 cstart.asm#62 MOVW SP,#LOWW(__STACK_ADDR_START)
> 256 0x000d8 +0 MOVW SP,#0FE20H

ウォッチドッグだか不正アクセスだか不正命令だかでリセットが掛かってるよう見えるのですが、

japan.renesasrulz.com/.../ri78v4

↑で報告されている状況と似た感じなので試しに目を通されると何か参考になるかもしれません。

fujita nozomuさん

 

コメントありがとうございます。

リンク先参照させて頂きます。

先般のトレースで起きていたRESFは02H(IAWRF)です。

WDTRFが起きていた時のトレースは

_mmcopy;
0 N_LIB.C#69 for(i=0;i<n;i++)
0 00x9ba6 +39 BC $_mmcopy+0xf
1 N_LIB.C#69 for(i=0;i<n;i++)
1 00x9ba6 +39 BC $_mmcopy+0xf
...
223 N_LIB.C#69 for(i=0;i<n;i++)
223 00x9ba6 +39 BC $_mmcopy+0xf
224 N_LIB.C#69 for(i=0;i<n;i++)
224 00x9ba6 +39 BC $_mmcopy+0xf
225 0x00000 CMP0 X

256 cstart.asm#62 MOVW SP,#LOWW(__STACK_ADDR_START)
256 0x000d8 +0 MOVW SP,#0FE20H

でした。

但し、OCDトレースが採取できたのはIAWRF、WDTRF各１回のみです。

それ以前はG13(R5F100LGDFB#30)を使用していたため、トレースが採取出来ておりません。

リンク先の

>・内蔵RAMのトレースRAM領域をプログラム(カーネル側＆アプリケーション側)で使用してしまっていないか？(MAPファイルを見れば分かるかと思います。)

ですが、mapファイル上はそのようなことにはなっていないようです。

*** Mapping List ***

SECTION START END SIZE ALIGN
.vect
00000000 0000007f 80 0
.constf
00000080 00000080 0 2
.data
00000080 00000080 0 2
.sdata
00000080 00000080 0 2
.option_byte
000000c0 000000c3 4 1
.security_id
000000c4 000000cd a 1
.monitor1
000000ce 000000d7 a 1
.text
000000d8 0000031f 248 1
.RLIB
00000320 00000462 143 1
.SLIB
00000463 00000469 7 1
.const
00003000 0000318e 18f 2
.textf
0000318f 0000ad70 7be2 1
.monitor2
0007fe00 0007ffff 200 1
.dataR
000f3f00 000f3f00 0 2
.bss
000f4700 000f6032 1933 2
.sbss
000ffe20 000ffe20 0 2
.sdataR
000ffe20 000ffe20 0 2

また、スタック領域ですが、

__RAM_ADDR_START
000f3f00
__s.bss
000f4700
__e.bss
000f6033
__STACK_ADDR_END
000f6034
__s.sbss
000ffe20
__e.sbss
000ffe20
__s.sdataR
000ffe20
__e.sdataR
000ffe20
__STACK_ADDR_START
000ffe20 0001(000000da:.text)
__RAM_ADDR_END
000ffee0

となっております。

Call Walkerでスタック使用量を見積もると、

VCD-30G14.cal(272)

となっております。動的な使用量は考慮されておりませんが、十分なスタック領域があると考えております。

問題となっている事象について整理させて頂きますが、

①現場で発生しているのはRESF=02H(IAWRF)のみです。平均すると7回/月の頻度で起きておりますが、最長で28日間発生しなかったこともあります。現場ではG13(R5F100LGDFB#30)を使用しております。

②社内検証環境で発生したのはRESF=02H、RESF=10H(WDTRF)で、RESF=10Hはこれまでに２回発生しており、E1エミュレータ接続時のみに確認されております。RESF=02Hは確認している限りでは6回程度発生しております。OCDトレースを採取することで原因究明の一助となると考え、3/12からG14(R5F104LLAFB#V0)を搭載し、検証を継続したところ、3/13にRESF=10Hが発生しました。その時のトレース結果が上記のものです。その後3/21にRESF=02Hが発生し、それが昨日投稿したトレースです。日付については以前申し上げたのと若干異なっておりますが、先日は勘違でログファイルの開始日を記載してしまいました。以降現時点までリセットは発生しておりません。

③静電気試験で10kVの静電気をかけるとRESF=80H、RESF=04H、RESF=02Hが発生することがあります。毎回発生するわけではなく、何か特定のタイミングで発生するようです。

現状はリセットが発生しても即復旧してシステム上は影響が出ないよう処置を施しております。稼働(2019/5)から約１年経過しており、今のところ致命的な問題は発生しておりませんが、リセットが発生するタイミングによっては重大な被害を及ぼす可能性があります。

最初の投稿の主旨とは変わってしまっておりますが、最も解決したい問題は①の現場で発生しているIAWRFです。もちろんWDTRFが何故発生したのかも疑問ではありますが、これまで一度も現場では発生しておらず、E1エミュレータを接続したことによる副次的な問題と考えます。

これ以上の原因究明のためにはIECUBEを使用するしかないのかと考えております。

fujita nozomuさん

有償でコンサルして頂くことは可能でしょうか？

可能であればお願い致します。

投稿した後で気づいたのですが、3/13のRESF=10Hの時にメモリの内容を確認した際に、スタックエンドアドレス付近までデータが埋まっておりました。

一方mapファイルから、スタックエンド付近は

0010 r_cg_serial
SECTION=.textf

～中略～

SECTION=.bss
_gp_uart0_tx_address
000f601e 0010(0000a819:.textf)

～中略～

_g_uart1_rx_count
000f602e 0010(0000a946:.textf)
0011(0000020e:.text)
0011(0000021d:.text)
0011(00000223:.text)
_g_uart1_rx_length
000f6030 0010(0000a94b:.textf)
0011(0000020b:.text)
0011(00000220:.text)

となっております。

スタックオーバーフローが発生しているのでしょうか？

yandooさん、こんにちは。Hosです。

スタックオーバーフローが疑わしいのであれば、スタック量の使用量を調査してはいかがでしょうか。
通常のコンテキストと各割り込みのそれぞれを出して、スタック量が溢れないか検証すればよいかと思います。
CS+は使ったことがないのですが、スタック量の見積もりツールがあるのではないでしょうか。
(それが使えなければ、頑張って計算するしかないですが…)

Hosさん、こんにちは。

コメントありがとうございます。

スタック見積ツールCall Walkerでの使用量は(272)となっております。一方、mapファイルからは40,428Byteのスタック領域が確保されております。Call Walkerでは静的な最大量しか考慮されていないので、多重割り込みなどによる動的な最大量は考慮されておりませんが、約150倍の領域が確保されているので十分と考えました。

しかし、RESF=10Hの発生時に採取したスタック領域の内容を見ると、UART経由で出力しているデバッグ用モニターポートの出力情報が判読できる形で残っております。

プログラム上の何らかのバグでスタック領域がポップされないまま浸食され続けているのではないかと考えられます。

何とか少しヒントが得られたような気がします。

コメント頂いた皆様ありがとうございました。

Hosさん、こんにちは。

コメントありがとうございます。

スタック見積ツールCall Walkerでの使用量は(272)となっております。一方、mapファイルからは40,428Byteのスタック領域が確保されております。Call Walkerでは静的な最大量しか考慮されていないので、多重割り込みなどによる動的な最大量は考慮されておりませんが、約150倍の領域が確保されているので十分と考えました。

しかし、RESF=10Hの発生時に採取したスタック領域の内容を見ると、UART経由で出力しているデバッグ用モニターポートの出力情報が判読できる形で残っております。

プログラム上の何らかのバグでスタック領域がポップされないまま浸食され続けているのではないかと考えられます。

何とか少しヒントが得られたような気がします。

コメント頂いた皆様ありがとうございました。