GPIOピンを使用してオシロスコープでタイミングを観測する手法は、もちろん有効かつ現実的なアプローチです。しかし、MCUや開発ツールが提供する機能を使用すれば、より簡単かつ精密に実行時間を計測することができます。
本記事では、Cortex-M3/M4デバイスとIAR Embedded Workbench for ARMを使用してコードの実行時間を測定するための3つの基本的なテクニックと応用テクニックをいくつか紹介します。
そこまで正確さを求めず簡単に計測をしたいときに、ログブレークポイントが有用です。ログブレークポイントをセットされたコードが実行されると、使用しているコンピュータの時間がデバッグログウィンドウに表示されます。
実行時間を知りたいコード上で右クリックして、ブレークポイントの切り替え(ログ)を選択.
Lと記載されたブレークポイントが表示されます。
このコードは1秒ごとに実行されるTimer割込みハンドラです。実行結果はデバッグログウィンドウに、下記のように出力されます。
実行時の時間、該当のソースコードおよび、呼ばれた回数が表示
このテクニックは、精度の必要な計測には不向きですが、簡単に計測したい場合には最適な手法です。たとえば同じ処理のループを数千回回して前後の時間を比較する、といった使い方も可能です。
近年のMCUでは実行時間を取得するためのレジスタを搭載していることがあります。ARM Cortex-M3/4/7デバイスではCYCLECOUNTERというレジスタを搭載しています。
コードの2点のCYCLECOUNTERの値を取得しCPUクロック周波数を使って計算をすることで、実処理時間を求めることができます。たとえば、CPUが100MHzで動いている場合、100,000,000(1億)で割ることで、実際に経過した秒数を求めることができます。
IAR Embedded Workbench for ARMはCYCLECOUNTERを独自に拡張しています。前回表示時のCYCLECOUNTERとの差分をCCSTEPレジスタで簡単に確認することができます。
レジスタウィンドウを開きます。
CPUレジスタを選択します。
CYCLECOUNTERは開始時からの経過サイクルを示します。CCSTEPは前回の表示からの差分サイクルを示します。
ステップオーバをクリックすることで、CYCLECOUNTERの増加と、その増加サイクルがCCSTEPに表示されます。
424(Current CYCLECOUNTER) – 416(Previous CYCLECOUNTER) = 8(Current CCSTEP)
CYCLECOUNTERはARM Cortex-M3/4/7 MCUで提供されていますが、IAR Embedded Workbenchではデフォルトで無効になっています。I-jetを使用する場合、CYCLECOUNTERは自動的に有効になります。その他のエミュレータ(ICE)を使用していてCYCLECOUNTERの値が更新されない場合、Data Watchpoint and Traceレジスタカテゴリの中のDWT Controlレジスタ、CYCNTENAビット(DWT_CTRL.CYCNTEN)を1にセットにしてください。
CYCLECOUNTERは簡単に使用できて、正確に測定することが可能です。実時間が必要な場合はCPUクロックで割ることで求めることができます。CYCLECOUNTERはパイプラインやキャッシュの状態によって差が生じる可能性があります。1命令、2命令単位ではなく数十命令単位以上で使用することを推奨します。
タイマーはMCUに指定時間で処理をさせるために重要な機能です。タイマーのカウントアップ/カウントダウン割込みを使用することが多くありますが、カウント値を読むことで実行時間の計測をすることも可能です。
最初に確認するのは、クロックソースとプリスケーラです。プリスケーラが10であれば、クロックソースの10サイクルごとに、タイマー値がカウントアップ・ダウンされます。クロックソースがCPUクロックと一緒で、たとえばプリスケーラが1000でCPUクロックが100MHzであれば、タイマーカウントが100のときに0.001秒、つまり1msが経過時間として求められます。
unsigned int cnt1 = 0;
unsigned int cnt2 = 0;
cnt1 = TIM3->CNT;
func();
cnt2 = TIM3->CNT;
printf("cnt1:%u cnt2:%u diff:%u \n",cnt1,cnt2,cnt2-cnt1);
以下のように結果が出ます。
cnt1:370 cnt2:740 diff:370
タイマーを他の機能でも使用していた場合、割込みが発生した際にカウントはリセットされてしまいますので、計測専用にタイマーを使用することを推奨します。コード実行がブレークポイントなどで停止しているときでもタイマーのカウントは実行されていることがあります。したがって、値は変数などに取得しておく必要があります。
なお、ARM Cortex-M共通のSystickTimerは、CPUが停止中はカウントを停止します。これにより、時間の計測を手軽に行うことができるため、CYCLECOUNTERレジスタを搭載していないCortex-M0/M0+ MCUでは特に有効な手段です。
データログブレークポイントはARM Cortex-M3/M4デバイスの持っている便利なデバッグ機能の一つです。SWD/SWOをサポートしている、I-jetなどのICE(エミュレータ)を使用することで、データアクセスのログを取ることができ、またタイムスタンプをリアルタイムに取得することが可能です。
デバッグを開始する前にICEの設定をSWDとSWOを使用するように指定します。
サンプルコード:
static int data_main = 0;
static int data_systick = 0;
void Delay(Int32U Dly)
{
for(volatile Int32U j = Dly; j; j--) { }
}
void SysTick_Handler(void)
{
data_systick += 10;
}
void main(void)
{
SystemInit();
SysTick_Config(900000);
SysTick_CLKSourceConfig(SysTick_CLKSource_HCLK_Div8);
while(1)
{
Delay(100000);
data_main++;
}
}
mainループでは data_main 変数が一定のディレイごとにインクリメントされます。SysTick 割込みハンドラでは data_systick 変数をインクリメントしています。データログブレークポイントを使用することで、変数の値とタイミングを見ることができます。
エディタ画面のdata_main 変数の上で右クリックして ’data_main’のデータログブレークポイントを設定 を選択します。
data_systick についても同様にデータログブレークポイントを設定します。
C-SPYデバッグセッションを開始します。
データログブレークポイントはエディタ画面に表示されません。
データログブレークポイントを確認するには 表示->ブレークポイント を選択してください。
リストウィンドウ内で、データログブレークポイントを確認できます。
データログは、デフォルトでは無効になっています。有効にするために、データログウィンドウを開きます。 (I-jet/JTAGjet > データログ)
ウィンドウ内で右クリックして 有効化 を選択します。
サイクルベースのカウントで確認することも可能です。
'data_main' W:12 と'data_main' W:13のデータを見てみると、差分は866,768サイクルであることがわかります。つまりDelay(100000)はおよそ866,768サイクルだと見なすことができます。
元々、データログはデータアクセスをトレースするための機能ですが、このようにコード実行やタイミングのトレースへの適用も実用的なアプローチです。
イベントログは、ARM Cortex-M3/M4のもう一つのデバッグ機能です。アプリケーション中にイベントコードを追記することで、そのコードが実行されるごとにイベントログが生成されます。
データログのテストコードを少し修正します。
static int data_main = 0;
static int data_systick = 0;
#include <arm_itm.h>
void Delay(Int32U Dly)
{
for(volatile Int32U j = Dly; j; j--) { }
}
void SysTick_Handler(void)
{
data_systick += 10;
ITM_EVENT32_WITH_PC(2,data_systick);
}
void main(void)
{
SystemInit();
SysTick_Config(900000);
SysTick_CLKSourceConfig(SysTick_CLKSource_HCLK_Div8);
while(1)
{
Delay(100000);
data_main++;
ITM_EVENT32_WITH_PC(1,data_main);
}
}
イベントログを使用するためにarm_itm.hファイルをインクルードする必要があります。
ITM_EVENT32_WITH_PC は上記ヘッダファイルで定義されているマクロで、最初の引数がチャンネル、2つ目の引数がデータとなります。データは定数かあるいは変数を指定します。チャンネルは1から4のいずれかを指定します。
デバッグ画面でイベントログを使用するために、イベントログウィンドウを開き有効化します。
イベントログウィンドウを右クリックし 有効化 を選択します。
準備ができたのでアプリケーションを実行してみます。イベントログデータが取得されます。
チャンネル1で指定したデータはITM1列に、チャンネル2で指定した変数はITM2列に表示されます。
値だけでなく、マクロコード実行時のプログラムカウンタやタイムスタンプも取得できます。
サイクル単位で表示することも可能です。
ITM1の56と57の間は48,541,271 – 47,674,478 = 866,793となります。この数値は、データログで確認したものとほぼ同じ数値となります。
イベントログのデータはテキストファイルで保存でき、後から解析することが可能です。
データログとイベントログは、同一時間軸を使用しタイムラインウィンドウ内でで表示させることが可能です。データアクセスやITMイベントがどのようなタイミングで発生し、時差がどの程度かを計測することもできます。
I-jet /JTAGjet > タイムラインウィンドウ を開きます。
タイムラインウィンドウ内にいくつかの項目が表示されます。データログのペインと、イベントのペインを右クリックし 有効化 を選択します。
時間軸のスケールは、ウィンドウ内を右クリックし ズーム から選択可能です。
これで、データログのデータとITMイベントのデータをタイムスタンプ情報とともに可視化することができます。
データ上にマウスオーバーすると、詳細な時間情報を見ることができます。
時間範囲を選択することで、該当範囲の時間情報を取得することも可能です。
コードパフォーマンスの最適化に取り組む前に、測定環境を整える必要があります。経過時間を測定するためには、汎用的なテクニックとMCU特有のテクニックが存在します。 この記事で紹介したテクニックを参考にすることで、皆さんの評価環境やデバッグ目的に合わせた測定方法を構築することが可能です。ここで紹介した機能の詳細についてはIAR Embedded WorkbenchのヘルプメニューからC-SPYデバッグガイドを参照してください。