Zephyrで実行時間を計測する

Zephyr nrf52840

はじめに

Zephyrでアプリケーションを開発しており、ベンチマークが取りたくなりました。 driverが提供されているnRF52840のRTC (Real Time Counter) を使って、プログラムの実行時間を計測してみます。

最終的には、Zephyr kernelが提供しているKernel Clock APIを使用します。

nRF52840 RTC (Real Time Counter)

nRF52840には、3つのRTCが搭載されています。

www.nordicsemi.com

ZephyrでのnRF RTC

Kernel configでは、デフォルトでdriverが有効になっています。

# Timer Drivers
#
CONFIG_NRF_RTC_TIMER=y

NRF_RTC_TIMER

3つあるRTC (0, 1, 2)のうち、RTC1のdriverが提供されています。 これは、Zephyr kernelがsystem clockとして利用します。 0と2を利用したい場合には、どうすれば良いのでしょうね？

nrf_rtc_timer.c

NRF RTCのdriverです。

|> zephyr/drivers/timer/nrf_rtc_timer.c

ざっとAPIを一通り見てみます。

int z_clock_driver_init(struct device *device);
void z_clock_set_timeout(s32_t ticks, bool idle);
u32_t z_clock_elapsed(void);
u32_t _timer_cycle_get_32(void);

system clockは1つだけしかない、ということが前提（当然の前提ですが）で、APIを関数ポインタで登録せずに、kernelと静的にリンクしているっぽいですね。 zephyr/drivers/timer下にあるdriverには、全て同じ名前の関数が実装されています。

# at zephyr/include
$ grep -r _timer_cycle_get_32 *
...
arch/posix/arch.h:extern u32_t _timer_cycle_get_32(void);
arch/posix/arch.h:#define _arch_k_cycle_get_32()  _timer_cycle_get_32()
arch/arm/cortex_m/misc.h:extern u32_t _timer_cycle_get_32(void);
arch/arm/cortex_m/misc.h:#define _arch_k_cycle_get_32() _timer_cycle_get_32()
arch/nios2/arch.h:extern u32_t _timer_cycle_get_32(void);
arch/nios2/arch.h:#define _arch_k_cycle_get_32()
...

はい、予想通りですね。kernelと結びついている部分も、下の通りです。

# at zephyr/include
$ grep -r _arch_k_cycle_get_32 *
...
kernel.h:#define k_cycle_get_32()   _arch_k_cycle_get_32()

system clock driverインタフェース

Zephyrのsystem clock driverインタフェースについて調べます。

docs.zephyrproject.org

kernel.hで提供されているAPIは、次の通りです。k_cycle_get_32()の実態は、上述の通り、nrf_rtc_timer.cの_timer_cycle_get_32()です。

ということで、カウンタがラウンドアップしない範囲であれば、計測したい処理の前後で、k_cycle_get_32()を実行して、その差分を計算すればよいことになります。 uptime系のAPIはミリ秒単位なので、ミリ秒単位での計測がしたい場合に使えそうです。

上記Zephyrドキュメントでも、サンプルコード付きで解説があります。

Measuring Time with Normal Precision

s64_t time_stamp;
s64_t milliseconds_spent;

/* capture initial time stamp */
time_stamp = k_uptime_get();

/* do work for some (extended) period of time */
...

/* compute how long the work took (also updates the time stamp) */
milliseconds_spent = k_uptime_delta(&time_stamp);

Measuring Time with High Precision

ありがたいことに、クロックサイクルからナノ秒単位に変換するマクロも提供されています。

u32_t start_time;
u32_t stop_time;
u32_t cycles_spent;
u32_t nanoseconds_spent;

/* capture initial time stamp */
start_time = k_cycle_get_32();

/* do work for some (short) period of time */
...

/* capture final time stamp */
stop_time = k_cycle_get_32();

/* compute how long the work took (assumes no counter rollover) */
cycles_spent = stop_time - start_time;
nanoseconds_spent = SYS_CLOCK_HW_CYCLES_TO_NS(cycles_spent);

SYS_CLOCK_HW_CYCLES_TO_NSマクロ

#define SYS_CLOCK_HW_CYCLES_TO_NS(X) (u32_t)(SYS_CLOCK_HW_CYCLES_TO_NS64(X))

/* SYS_CLOCK_HW_CYCLES_TO_NS64 converts CPU clock cycles to nanoseconds */
#define SYS_CLOCK_HW_CYCLES_TO_NS64(X) \
        (((u64_t)(X) * NSEC_PER_SEC) / sys_clock_hw_cycles_per_sec())

sys_clock_hw_cycles_per_sec()は定数を返す関数です。