マイコンカーラリー printfデバッグ (5) 割り込み周期の確認

printfデバッグで原因が判って問題は解決しましたが、制御ループが正確なタイミングで実行されていないと制御が不安定になる原因になりますので、タイマ割り込みと制御ループの実行間隔を調べて見ました。

(4)のtimeに表示されている数値は1ms毎の割り込み関数でインクリメントされているので正確に増えていますが実際には消去関数は130mS程度割り込みを禁止しているのでその間は実際の周期は狂っているはずです。

そこで今度はタイマーRFを使って割り込み関数の起動タイミングを調べてみます。

init()の最後に次の処理を追加してタイマRFを20MHz/32のクロックでインクリメントします。
本当ならばもっときりの良いクロックを使いたかったのですが空いているタイマーの制約上このようなクロックを使うことになりました。

 /* タイマ 時間 計測 */
 trfcr0 = 0x05; /* f32 フリーランカウント開始 */

タイマRFが0-0xFFFFまでカウントアップする時間は 約(1/9.5)秒、およそ0.1秒です。

次のようにタイマ関数の先頭にprintf文を入れてタイマRFの値を表示してみます。

/************************************************************************/
/* タイマRB 割り込み処理 */
/************************************************************************/
#pragma interrupt /B intTRB(vect=24)
void intTRB( void )
{
   static int line_no; /* 行番号 */
   unsigned int i;

   asm(" fset I "); /* タイマRB以上の割り込み許可 */

#ifdef DEBUG
   printf("%04X\n",trf); // TRF 表示 20/32 MHzクロック 
#endif
   uTimer1ms++; // 時間計測用タイマ
   cnt0++;
   cnt1++;
   cnt2++;
   cnt_lcd++;
   check_sen_cnt++;
   check_enc_cnt++;

   ...

実行結果は次のようになります

これをグラフ表示で見ると次のように周期的に間隔が乱れているのが判ります。

間隔の乱れているところを拡大してみると次のようになっています。

縦軸がタイマの値で横軸はデータの数です、タイマの値は16bitで65535を超えると0に戻るためノコギリ波のような形になります、真ん中の大きい段がDataFlashの消去で割り込みが止まっている時でおよそ(57+105×n)mS止まっています。
ここで57mSはグラフから読み取れる値で、105mSはTRFがタイムアウトする時間です。
DataFlash消去中はデータも出力されないためその間に何度TRFがタイムアウトしているかはわかりません。
止まっている時間を正確に知りたければ例えば10KHzクロックでカウントアップするタイマがあれば6.5秒までは測れることになります。
手がかりとしてdata_flash_lib.cのソースに次のような記述があります。

/************************************************************************/
/* モジュール名 blockEraseDataFlash */
/* 処理概要 ブロックイレーズ */
/* 引数 unsinged int アドレス */
/* 戻り値 1:エラーなし 0:エラーあり */
/* メモ 実測で135ms程度 */
/************************************************************************/
int blockEraseDataFlash( unsigned int address )
{
   volatile int ret = 1;
   volatile int block;

   block = checkBlockAddress( address );
   if( block == -1 ) return 0;

   asm( "FCLR I" ); /* 全体の割り込み禁止 */
   
   ...

これを考慮すれば n=1で 162mSの間割り込みが止まっていると考えるのが妥当でしょう。

両側の小さい段は書き込みの時で書き込みの時も割り込み禁止期間があり数ミリ秒は割り込みが止まるようです。

マイコンカーラリーではロボットが高速走行します。
例えば2m/秒の速度で走っているとすれば2mm / 1msの間隔で制御をしていますが、162mS制御不能になればその間に 2mm × 162 = 324mm 進んでしまうことになります。
カーブ等で324mmの間制御が止まればコースアウトは確実です。

 

次にメインループの先頭にtrfを表示するprintfを入れてメインループの実行間隔も確認してみます。

while( 1 ) {
   // デバッグ表示
#ifdef DEBUG
   printf("%04X\n",trf); // TRF 表示 20/32 MHzクロック
#endif
   // LCD表示、パラメータ設定処理
   lcdProcess();
 
   ...

結果のグラフ表示は次のようになりました

当然ですがこちらも同じように制御周期が乱れています。
拡大してみます。

メインループの周期はノコギリ波の周期とその間のデータ数から求められます。
ノコギリ波の1周期は105msでその間におよそ120のデータが出力されていますから、105/120=約0.9msとほぼ割り込みと同じ周期でメインループが繰り返されていることがわかります。。

 

 

 

 

 

マイコンカーラリー printfデバッグ (4) トラブル原因の特定

printfデバッグの実行

準備ができたのでデバッグ文を入れたプログラムをボードに書き込み実行してみると次のような結果になりました。

なんと50ms毎にwriteDataFlashが呼び出されて32回毎にDataFlashの消去が行われています。
データフラッシュの耐久性は1万回の消去までOKとなっています。
実際はかなりマージンがあるはずなので2万回が寿命と考えて2万回×32=32万回のデータ消去で寿命を迎えてデータエラーが発生するようになります。
時間にすると1.6秒×32万回=512000秒=142.2時間になり、如何に熱心に練習されているかがこのデータから読み取れます。

writeDataFlash関数が呼ばれているところをファイル検索で調べるとメインループの中とメインループから呼び出された関数lcdProcessの中でスイッチを押した時に呼ばれるようになっています。

で、次のようにしてメインループの最初でスイッチの値を表示してみました。

while( 1 ) {
   // デバッグ表示
#ifdef DEBUG  スイッチ状態の表示
   printf("pushsw_get()=%d, SW_1=%d, SW_2=%d, SW_3=%d, SW_4=%d\r\n",
          pushsw_get(), getSwFlag(SW_1), getSwFlag(SW_2), getSwFlag(SW_3),       getSwFlag(SW_4));
   // printf("%04X\n",trf); // TRF 表示 20/32 MHzクロック
#endif
   // LCD表示、パラメータ設定処理
   lcdProcess();  <== この中で呼ばれる

   ...
   ...
   switch( pattern ) {
     case 0:
       /* プッシュスイッチ押下待ち */
       servoPwmOut( 0 );
       if( pushsw_get() ) {
           writeDataFlashParameter(); // パラメータ保存  <== ここで呼ばれる

   ...

プログラムを実行すると次の結果が表示されました

SW_4だけが時々ONになっています、SW_4は同じ信号線を使ってLCDの表示とスイッチの読み込みを兼ねているのでハードウェアとの相性かソフト的な原因でこのようなことが起こっていると思われます。
SW_4の動作を修正することが目的ではなくpushsw_get()が押された時だけwriteDataFlash関数を呼び出すようにすれば実用上問題無いのでSW_4誤動作の件は無視してlcdProcessの中の呼び出しを削除するようにアドバイスしました。

 

マイコンカーラリー printfデバッグ (3) printf文を埋め込む

相談を受けたのは「マイコンカーラリーのプログラムでデータフラッシュにパラメータを保存しているが、最近パラメータが壊れるようになって困っている。」ということでした。

マイコンカーラリー競技は白線を引いたコースで走行タイムを競う競技で、現在は工業高校の先生・生徒が中心となって盛り上がっています。

プログラムは「JMCR実行委員会 &株式会社日立ドキュメントソリューションズ
」が提供しているテンプレートを基にして各参加者が改造・修正して作っています。

そのため、プログラム構造はしっかりしていて第三者が見ても判り易く出来ていますが、プログラムソースを見てもどうしてそのようなことが起きているのか原因を見つけることが出来ませんでした。

そこでprintfデバッグを使えるようにして問題の原因を探ることにしました。

まず、main関数の最初にUART0の初期化を挿入します。

void main( void )
{
 int i, ret;
 char fileName[ 8+1+3+1 ]; /* 名前+'.'+拡張子+'\0' */
 unsigned char b;

/* マイコン機能の初期化 */
 init(); /* 初期化 */
 setMicroSDLedPort( &p6, &pd6, 0 ); /* microSD モニタLED設定 */
 /* uart0 初期化 */
 init_uart0_printf(SPEED_9600);
 uart0_setbps(1250000);
 //for(;;) printf("Hello World. \r\n");
 /* 全体の割り込み許可 */
 asm(" fset I "); 
 ..
 ..

関数 init_uart0_printf(SPEED_9600)  はprintf_lib.cに含まれています。
この関数で設定できる通信レートは最高38400bpsなので、とりあえず9600bpsで初期化しておきます。
次にuart0_setbps(1250000)で設定できる最高スピードの1250000に再設定します。

uart0_setbps(long bps)は次のようになっています。

/*******************************************************************************
* uart0ボーレート設定
* init_uart0_printf()の後にこの関数を実行する
*******************************************************************************/
void uart0_setbps(long spd)
{
 int brg;
 
 brg = (1250000L * 10 / spd + 5) / 10 - 1; 
 /* UART0の設定 */
 u0sr = 0x05; /* P14=TXD0,P15=RXD0に設定 */
 u0c0 = 0x00; /* カウントソース=20MHz */
 u0c1 = 0x05; /* 送信、受信許可 */
 u0brg = brg; /* 通信速度 = brg */
 u0mr = 0x05; /* UART0 データ長8bit 1ストップビット */
}

uart0_setbps(long spd)の引数spdには任意の値を設定できますが通信相手が対応できる速度に対して誤差が大きくならないように注意する必要があります。

R8C/38Cマイコンのボーレートレジスタu0brgに設定した値をbrgとすると 通信速度は

20000000 / 16  / (brg  + 1)で求めることができます。

brgには0から255までの任意の値を設定可能ですが通信相手の速度に対して最大10%以内の誤差、実用的には5%以下の誤差でないと安定した通信ができません。

brg = 0 の時は 20000000 / 16 / 1 =1250000となり最高スピードでUSBシリアルのICも1250000bpsに対応していますからこの時は誤差0%となります。

printfをサポートする関数が printf_lib.c に用意されていますのでこれだけでprintf()からの出力がUART0から出力されUART0にUSBシリアルで接続したPCのターミナルソフトで表示できるようになります。

次にDataFlash書き込み関数にprintf文を埋め込みます。

/* DataFlash関連 */
#define DF_ADDR_START 0x3000 /* 書き込み開始アドレス */
#define DF_ADDR_END 0x33ff /* 書き込み終了アドレス */

#define DF_PARA_SIZE 32 /* DataFlashパラメータ数 */

#define DEBUG

/************************************************************************/
/* DataFlashへパラメータ書き込み */
/* 引数 なし */
/* 戻り値 なし */
/************************************************************************/
void writeDataFlashParameter( void )
{
  unsigned int st = DF_ADDR_START;
  signed char c;

  while( 1 ) {
    // 書き込む番地を探す
    readDataFlash( st, &c, 1 );
    if( c == -1 ) {
      writeDataFlash( st, data_buff, DF_PARA_SIZE );
#ifdef DEBUG
      printf("writeDataFlash.. st=%u, time=%d\r\n", st, iTimer1ms);
#endif
      break;
    }

    st += DF_PARA_SIZE;

    if( st > DF_ADDR_END ) {
      // すべて使用したら、イレーズして先頭に書き込み
      blockEraseDataFlash( DF_ADDR_START );
      writeDataFlash( DF_ADDR_START, data_buff, DF_PARA_SIZE );
#ifdef DEBUG
      printf("writeDataFlash.. (EraseData) st=%u, time=%d\r\n", st, iTimer1ms);
#endif
      break;
    }
  }
}

データを保存するDataFlashは0x3000から0x33FFの1Kバイトで書き込みはバイト単位でおこなえるのですが消去は1Kバイトブロックの一括消去になります。
それで32バイトづつ書き込んで一杯になったらブロック消去をおこない、また先頭から書き込んでいくという繰り返しをおこなっています。

データフラッシュの書き込み制限回数は10000回ですがこれは10000回の消去が可能という意味なのでこの関数のような使い方をすれば1024/32*10000の32万回のデータ保存が可能ということになります。