Arduinoでのウォッチドグタイマの発生原因を特定する

#はじめに
ウォッチドグタイマは、もしハングアップしても致命傷にならないようにするのに大変便利な機能です。でも、開発中にウォッチドグタイマによるリセットがかかった時、どこに原因があるのかを特定しておくのは大変重要です。
今回Arduino（ATMEGA1284）でウォッチドグタイマをいじることがあったので、ウォッチドグタイマの発生源を特定する方法をいろいろ試行錯誤したので、そのまとめです。
#動作環境
最初はArduino MEGAでざっとの構築を行い、その後Atmega1284を使った基板を起こしそこで最終デバッグを行いました。
開発環境はArduino 1.8.5を使いました。
他のATMEGAを搭載したArduinoやATMEGAでも使える手法だと思いますが、確認していないのでもしこの方法で確認出来たらコメントいただけると皆さんの役に立てるかと思います。
#どうやって原因を特定するか？
ウォッチドグタイマは一定時間内にwdt_reset();を呼ばないと割込みがかかり、その割込みでリセットをかけるという仕組みです。ですので、ウォッチドグタイマの割り込みルーチンで、そのリターンアドレスを記録しておけば、どこで割込みがかかったかが特定できます。
探してみたら、[per1234/WatchdogLog https://github.com/per1234/WatchdogLog](https://github.com/per1234/WatchdogLog)にありました。
ここからWatchDogLog.cpp, WatchDogLog.hを対象のプロジェクトフォルダに入れて

```watchdogtest.ino
#include "WatchdogLog.h"

const unsigned int EEPROMaddress = 0;               // EEPROMのこのアドレスからスタックが書き込まれる

void setup()
{
  Serial.begin(115200);
  while (!Serial) {};

  ...何かの処理...

  unsigned long programAddress;
  EEPROM.get(EEPROMaddress, programAddress);
  if (programAddress > 0) {
    Serial.println(programAddress, HEX);
    programAddress = 0;
    EEPROM.put(EEPROMaddress, programAddress);      // 記録していたスタックアドレスをゼロクリア
  }

  ...何かの処理...

  wdt_enable(WDTO_8S);    // 8秒間隔でのwatch dog timer
  WatchdogLog.begin(0);   // ここでは０だが保存すべきEEPROMのオフセットを指定します。
}

void loop()
{
  ...何かの処理...
  wdt_reset();            // 8秒以上にならないように、必要な場所に入れておきます
}
```

とすれば、ウォッチドグタイマの発動した場所がprogramAddressとなるので簡単にわかります。
#programAddressってどこ？
簡単にわかるといいながら、その場所ってどこなのでしょう。
まず、Arduino IDEのファイル － 環境設定 で設定タブの　「より詳細な情報を表示する」－「コンパイル」にチェックを入れます。その状態でコンパイルをすると、いっぱいメッセージが表示されますが

```log
"C:\Users\(ユーザ名)\AppData\Local\Arduino15\packages\arduino\tools\avr-gcc\4.9.2-atmel3.5.4-arduino2/bin/avr-objcopy" -O ihex -R .eeprom  "C:\Users\(ユーザ名)\AppData\Local\Temp\arduino_build_611234/watchdogtest.ino.elf" "C:\Users\(ユーザ名)\AppData\Local\Temp\arduino_build_611234/watchdogtest.ino.hex"
次のフォルダのライブラリSPIバージョン1.0を使用中：C:\Users\(ユーザ名)\AppData\Local\Arduino15\packages\arduino\hardware\avr\1.6.21\libraries\SPI 
次のフォルダのライブラリEthernet2バージョン1.0.4を使用中：C:\USR\SRC\Arduino\arduino-1.8.5\Arduino\libraries\Ethernet2 
次のフォルダのライブラリNTPClientバージョン3.1.0を使用中：C:\USR\SRC\Arduino\arduino-1.8.5\Arduino\libraries\NTPClient 
次のフォルダのライブラリEEPROMバージョン2.0を使用中：C:\Users\(ユーザ名)\AppData\Local\Arduino15\packages\arduino\hardware\avr\1.6.21\libraries\EEPROM 
次のフォルダのライブラリWireバージョン1.0を使用中：C:\Users\(ユーザ名)\AppData\Local\Arduino15\packages\arduino\hardware\avr\1.6.21\libraries\Wire 
最大131072バイトのフラッシュメモリのうち、スケッチが47978バイト（36%）を使っています。
最大16384バイトのRAMのうち、グローバル変数が1086バイト（6%）を使っていて、ローカル変数で15298バイト使うことができます。
```

見るべきところは、"C:\Users\(ユーザ名)\AppData\Local\Temp\arduino_build_611234/watchdogtest.ino.elf"のところで、まず要はこのelfファイルをコピーしてきます。
そして、次のバッチファイルを作っておいて実行します。

```DisAssemble.cmd
(Arduino IDEのインストールしてある場所)\hardware\tools\avr\bin\avr-objdump.exe -I watchdogtest.ino -d -S -j .text .\watchdogtest.ino.elf > watchdogtest.asm
```

とすれば、逆アセンブルした watchdogtest.asm が出来上がります。
アセンブラなんかわからないという人もいるでしょうが、大丈夫です。ソースファイルが埋め込まれているので大体わかります。

で表示されたアドレスが4525(16進)だったとして、4525なんてASMファイルの中にないのです！
Atmegaシリーズのアセンブリコードはワード毎に置くようになっているのでそれを1/2して記録されるようになっています。ですので128KBまでのフラッシュメモリのCPUであれば2バイトで表現できてしまいます。（128kB以上のCPUは使ったことがないのでわかりません）
ということで、実際のアドレスは4525x2=8a4aとなります。
この部分のコードがどうなっているかというと

```watchdogtest.asm
    8a28:	08 95       	ret

00008a2a <delay>:
    8a2a:	8f 92       	push	r8
    8a2c:	9f 92       	push	r9
    8a2e:	af 92       	push	r10
    8a30:	bf 92       	push	r11
    8a32:	cf 92       	push	r12
    8a34:	df 92       	push	r13
    8a36:	ef 92       	push	r14
    8a38:	ff 92       	push	r15
    8a3a:	6b 01       	movw	r12, r22
    8a3c:	7c 01       	movw	r14, r24
    8a3e:	0e 94 f0 44 	call	0x89e0	; 0x89e0 <micros>
    8a42:	4b 01       	movw	r8, r22
    8a44:	5c 01       	movw	r10, r24
    8a46:	c1 14       	cp	r12, r1
    8a48:	d1 04       	cpc	r13, r1
    8a4a:	e1 04       	cpc	r14, r1
    8a4c:	f1 04       	cpc	r15, r1
    8a4e:	01 f1       	breq	.+64     	; 0x8a90 <delay+0x66>
    8a50:	0e 94 db 4e 	call	0x9db6	; 0x9db6 <yield>
    8a54:	0e 94 f0 44 	call	0x89e0	; 0x89e0 <micros>
```

となって、8a4a:の行のところから、さかのぼって ret が出てくる行の次の<delay>関数内でタイムアウトしたということがわかります。
めでたし、めでたし。

と言いたいところですが、実はこれでは何も情報を得られません。
何故なら、あちこちからdelayは呼ばれているので有益な情報になっていないのです。
実際、何度かウォッチドグが発生した経験からは、delay,yield,microsの中で最初のアドレスが見つかることがほとんどでした。まあ、実際delayさせているので、その中で見つかる可能性は大でしょう。
#ではどうするか？
ならば、さらにさかのぼって調べてやればいいのです。
ということでWatchDogLog.cppの改造です。標準では2バイト分でしたが、32バイト分記録するようにしました。

```WatchDogLog.cpp
ISR(WDT_vect, ISR_NAKED) {
  register uint8_t *programCounter;
  programCounter = (uint8_t*)SP;
//  programCounter += programCounterSize;
  WatchdogLog.writeLog(programCounter);
}

void WatchdogLogClass::writeLog(uint8_t *programCounter) {
  wdt_disable();
  uint8_t *_sp = programCounter;
  uint16_t p = EEPROMbaseAddress;
  for(int i = 0; i < 32; i++) {
    uint8_t v = *++_sp;
    EEPROM.write(p++, v);
  }
  wdt_enable(WDTO_15MS);
  while (true) {};
}
```

元のコメントは長くなるので省いています。


```watchdogtest.ino
#include "WatchdogLog.h"

const unsigned int EEPROMaddress = 0;               // EEPROMのこのアドレスからスタックが書き込まれる

void setup()
{
  Serial.begin(115200);
  while (!Serial) {};

  ...何かの処理...

  unsigned long programAddress;
  EEPROM.get(EEPROMaddress, programAddress);
  if (programAddress > 0) {
    uint8_t c;
    for(int i = 0; i < 32; i++) {
      c = EEPROM.read(EEPROMaddress + i);
      String s = String(c, HEX);
      if (s.length() == 1)
        s = "0" + s;
      Serial.print(s);
      Serial.print(" ");
      programAddress = 0;
      EEPROM.put(EEPROMaddress, programAddress);      // 記録していたスタックアドレスをゼロクリア
    }
  }

  ...何かの処理...

  wdt_enable(WDTO_8S);    // 8秒間隔でのwatch dog timer
  WatchdogLog.begin(0);   // ここでは０だが保存すべきEEPROMのオフセットを指定します。
}

void loop()
{
  ...何かの処理...
  wdt_reset();            // 8秒以上にならないように、必要な場所に入れておきます
}
```

こうすると、さらに上までさかのぼれます。
#実際にさかのぼってみた
実際に出たエラーの例として、

```
45 25 01 ce 00 50 00 02 00 02 36 86 3f a0 3f d0 40 00 eb 2a 72 5a 02 31 d4 c7 3b fe 96 85 54 f9
```

の様に出力されるのですが、先ほどと同じように45 25 は4525x2=8a4aとなります。そこから上に進んでいって ret が出てくる行の次が今いる関数です。

```watchdogtest.asm
    8a28:	08 95       	ret

00008a2a <delay>:
    8a2a:	8f 92       	push	r8
    8a2c:	9f 92       	push	r9
    8a2e:	af 92       	push	r10
    8a30:	bf 92       	push	r11
    8a32:	cf 92       	push	r12
    8a34:	df 92       	push	r13
    8a36:	ef 92       	push	r14
    8a38:	ff 92       	push	r15
    8a3a:	6b 01       	movw	r12, r22
    8a3c:	7c 01       	movw	r14, r24
    8a3e:	0e 94 f0 44 	call	0x89e0	; 0x89e0 <micros>
    8a42:	4b 01       	movw	r8, r22
    8a44:	5c 01       	movw	r10, r24
    8a46:	c1 14       	cp	r12, r1
    8a48:	d1 04       	cpc	r13, r1
    8a4a:	e1 04       	cpc	r14, r1
    8a4c:	f1 04       	cpc	r15, r1
    8a4e:	01 f1       	breq	.+64     	; 0x8a90 <delay+0x66>
    8a50:	0e 94 db 4e 	call	0x9db6	; 0x9db6 <yield>
    8a54:	0e 94 f0 44 	call	0x89e0	; 0x89e0 <micros>
```

で、次のアドレスを計算するのですが、ret の次に push がいっぱい(8個)並んでいます。このpushの数だけ飛ばして次は 36 86 になります。3686x2=6d0c

```watchdogtest.asm
    6d00:	61 e0       	ldi	r22, 0x01	; 1
    6d02:	70 e0       	ldi	r23, 0x00	; 0
    6d04:	80 e0       	ldi	r24, 0x00	; 0
    6d06:	90 e0       	ldi	r25, 0x00	; 0
    6d08:	0e 94 15 45 	call	0x8a2a	; 0x8a2a <delay>
    if (status() == SnSR::CLOSED) {
    6d0c:	ce 01       	movw	r24, r28
    6d0e:	0e 94 24 36 	call	0x6c48	; 0x6c48 <_ZN14EthernetClient6statusEv>
    6d12:	ea cf       	rjmp	.-44     	; 0x6ce8 <_ZN14EthernetClient7connectE9IPAddressj+0x84>
      _sock = MAX_SOCK_NUM;
      return 0;
    }
```

6d0c:の前の行に call \<delay\> とありますね。つまり、delayを呼び出したのがそのcallで戻り先が6d0c:ということなのです。
同じように、ret が出てくるまでさかのぼると。

```watchdogtest.asm
    6c60:	80 e0       	ldi	r24, 0x00	; 0
    6c62:	08 95       	ret

00006c64 <_ZN14EthernetClient7connectE9IPAddressj>:
  } else {
    return ret;
  }
}

int EthernetClient::connect(IPAddress ip, uint16_t port) {
    6c64:	cf 92       	push	r12
    6c66:	df 92       	push	r13
    6c68:	ff 92       	push	r15
    6c6a:	0f 93       	push	r16
    6c6c:	1f 93       	push	r17
    6c6e:	cf 93       	push	r28
    6c70:	df 93       	push	r29
  if (_sock != MAX_SOCK_NUM)
```

と int EthernetClient::connect(IPAddress ip, uint16_t port) 関数内から呼ばれたとわかります。今回はここまで特定できれば十分だったのですが、さらにさかのぼる必要があれば繰り返せば大丈夫です。
その場合、保存するEEPROMの領域も広げておく必要があります。

※スタックのダンプリストは、実際の物をちょっといじってあります。もし、矛盾があったら、ごめんなさい。