rp2040で実行時間を測定する

1. 概要

処理時間を計測する場合、一般的には時間取得APIの分解能が（多くはμsの単位であるため）制限されているため、以下のような方法が用いられます。

1. 開始時刻を取得する
2. n回の処理を実行する
3. 終了時刻を取得する
4. 終了時刻から開始時刻を引き、繰り返し回数nで割ることで、処理一回あたりの時間を求める

しかし、より高い分解能が必要な場合は、ハードウェアに依存した方法で実現する必要があります。
例えば、Cortex-MにはDWT（Data Watchpoint and Trace Unit）というカウンタがあり、CPUクロック単位で処理時間を計測することができます。ただし、rp2040にはDWTが搭載されていないため、CPUクロック単位での測定方法を調査し、実装してみました。

2. SysTickタイマのレジスタを利用

処理時間の計測には、いくつかの候補となるタイマがありますが、既にタイマとして利用されており、新たな資源を必要としないことから、SysTickタイマを使用することにしました。
SysTickタイマは、Cortex-M系のプロセッサに標準的に装備されており、周期的な割り込みを発生させるために使用されています。通常、SysTickタイマの入力クロックはCPUのクロックとは別のものが使用されますが、rp2040ではこのタイマのクロックソースがCPUのクロックと一致しています。したがって、このカウンタ値を読み出すことで、CPUサイクル単位での時間測定が可能となります。
現在のカウント値は、「SysTick現在値レジスタ(0xE000E018)」から読み出すことができます。

SysTickタイマの特徴は以下の通りです：

• ダウンカウンタ（1クロックごとにカウンタ値が減少する）
• 大きさは24ビット（32ビット中の下位24ビットを使用）

さらに、最大値は、「SysTickリロード値レジスタ(0xE000E014)」に格納されており、カウンタ値が0になるとこの値がカウンタ値に設定されます（このレジスタも下位24ビットに値が設定可能です）。

3. コードの例

Arduino環境で動作するプログラムを作成しました。この環境において、SysTick現在値レジスタ(0xE000E018)は、systick_reg->cvrで参照できます。値取得時のオーバーヘッドが少なくなるよう、get_cvr()をinline関数として定義しています。

#include <Arduino.h>
#include <hardware/structs/systick.h>

// 時刻取得関数
inline uint32_t get_cvr()
{
  return systick_hw->cvr;
}

// tick値の差分を計算
__attribute__((noinline)) static uint32_t tick_diffs(uint32_t start_time, uint32_t end_time)
{
  if (start_time <= end_time) {
    // 測定時間内にreload発生
    start_time += systick_hw->cvr + 1;
  }
  return start_time - end_time;
}

// 
__attribute__((noinline)) static uint32_t __not_in_flash_func(systick_test1)(void)
{
  uint32_t start_time;
  uint32_t end_time;

  start_time = get_cvr();
  end_time = get_cvr();
  return tick_diffs(start_time, end_time);
}

// 
__attribute__((noinline)) uint32_t __not_in_flash_func(systick_test2)(void)
{
  uint32_t start_time;
  uint32_t end_time;

  start_time = get_cvr();
  _NOP();
  end_time = get_cvr();
  return tick_diffs(start_time, end_time);
}

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

void loop()
{
  uint32_t t1 = systick_test1();
  Serial.print("systick_test1: ");
  Serial.println(t1);
  uint32_t t2 = systick_test2();
  Serial.print("systick_test2: ");
  Serial.println(t2);
  delay(500);
}

注意事項：
rp2040の外付けQSPIに格納されているプログラムを実行する場合、キャッシュ内にコードが格納されていない場合、アクセスタイムが長くなってしまいます。この問題を防ぐため、コードをRAMに配置するよう、__not_in_flash_funcマクロを指定しています。

オーバーヘッドがどの程度になるかを確認するため、逆アセンブルしてみます。

00000000 <systick_test1()>:
   0:   b510            push    {r4, lr}
   2:   4b03            ldr     r3, [pc, #12]   ; (10 <systick_test1()+0x10>)
   4:   6898            ldr     r0, [r3, #8]    ; SysTick現在値レジスタからの読み出し①
   6:   6899            ldr     r1, [r3, #8]    ; SysTick現在値レジスタからの読み出し②
   8:   f7ff fffe       bl      0 <systick_test1()>
   c:   bd10            pop     {r4, pc}
   e:   46c0            nop                     ; (mov r8, r8)
      10:   e000e010        and     lr, r0, r0, lsl r0   ; 

Disassembly of section .time_critical.systick_test2:

00000000 <systick_test2()>:
   0:   4b03            ldr     r3, [pc, #12]   ; (10 <systick_test2()+0x10>)
   2:   b510            push    {r4, lr}
   4:   6898            ldr     r0, [r3, #8]    ; SysTick現在値レジスタからの読み出し①
   6:   46c0            nop                     ; (mov r8, r8)
   8:   6899            ldr     r1, [r3, #8]    ; SysTick現在値レジスタからの読み出し②
   a:   f7ff fffe       bl      0 <systick_test2()>
   e:   bd10            pop     {r4, pc}
  10:   e000e010        and     lr, r0, r0, lsl r0

4. 実行結果

上記のプログラムの実行結果です。NOPなしの処理サイクル数が2で、NOPを1つ追加した処理サイクル数が3になっています。

systick_test1: 2
systick_test2: 3
systick_test1: 2
systick_test2: 3
systick_test1: 2

厳密には確認できていないのですが、この方法で処理時間を計測することができそうです。