ARM Cortex-M MCUのコード実行時間の測定

著者：Jean J. Labrosse氏、RTOSエキスパート

コードの実行時間を測定するには、多くの方法があります。組込みエンジニアであった筆者がよく使用していたのは、デジタル出力と1台のオシロスコープを用いる方法です。いずれかの出力をハイに設定してモニターするコードを実行し、その後、その出力をローに戻すだけです。もちろん、これを行うには少なからずセットアップ作業が必要となります。すなわち、未使用の出力を1つ以上見つけ、それが容易にプローブできることを確認して、そのポートを出力に設定します。コードを書込み、コンパイルして、オシロスコープをセットアップする、といった作業です。信号が出力されたら、しばらくの間モニターして最小値と最大値を確認する必要があるかもしれません。デジタルストレージスコープを使えばこのプロセスを容易に行えますが、さらに簡単な方法があります。

実行時間を測定する他の方法として、トレース対応のデバッグプローブを使うやり方があります。単にコードを実行し、トレースを観察して経過時間（デルタタイム）を計算（通常は手動で）した後、CPUサイクルをマイクロ秒に変換するだけです。しかし、トレースが示すのは1つの実行例に過ぎず、最も厳しい条件での実行時間を調べるには、更にトレースの取得と観察を続けなくてはなりません。これは非常に面倒なプロセスとなる可能性があります。

Cortex-Mのサイクルカウンタ

CoreSightデバッグポートは、Cortex-Mをベースとするほとんどのプロセッサに用意されており、CPUのクロックサイクルをカウントする32ビット自走カウンタを内蔵しています。このカウンタはDWT（Debug Watch and Trace）モジュールの一部で、これを使用することでコードの実行時間を簡単に測定できます。以下に示すコードがあれば、この便利な機能を有効化し初期化できます。

#define  ARM_CM_DEMCR      (*(uint32_t *)0xE000EDFC)
#define  ARM_CM_DWT_CTRL   (*(uint32_t *)0xE0001000)
#define  ARM_CM_DWT_CYCCNT (*(uint32_t *)0xE0001004)


if (ARM_CM_DWT_CTRL != 0) {        // See if DWT is available
    ARM_CM_DEMCR      |= 1 << 24;  // Set bit 24
    ARM_CM_DWT_CYCCNT  = 0;
    ARM_CM_DWT_CTRL   |= 1 << 0;   // Set bit 0
}

DWTサイクルカウンタを使用してコード実行時間を測定

1つのコードセグメントの実行時間を測定し計算するには、以下に示すように、そのセグメントの前後でサイクルカウンタの値を読み出します。もちろん、そのためには対象となるコードに計測器を入れる必要がありますが、得られた値は非常に正確です。

uint32_t  start;
uint32_t  stop;
uint32_t  delta;

start = ARM_CM_DWT_CYCCNT;
// Code to measure
stop  = ARM_CM_DWT_CYCCNT;
delta = stop – start;

符号なしで計算しているため、stopがstartより小さい場合でも、deltaは測定したコードの実際の実行時間（単位:CPUクロックサイクル）を表します。

もちろん、startとstopの読み出し値の間にあるコードの実行時間を測定中に、割り込みが発生することが考えられます。そのため、このシーケンスを実行するたびに値が異なる可能性は大いにあります。この場合は、以下に示すように測定中に割り込みをディスエーブルすることで割り込みによる影響を取り除く必要があります。ただし、割り込みを無効にすると測定中の割り込み遅延が大幅に減少してしまう可能性があることを意識しておく必要があります。そうは言うものの、割り込みはコードの最長実行時間に影響するため、これを含めることが有用な場合もあります。

Disable Interrupts;
start = ARM_CM_DWT_CYCCNT;
// Code to measure
stop  = ARM_CM_DWT_CYCCNT;
Enable Interrupts;
delta = stop – start;

測定対象のコードに条件文、ループなどの変動要因が含まれていた場合、得られた値が最悪実行時間を表さないことがあります。これを補正するには、以下に示すようにピークディテクタを追加すれば済みます。その場合、言うまでもなく測定の前に最大値を宣言し、最小値（つまり0）に初期化する必要があります。

start = ARM_CM_DWT_CYCCNT;
// Code to measure
stop  = ARM_CM_DWT_CYCCNT;
delta = stop – start;
if (max < delta) {
    max = delta;
}

同様に、最短実行時間を知ることも有用な場合があります。測定は最小値を宣言し、最大値（0xFFFFFFFF）に初期化してから行います。新たにコードは次のようになります。

start = ARM_CM_DWT_CYCCNT;
// Code to measure
stop  = ARM_CM_DWT_CYCCNT;
delta = stop – start;
if (max < delta) {
    max = delta;
}
if (min > delta) {
    min = delta;
}

タスク（RTOSを使用時）が待機中のイベントを実行するのに要する時間を測定することも可能です。たとえば、タスクが最長実行時間の条件を満たすかどうかを調べるとします。この場合、「Wait for ...」コードの直後、あるいは割り込みに対応してタスクが必要な処理を実際に実行した後に‘stop’コードを追加できます。どちらの値も意味あるものとなります。

void  MyISR (void) 
{
    Clear interrupt source;
    start = ARM_CM_DWT_CYCCNT;
    Notify task that interrupt occurred;
}


void  MyTask (void)
{
    Task initialization;
    while (1) {
        Wait for notification from ISR;
        stop  = ARM_CM_DWT_CYCCNT;
        delta = stop – start;
        if (max < delta) {
            max = delta;
        }
        if (min > delta) {
            min = delta;
        }
        Code to handle event;
    }
}
    
// Code to measure
stop  = ARM_CM_DWT_CYCCNT;
delta = stop – start;
if (max < delta) {
    max = delta;
}
if (min > delta) {
    min = delta;
}

実行時間は、CPUにキャッシュがあるか否かにも依存します。Cortex-M7や一部のCortex-M4プロセッサに見られるとおりです。システムが命令キャッシュやデータキャッシュを使用している場合、コードの同じセクションを何度も測定すると、結果が一致しない場合があります。キャッシュを無効化して最も厳しい条件を測定することを検討すべき場合もあります。

値を表示する際、ほとんどのデバッガはこれらの変数値をリアルタイムで表示できます。その場合、表示された変数は、その値を保持し、リアルタイムでモニタリングが可能なように、グローバルスコープで宣言する必要があります。また、残念なことにこの値が示しているのはCPUのクロックサイクルで、ほとんどのデバッガは変数を時間に変換して見やすく表示できるほど高性能ではありません。CPU速度が16MHzの場合、1123サイクルではなく70.19マイクロ秒と表示するほうがはるかに便利です。運よくCPUの動作速度が100MHzであれば、変換は簡単なのですが。

経過時間モジュール

アプリケーションにコードのスニペットを追加するか、この記事にある簡単なモジュールを使用することができます。‘elapsed_time.c’ モジュールで使われている関数は4つのみです。

 

使用方法：

•  まず、#include <elapsed_time.h>とします。
• elapsed_time_init()を呼び出してから、cで定義された他の関数を使用します。
• ELAPSED_TIME_MAX_SECTIONSを設定して、経過時間測定構造体の最大数を定義します。これは、stop/startコードでラップする必要のあるさまざまなコードスニペットの数に対応します。
• elapsed_time_start()を呼び出し、モニターするコードスニペットのインデックス（ELAPSED_TIME_MAX_SECTIONS-1）を渡します。
• elapsed_time_stop()を呼び出し、elapsed_time_start()で使用した同じインデックスを渡します。
• デバッガがリアルタイム（ターゲットが実行中）で変数をモニターできる場合は、elapsed_time_tbl[]を表示して、使用した対応するインデックスのELAPSED_TIME構造体を調べることができます。
• 手順4から6を繰り返し、最悪条件と最良条件でコードを実行することで、ELAPSED_TIME構造体の.minフィールドと.maxフィールドに、測定するコードのスニペットの実行時間が適切に表示されます。

見て分かるとおり（elapsed_time.cを参照）、測定中は割り込みを無効化していません。その理由は、ISRが含まれる可能性があり、それが測定された実行時間に与える影響を知っておく必要があるためです。

void  main (void)
{
    // Some code
    elapsed_time_init();         // Initialize the module
    // Some code
}



void  MyCode (void) 
{
    // Some code here
    elapsed_time_start(0);    // Start measurement of code snippet #0
    // Code being measured
    elapsed_time_stop(0);     // Stop and 
    // Some other code
}

もちろん最短実行時間と最長実行時間は、測定の頻度や、コードが最悪条件あるいは最良条件で実行しているかによっても左右されます。
以下に示すIAR Embedded WorkbenchのLiveWatchウィンドウのスクリーンショットは、値を未処理のまま示したものです。

elapsed_time_tbl[]は、さまざまなコードスニペットの測定結果を保存するアレイです。なお、startフィールドでは、値はアクティビティを示すのみで、それ以外の表示は制限されています（つまり値が変化している最中は、測定が実行中であることを意味します）。また、値はCPUクロックサイクル単位で表示され、残念ながらC-SPYにはこれらの値をマイクロ秒に変換するスケーリング機能がありません。

 

 

もちろん、elapsed_time.*モジュールに改良を加えることは可能です。追加が可能な機能を以下に示します。作業が簡単になるようにプロトタイプ、変数、構造体メンバーを追加しました。必要に応じてコードを実装してください。

• 最長実行時間が閾値（.threshold）を超えた場合に呼び出されるコールバック関数を追加。そのような状態になったときに直ちに通知を受けとる（LEDの点灯、アラーム音など）必要がある場合に便利です。実際は、閾値を超える原因となった条件が何かを調べる必要が生じた場合に、ブレークポイントを設定しておくことも可能です。.callback_ptr memberをELAPSED_TIMEに追加してください。
• チャンネルごとに測定をイネーブル／ディスエーブルできるようにBooleanを追加。これにより、コードに計測器を入れて、どの測定を有効または無効にするかを決定できます。.enableなどの構造体メンバーをELAPSED_TIME構造体に追加できます。デバッグ時に、C-SPYを使用して.enableを1（イネーブル）または0（ディスエーブル）に設定できます。あるいは、APIを呼び出しても同じことが可能です。
• サイクルからマイクロ秒への変換に使用できるCPUクロック周波数（elapsed_CPU_clock_frequency）を指定するために、モジュールにグローバル変数を追加。必要なのは、elapsed_time_stop()で各種フィールド（.current、.min、.max）をelapsed_CPU_clock_frequencyで除算することだけです。ゼロ除算とならないように、この変数は必ずゼロ以外の値に初期化してください。