ROS2タイマーコールバックの起床レイテンシ測定

前回の記事（ROS2 タイマーの解析と実験）では、タイマーの起床処理を解析し、最終的な就寝にfutexシステムコールが呼ばれていることと、タイマーがシステム時刻の調整に影響を受けることを確認しました。

今回はタイマーの起床レイテンシを測定しました。

タイマー起床試験

起床レイテンシを測定するために、周期的に起床と就寝を繰り返すテストケースを用意しました。
起床レイテンシは、設定された起床時刻から、関数が実行開始される時刻までと定義しています。ROS2のタイマーコールバックの場合、rcl層で設定されている起床時刻から実際にコールバックを実行開始するまでの時間になります。
今回は、以下の３パターンの測定と比較を行いました。

タイマーコールバックの起床レイテンシ
futex の起床レイテンシ
nanosleep の起床レイテンシ

周期は起床と就寝の処理が十分間に合うように、長めの10msとし、それぞれパターンで10分間測定しました。測定環境はリアルタイム性能の測定に向けたRaspberryPi3のセットアップで用意したRaspberryPi 3B+です。

タイマーコールバックに設定された起床時間は、rcl層のAPIとして公開されていません。そこで今回は、起床予定時刻の取得用にAPIを追加して測定しました。追加したAPIの差分については、 githubで公開しているrcl/timerの差分をご覧ください。

futexはROS2の就寝時に最終的に実行されるシステムコールです。通知による起床が可能ですが、ROS2の実装（正確にはstd::condition_variable::wait_for）に合わせてタイムアウトオプションで起床させました。futexの起床レイテンシとタイマーコールバックの起床レイテンシを比較することで、ROS 2のレイヤによる起床時のオーバーヘッドが測定できます。
加えて、高精度なタイマーであるnanosleepの起床レイテンシも測定しました。
futexとnanosleepの測定は擬似的なコードで書くと、以下のようになります。

int mem;  // futex 通知用
int main(int argc, char *argv[]) {
  // スレッドの優先度を98に設定。

  struct timespec period; // 10ms に設定
  struct timespec expected, wakeup, latency;

  clock_gettime(CLOCK_MONOTONIC_RAW, &expected);
  for (unsigned long i = 0; i < 60000; i++) {
    // expected = expedted + period

    clock_nanosleep(CLOCK_MONOTONIC, TIMER_ABSTIME, &expected, NULL);
    //  syscall(SYS_futex, &mem, FUTEX_WAIT_BITSET_PRIVATE | FUTEX_CLOCK_REALTIME,
    //          mem, &expected, nullptr, FUTEX_BITSET_MATCH_ANY);

    clock_gettime(CLOCK_MONOTONIC, &wakeup);

    // レイテンシの計算　latency = wakeup - expected
  }

  // 測定結果のファイル書き込み
  return 0;
}

測定結果

上の図は、緑色がタイマーコールバックの起床レイテンシ、青色がfutexの起床レイテンシ、赤色がnanosleepの起床レイテンシを示しています。

最悪値の比較では、レイテンシの小さい順に、nanosleep, futex, タイマーコールバックとなりました。タイマーコールバックの起床時間は、 futex システムコールの起床時間よりも最悪350us 程度遅く、ROS 2のレイヤによるオーバーヘッドが350 us 生じることを示しています。nanosleepの起床レイテンシが最悪で38us、タイマーコールバックの起床レイテンシが最悪で439usなので、オーダーひとつ分の差が生じています。futex システムコールのように通知による起床を必要とせず、タイマーでの起床のみで十分な場合、nanosleepで周期的な処理はROS2のタイマーを使わずに自前で実装すると、起床レイテンシが改善できそうです。

今回測定したケースはコールバックが１つしかないケースだったため、rclcpp層のエグゼキュータによるスケジューリングによる影響は小さいです。通常のアプリケーションでは、ノードは複数のコールバックを実行しますが、subscribeコールバックの実行中にタイマーが起床した場合など、他のコールバックに待たされ、測定した350usよりもタイマーコールバックの実行が遅れるケースがあるので注意が必要です。