ftrace と bpftrace によるユーザー空間トレーシング

動的トレーシングは、「ある関数が遅い可能性がある」という状態を観測可能なイベントに変換します：呼び出し回数、引数、戻り値、エントリからリターンまでの時間差など。まずプロービングのレイヤーと対象の識別子を特定し、スクリプトを決定します。関数名が同じ、パスが同じ、TID が同じであっても、必ずしも同じビジネスリクエストを指すわけではありません。

本文のコマンドは bpftrace 0.24 ドキュメントに基づいており、/absolute/path/prog、関数名、PID は置き換える必要があるテンプレートです。対象のバイナリ、カーネルの機能、権限は要件を満たしている必要があります。例では、すべてのシステムに同じ libc パスがあるとは仮定していません。

各レイヤーのツールはそれぞれ何を担当するか

tracefs は通常 /sys/kernel/tracing にマウントされ、互換パスは debugfs 下にある場合があります。ftrace のカーネル関数トレーサ、tracefs インフラ全体、BPF を同じメカニズムと混同しないでください。ftrace ドキュメント

プローブアドレス：シンボル名、仮想アドレス、ファイルオフセットは異なる

bpftrace や perf probe は ELF シンボルの解析に役立ちます。しかし、カーネルの生の uprobe_events インターフェースの定義は、対象ファイルパスとファイルオフセットを使用しており、生のイベントフォーマットとして /bin/bash:readline と直接記述することはできません。

ELF 内のシンボル仮想アドレス v が与えられた場合、それが属するファイルサポートマッピングを見つける必要があります。典型的な変換は file_offset = p_offset + (v - p_vaddr) であり、アドレスが対応するセグメントのファイルコンテンツ範囲内にあることを検証します。PIE のランタイムロードベースアドレスはこのファイルオフセットとは異なります。ランタイムアドレスを直接埋め込むと、誤った位置にプローブされます。

生のインターフェースの概念的形式は以下の通りで、フォーマット説明であり、OFFSET は検証済みの値に置き換える必要があります：

p:group/event /absolute/path/prog:OFFSET
r:group/event_return /absolute/path/prog:OFFSET

これはインターフェースの構文であり、構造図ではありません。実際の操作では、手計算の誤りを避けるため、シンボル解析ツールを優先して使用するのが一般的です。生のイベント管理には、enable、バッファ読み取り、名前による削除なども含まれます。Uprobe tracer ドキュメント

能力と対象をまず列挙する

bpftrace --version
bpftrace --info
bpftrace -l 'uprobe:/absolute/path/prog:*work*'
bpftrace -lv 'uprobe:/absolute/path/prog:work'
bpftrace -lv 'tracepoint:syscalls:sys_enter_openat'
readelf -Ws /absolute/path/prog

関数がインライン化されている、削除されている、または最適化されたクローンしかない場合、独立したエントリがない可能性があります。C++ の名前修飾と複数の同名シンボルも曖昧さを解消する必要があります。DWARF は型付き引数の取得に役立ちますが、実行中のビルドと一致している必要があります。コンテナ内外のパス、削除された古いマッピング、ファイルの置き換えも、対象の特定に影響します。

bpftrace の -p PID は、サポートされているユーザープローブに特定のプロセスにアタッチし、他の関連プローブを PID でフィルタリングし、対象の終了時に終了します。具体的な動作は対応するバージョンの説明を参照してください。--dry-run は、ロードとアタッチを試みて終了しますが、⁠純粋なオフラインの構文チェックではありません⁠。bpftrace CLI

シンボルと結果を確認できる小さな対象をまず準備する

trace-target.c として保存します。work は非再帰で同期的にリターンする C 関数であり、エントリの size はループに参加する項目数を表し、戻り値は累積結果です。size バイトの読み書きは行わないため、後のスクリプトモデルを使用する場合は、指標名を入力項目数に変更する必要があります。

#include <stdio.h>
__attribute__((noinline))
long work(unsigned long size) {
    volatile unsigned long total = 0;
    for (unsigned long i = 0; i < size; ++i) total += i & 7u;
    return (long)total;
}
int main(void) {
    long a = work(1000);
    long b = work(2000);
    printf("%ld %ld\n", a, b);
    return a == 3500 && b == 7000 ? 0 : 1;
}

cc -g -O1 trace-target.c -o trace-target
./trace-target
readelf -Ws ./trace-target
objdump -d ./trace-target

この例では、範囲内の累積と long 変換は有効です。まず work の独立したエントリが存在することを確認し、プログラムが 3500 7000 を出力してからプローブを確立します。noinline は観察点を保持するのに役立つコンパイラ属性ですが、任意の生産ビルドで同じアドレスとコード形状が採用されることは保証されません。

短命のプロセスは、手動でアタッチする前に終了する可能性があります。bpftrace -c で対象を起動する場合、0.24 ではデフォルトですべてのプローブをその子プロセスにフィルタリングしないことに注意してください。ユーザーコンテキストプローブには pid == cpid を使用して明示的にフィルタリングできます。ツールによって起動された子プロセスはツールの権限を継承するため、実行方法を選択する際は、元の負荷の実行条件と一致させる必要があります。bpftrace -c

引数：エントリで引数を読み、リターンで結果を読む

通常のネイティブ C ABI でコンパイルされた long work(unsigned long size) について、エントリ uprobe では arg0 を読み取り、リターン uretprobe では retval を読み取ることができます。リターン時には引数レジスタが既に上書きされている可能性があり、uretprobe で arg0 を元の size として扱うことはできません。

argN の位置は ABI と型分類によって異なります。浮動小数点数、構造体、スタック経由の引数渡し、言語ランタイム固有の ABI は、%si、%rdi、x0 を適当に置き換えるだけでは解決できません。エントリの引数を保持する必要がある場合は、エントリで記録し、対応するリターンで取り出す必要があります。bpftrace プローブ説明

文字列を読み取る場合、「ポインタアドレス」と「その時点での内容」を区別する必要があります。str() はプローブ時にユーザーメモリを読み取ろうとしますが、文字列の長さは設定によって制約され、無効なアドレスや内容の変化が結果に影響します。戻り値のポインタを自動的にエントリの文字列として扱わないでください。

明確な前提条件を持つレイテンシスクリプト

以下を work.bt として保存します。前提条件は、同じスレッドが work をネストしたり、再帰したり、シグナルハンドラによって再入したりせず、正常にリターンすることです。これらの条件が満たされない場合は、後の相関設計を使用する必要があります。

uprobe:/absolute/path/prog:work
{
    @start[tid] = nsecs(monotonic);
    @size[tid] = arg0;
}

uretprobe:/absolute/path/prog:work
/@start[tid]/
{
    @lat_us = hist((nsecs(monotonic) - @start[tid]) / 1000);
    if ((int64)retval >= 0) {
        @successful_input_bytes = sum(@size[tid]);
    }
    delete(@start, tid);
    delete(@size, tid);
}

END
{
    clear(@start);
    clear(@size);
}

bpftrace -p 12345 work.bt

ここでは、負でない戻り値が成功を表し、累積するのは成功した呼び出しのエントリ size の合計であり、生存メモリ、実際に書き込まれたバイト数、戻り値そのものではないという追加の規約があります。work のインターフェース定義が異なる場合は、指標の意味論を変更する必要があります。

nsecs(monotonic) は、システムのスリープ時間を含まない単調クロックを明示的に使用します。差を 1000 で割った値はマイクロ秒です。したがって、lat_us > 10000 は 10 ミリ秒以上を意味し、10 マイクロ秒とコメントしないでください。hist はカーネル側で集計し、呼び出しごとにテキストを出力するのを回避します。map の削除構文は 0.24 標準ライブラリに従います。bpftrace 標準ライブラリ

関数エントリからリターンまでの時間には、CPU 実行、プリエンプション、ブロッキング、およびプローブオーバーヘッドが含まれます。呼び出しレイテンシが非常に長いからといって、futex wait が発生したことを単独で証明するものではありません。その間に futex システムコールが見えても、操作の種類、戻り値、時間範囲を確認して、実際の待機を判断する必要があります。

再帰、スレッド終了、非同期リクエストの相関

@start[tid] だけでタイムスタンプを保存すると、内側の呼び出しが外側の呼び出しを上書きします。再帰シナリオでは、TID ごとに深さを維持し、(tid, depth) を開始時間と引数のキーとして使用できます。リターン時には現在の層を取得してデクリメントします。アタッチ時の既存呼び出し、リターン見逃し、longjmp、例外展開、スレッド終了、map 容量を同時に考慮する必要があり、そうでないと深さが一致しない可能性があります。

コルーチンや非同期リクエストはスレッド間や複数の関数呼び出しにまたがることがあります。この場合、TID は実行スレッドを表すのに適していますが、リクエスト ID としては機能しません。USDT またはアプリケーションが既に持っている相関識別子を使用して request_id を記録し、開始、一時停止、再開、完了イベントを接続するのが最善です。

リターンプローブも、すべての言語ランタイムで透明であるわけではありません。カスタムスタック、特殊なリターンパスなどは、サポート状況を確認する必要があります。複雑なランタイムでは、意味論が明確な USDT が、特定の内部関数の機械語 ABI に依存するよりも安定していることがよくあります。

イベントシーケンスを使って再帰がどのタイムスタンプを上書きしたかを確認する

同じスレッドの外側の work が 100 μs で入り、再帰的な内側の work が 130 μs で入り、内側が 170 μs でリターンし、外側が 200 μs でリターンすると仮定します。@start[tid] だけを保存している場合、130 は 100 を上書きします。最初のリターンで 40 μs が得られ、エントリが削除されますが、外側の 100 μs のレイテンシは失われます。

以下のオフラインモデルはスレッドごとのスタックを使用し、ペアリングロジックの検証のみを目的としており、BPF をロードしたりプローブをアタッチしたりしません。また、「エントリのないリターン」と、観測終了時に未完成の呼び出しも記録します。

from collections import defaultdict
stacks = defaultdict(list)
durations = []
orphan_returns = 0
events = [
    (1, "return", 90),
    (1, "enter", 100), (1, "enter", 130),
    (1, "return", 170), (1, "return", 200),
    (2, "enter", 210),
]
for tid, kind, timestamp in events:
    if kind == "enter":
        stacks[tid].append(timestamp)
    elif stacks[tid]:
        start = stacks[tid].pop()
        assert timestamp >= start
        durations.append((tid, timestamp - start))
    else:
        orphan_returns += 1
assert durations == [(1, 40), (1, 100)]
assert orphan_returns == 1
assert sum(map(len, stacks.values())) == 1

このモデルは、同じスレッドのイベント順序が完全で、ネストが正常であることを仮定しています。実際には、中間リターン見逃し、longjmp、または例外パスにより、スタックの深さが永久的にずれる可能性があります。したがって、depth を追加しても、相関の問題が完全に解決されるわけではありません。不一致の数を記録し、スレッドごとの深さと総キー数を制限し、確認できるスレッド終了またはセッション境界でクリーンアップする必要があります。

特に、観測終了時にまだ実行中の低速呼び出しは、リターンしないため、完了レイテンシヒストグラムに入りません。これらをカウントせずに直接クリアすると、レポートは高速な完了呼び出しに偏る可能性があります。未完成の数と、停止時点までの待機時間の下限を別途報告し、レイテンシがゼロであると見なしてはいけません。

内側の呼び出しは誰の開始時間を上書きしたか？

タイムラインは包含関係を描画しています：外側の 100 μs はすでに内側の時間を含んでいます。エントリで同じ start[TID] に書き込むと、内側が 100 を上書きし、内側リターン後にエントリが削除されると、外側はペアリングの根拠を失います。スタックは各層の開始点を保持できますが、見逃されたイベントを凭空から回復することはできません。未完成の数と不一致の数は、結果とともに報告されるべきです。

USDT：事前に観測可能なビジネスイベントを約束する

アプリケーションは SDT マクロを使用してリクエスト開始点を定義できます。以下のスニペットでは、request_id と size はビジネスコードによって提供されます。

#include <sys/sdt.h>

DTRACE_PROBE2(myapp, request_start, request_id, size);

これは関数本体に配置され、対応するヘッダーファイルをインストールしてビルドを完了する必要があります。対象が実際に保持しているプローブをリストしてから、引数契約に従って消費します。

readelf -n /absolute/path/prog
bpftrace -l 'usdt:/absolute/path/prog:*'
bpftrace -p 12345 -e 'usdt:/absolute/path/prog:myapp:request_start {
    @requests = count();
}'

USDT は、ビルド成果物のプローブメタデータを通じて位置と引数を記述し、一部の実装ではセマフォを使用してアクティベーションを調整します。非アクティブ時のコストは通常非常に低いですが、絶対ゼロではありません。コードレイアウト、引数計算、ビルド方法によってはコストがかかる可能性があります。すべてのアーキテクチャで特定の NOP を x86 INT3 に書き換えるとは一概に言えません。

ビジネスプローブはフィールドの意味論とともにバージョン管理する必要がある

イベントは通常、start/finish のペアで必要とされ、suspend/resume または明示的な cancel が追加されることもあります。リクエストがマシンを跨ぐ場合、それぞれの monotonic 値を直接減算することはできません。単一マシンのレイテンシと分散トレーシングにおけるクロックと因果関係は、別々に処理する必要があります。

指標の集計も次元を制御する必要があります。各 request_id をヒストグラムのキーとして長期保持すると、高基数の map になります。通常、ID は短期的な相関のために使用され、完了後に削除され、操作名、結果タイプなどの限られた次元で集計されます。少数の異常サンプルは詳細情報を保持できますが、すべての正常なリクエストを永続的なキーにしてはいけません。

ユーザー関数からシステム動作へ拡張する

bpftrace -p 12345 -e 'tracepoint:syscalls:sys_enter_openat {
    @open_calls = count();
}'

このカウントは openat エントリの回数を記述しており、成功したオープンを表すものではありません。成功、失敗、レイテンシは出口とペアリングする必要があります。ファイル名も最終的に解決されたファイルの識別子を完全に表現するものではなく、ディレクトリ fd、マウント名前空間、シンボリックリンク、パス変更などが関与する可能性があります。

既存の BCC ツールは方向性を検証するのに適しています。例えば execsnoop は exec 呼び出しとその引数、結果を観察しますが、完全な「誰が誰を fork したか」のトレーシングではありません。プロセス作成には、fork、clone、またはスケジューリングイベントも必要です。ツールはランタイムで BPF をコンパイルする可能性があり、コマンドラインプログラムだからといってすべてがプリコンパイルされたカーネルプログラムであるわけではありません。BCC execsnoop ソースコード

結果が信頼できるかどうかを判断する

対象の PID、ビルドの識別子、プローブの位置、引数の型、開始と終了の時間、カウントの分母を明確にします。イベントがない場合は、まず実際のパスが実際に実行されたことを確認し、シンボル解析、権限、サポート能力をチェックします。すぐにビジネスが発生していないと結論づけないでください。

高頻度のプローブは、測定対象のプログラムを変更します。プローブ側で集計を優先し、次元の数と観測時間を制限し、イベントロスト、map 満了、読み取り失敗などのフィードバックを確認します。ツールを停止すると、通常、ツールが管理していたアタッチメントが解放されます。手動で作成した tracefs イベントは、今回の名前でクリーンアップする必要があり、マシン上のすべての uprobe 設定をクリアしてはいけません。

サンプリングはホットスポットを見つけるのに適しており、イベントトレーシングは特定のパスと時間関係を検証するのに適しています。両方を組み合わせて使用するには、perf への深い入り方 を参照してください。

キーワード：ftrace, tracefs, uprobe, uretprobe, USDT, bpftrace, BCC, ABI, file offset, latency, correlation

観測結果に分母とギャップを付与する

プローブ内で完了した map 集計とユーザー空間での逐次出力は、異なるデータパスを持っています。出力ロストが見えても、すべてのカウントを区別なく変更することはできませんが、それによって観測全体にギャップがないと仮定することもできません。収集カバレッジ、ペアリングカバレッジ、出力カバレッジを別々に記述して初めて、あるレイテンシ分布が実際にはどの呼び出しを表しているのかがわかります。