3.9. ftrace ユーティリティーを使用したレイテンシーの追跡

Red Hat Enterprise Linux for Real Time カーネルで提供される診断機能の 1 つが ftrace です。これは、開発者がユーザー空間外で発生するレイテンシーおよびパフォーマンスの問題を分析し、デバッグするのに使用されます。この ftrace ユーティリティーには、さまざまな方法でユーティリティーを使用できるさまざまなオプションがあります。これは、コンテキストスイッチの追跡、優先順位の高いタスクでのウェイクアップにかかる時間の測定、割り込みが無効になっている期間の測定、特定の期間中に実行されたカーネル関数の一覧の表示に使用できます。
関数トレーサーなどの一部のトレーサーは、大量のデータ量を生成し、トレースログ分析を時間の消費タスクに切り替えます。ただし、トレーサーに対し、アプリケーションが重要なコードパスに到達した場合にのみ開始および終了するように指示することが可能です。
この ftrace ユーティリティーは、Red Hat Enterprise Linux for Real Time カーネルの trace バリアントがインストールされ、使用中の場合に設定できます。

手順3.3 ftrace ユーティリティーの使用

  1. /sys/kernel/debug/tracing/ ディレクトリーには、available_tracers という名前のファイルがあります。このファイルには、ftrace に使用できるすべてのトレーサーが含まれます。利用可能なトレーサーの一覧を表示するには、cat コマンドを使用してファイルの内容を表示します。
    ~]# cat /sys/kernel/debug/tracing/available_tracers
    function_graph wakeup_rt wakeup preemptirqsoff preemptoff irqsoff function nop
    
    ftrace のユーザーインターフェースは、debugfs にある一連のファイルです。ftrace ファイルは /sys/kernel/debug/tracing/ ディレクトリーにも存在します。以下を入力します。
    ~]# cd /sys/kernel/debug/tracing
    トレースを有効にするとシステムのパフォーマンスに影響を及ぼすことができるため、このディレクトリーのファイルを変更することができるのは root ユーザーのみです。
    ftrace ファイル

    このディレクトリー内のメインファイルは、以下のとおりです。

    trace
    ftrace トレースの出力を表示するファイル。これは、このファイルが読み込まれ、イベント読み取りを消費しないため、トレースを停止するため、実際にはトレースのスナップショットです。これは、ユーザーがトレースを無効にしてこのファイルを読み取ると、読み取り時に毎回同じ内容を報告します。
    trace_pipe
    「trace」と似ていますが、トレースをライブで読み込むために使用されます。プロデューサー/コンシューマートレースで、各読み取りが読み取られるイベントを消費します。ただし、これにより、トレースが読み取られることなく、アクティブなトレースを確認することができます。
    available_tracers
    カーネルにコンパイルされた ftrace トレーサーの一覧。
    current_tracer
    ftrace トレーサーを有効または無効にします。
    events
    トレースするイベントが含まれ、イベントを有効または無効にするのに使用できるディレクトリーと、イベントのフィルターの設定を行うことができます。
    tracing_on
    ftrace バッファーへの録画を無効および有効にします。tracing_on ファイル経由でトレースを無効にしても、カーネル内で実際のトレースは無効になりません。バッファーへの書き込みのみを無効にします。トレースを実行する作業は継続されますが、データはどこにも移動しません。
    トレーサー

    カーネルの設定方法によっては、指定のカーネルですべてのトレーサーが利用できるとは限りません。Red Hat Enterprise Linux for Real Time カーネルの場合、トレースカーネルとデバッグカーネルは、実稼働用のカーネルとは異なるトレーサーを持ちます。これは、トレーサーの一部にトレーサーがカーネルに設定され、アクティブではない場合に大きなオーバーヘッドが発生するためです。このトレーサーは、トレースおよびデバッグカーネルに対してのみ有効になります。

    function
    最も広く適用されるトレーサーの 1 つ。カーネル内の関数呼び出しを追跡します。トレースされた関数の数によっては、認識可能なオーバーヘッドが発生する可能性があります。アクティブでない場合にオーバーヘッドがほとんど作成されます。
    function_graph
    function_graph トレーサーは、結果を視覚的に表示するように設計されています。このトレーサーは、関数の終了を追跡し、カーネル内の関数呼び出しのフローを表示します。
    このトレーサーは、有効なときに function トレーサーよりも多くのオーバーヘッドがありますが、無効なときには同じオーバーヘッドが少ないことに注意してください。
    wakeup
    すべての CPU でアクティビティーが発生することを報告する完全な CPU トレーサー。リアルタイムタスクであるかに関わらず、システム内で最も優先度の高いタスクを起動するのにかかる時間を記録します。非リアルタイムタスクを起動するのにかかる最大時間の記録では、リアルタイムタスクを起動するのにかかる時間が非表示になります。
    wakeup_rt
    すべての CPU でアクティビティーが発生することを報告する完全な CPU トレーサー。現在の最も高い優先度タスクから、ウェイクアップ時間まで経過時間を記録します。リアルタイムタスクの時間を記録します。
    preemptirqsoff
    プリエンプションまたは割り込みを無効にするエリアを追跡し、プリエンプションまたは割り込みが無効となった最大時間を記録します。
    preemptoff
    preemptirqsoff トレーサーと同様ですが、プリエンプションが無効となった最大間隔のみを追跡します。
    irqsoff
    preemptirqsoff トレーサーと似ていますが、割り込みが無効になっている最大間隔のみを追跡します。
    nop
    デフォルトのトレーサー。トレース機能自体は提供しませんが、イベントがトレーサーに干渉する可能性があるため、nop トレーサーはイベントの追跡に具体的な目的に使用されます。
  2. トレーシングセッションを手動で開始するには、最初に available_tracers にある一覧から使用するトレーサーを選択し、echo コマンドを使用してトレーサーの名前を /sys/kernel/debug/tracing/current_tracer に挿入します。
    ~]# echo preemptoff > /sys/kernel/debug/tracing/current_tracer
  3. function および function_graph トレースが有効になっているかどうかを確認するには、cat コマンドを使用して /sys/kernel/debug/tracing/options/function-trace ファイルを表示します。値が 1 の場合は、これが有効であることを示し、0 は無効であることを示します。
    ~]# cat /sys/kernel/debug/tracing/options/function-trace
    1
    
    デフォルトでは functionfunction_graph トレースは有効になっています。この機能を有効または無効にするには、/sys/kernel/debug/tracing/options/function-trace ファイル echo に適切な値を設定します。
    ~]# echo 0 > /sys/kernel/debug/tracing/options/function-trace
    ~]# echo 1 > /sys/kernel/debug/tracing/options/function-trace

    重要

    echo コマンドを使用する場合は、値と > 文字の間に空白文字を配置するようにしてください。0>, 1>, and 2> (空白文字なし) を使用するシェルプロンプトでは、標準入力、標準出力、および標準エラーを参照します。誤ってそれらを使用すると、トレースが予期せぬ出力になる可能性があります。
    この function-trace オプションは、wakeup_rtpreemptirqsoff などによるトレースレイテンシーにより、関数トレースが有効になるため便利です。これは、オーバーヘッドを誇張することがあります。
  4. /debugfs/tracing/ ディレクトリー内のさまざまなファイルの値を変更して、トレーサーの詳細とパラメーターを調整します。以下に例を示します。
    irqsoff、preemptoff、preempirqsoff、および wakeup トレーサーは、レイテンシーを継続的に監視します。tracing_max_latency で記録されたものよりもレイテンシーが大きい場合は、レイテンシーのトレースが記録され、tracing_max_latency が新しい最大時間に更新されます。これ tracing_max_latency により、最後にリセットされた後、常に記録されたレイテンシーが最も高いレベルが表示されます。
    最大レイテンシーをファイルにリセットするには、echo 0tracing_max_latency ファイルに切り替えます。指定の量を超えるレイテンシーのみを見るには、echo でマイクロ秒単位で表示します。
    ~]# echo 0 > /sys/kernel/debug/tracing/tracing_max_latency
    トレースのしきい値を設定すると、最大レイテンシー設定が上書きされます。しきい値より大きいレイテンシーが記録されると、最大レイテンシーに関係なく記録されます。トレースファイルを確認すると、最後に記録されたレイテンシーのみが表示されます。
    しきい値を設定するには、記録される必要があるレイテンシーを上回るマイクロ秒を echo します。
    ~]# echo 200 > /sys/kernel/debug/tracing/tracing_thresh
  5. トレースログを表示します。
    ~]# cat /sys/kernel/debug/tracing/trace
  6. トレースログを保存するには、別のファイルにコピーします。
    ~]# cat /sys/kernel/debug/tracing/trace > /tmp/lat_trace_log
  7. 関数トレースは、/sys/kernel/debug/tracing/set_ftrace_filter ファイルの設定を変更してフィルターできます。ファイルにフィルターが指定されていない場合、すべての関数がトレースされます。現在のフィルターを表示するには、cat を使用します。
    ~]# cat /sys/kernel/debug/tracing/set_ftrace_filter
  8. フィルターを変更するには、追跡する関数の名前を echo します。このフィルターは、検索用語の先頭または末尾に * ワイルドカードを使用できます。
    * ワイルドカードは、単語の先頭 最後の両方で使用できます。たとえば、*irq* は、名前の irq に含まれるすべての関数を選択します。ただし、ワイルドカードは単語内で使用できません。
    検索用語とワイルドカード文字を二重引用符で囲むと、シェルが検索を現在の作業ディレクトリーに拡張しないようにします。
    フィルターの例を以下に示します。
    • schedule 関数のみを追跡します。
      ~]# echo schedule > /sys/kernel/debug/tracing/set_ftrace_filter
    • lock で終わるすべての関数を追跡します。
      ~]# echo "*lock" > /sys/kernel/debug/tracing/set_ftrace_filter
    • spin_ で始まるすべての関数を追跡します。
      ~]# echo "spin_*" > /sys/kernel/debug/tracing/set_ftrace_filter
    • 名前に cpu のある関数すべてを追跡します。
      ~]# echo "*cpu*" > /sys/kernel/debug/tracing/set_ftrace_filter

    注記

    echo コマンドとともに単一の > を使用する場合は、ファイル内の既存の値が上書きされます。ファイルに値を追加する場合は、代わりに >> を使用します。