Skip to content

필사 모드: eBPF可観測性の実践 — bpftraceでシステムのブラックボックスを開く

日本語
0%
정확도 0%
💡 왼쪽 원문을 읽으면서 오른쪽에 따라 써보세요. Tab 키로 힌트를 받을 수 있습니다.
원문 렌더가 준비되기 전까지 텍스트 가이드로 표시합니다.

はじめに

深夜2時、「APIレスポンスが断続的に3秒かかる」というアラートが鳴ります。APMダッシュボードを開いても、アプリケーションコードの中では何も遅くありません。CPU使用率もメモリも正常です。問題はアプリケーションとハードウェアの間のどこか、つまりカーネルというブラックボックスの中にあります。

このブラックボックスを開く最も強力な手段がeBPFベースの可観測性です。前回の記事でeBPFの基礎(プログラム、マップ、Verifier)を扱ったのに対し、今回は徹底して実践です。bpftraceワンライナーで5分以内に仮説を検証し、BCCツールボックスでディスク/ネットワーク/スケジューラを掘り下げ、フレームグラフでCPUを解剖した後、実際の障害シナリオ3つを段階的に追跡していきます。

従来の観測ツールの限界とeBPF可観測性

伝統的な観測ツールには、それぞれ死角があります。

| ツール系統 | 得意なこと | 限界 |

| --- | --- | --- |

| メトリクス (Prometheusなど) | トレンド、アラート | 集計された平均の裏に隠れた個別イベントが見えない |

| ログ | アプリケーションが記録すると決めたこと | 記録しなかったことは存在しないように見える |

| APMトレーシング | リクエスト単位の分解 | 計装コードの挿入が必要、カーネル区間は空白 |

| strace / ltrace | システムコールの全数観察 | ptraceベースのため対象プロセスが数十倍遅くなる |

| perf | CPUプロファイリング | イベントをダンプして後処理する方式、カスタムロジックが不足 |

eBPF可観測性の差別化ポイントは三つです。

1. コード修正も再デプロイも不要です。すでに実行中のプロセスとカーネルをその場で観察します。

2. オーバーヘッドが低い。イベントはカーネル内でフィルタ/集計され、必要な結果だけがユーザー空間に渡されます。straceがコンテキストスイッチの嵐を生むのとは対照的です。

3. カーネルとアプリケーションを同じツールで見られます。システムコール、ディスクIO、スケジューラ、TCP再送からユーザー関数のレイテンシまで、一本の線でつながります。

全体像をASCIIで描くと次のようになります。

観測対象レイヤとeBPFフック

+------------------------------------------------------------+

| アプリケーション <── uprobe / USDT (関数遅延、GCイベント) |

+------------------------------------------------------------+

| ライブラリ(libc) <── uprobe (malloc, pthreadなど) |

+------------------------------------------------------------+

| システムコール境界 <── tracepoint syscalls:* (open, read...)|

+------------------------------------------------------------+

| カーネルサブシステム |

| VFS/ファイルシステム <── kprobe/kfunc (vfs_readなど) |

| ブロック層 <── tracepoint block:* (IO遅延) |

| ネットワークスタック <── kprobe tcp_* / tracepoint sock:* |

| スケジューラ <── tracepoint sched:* (ランキュー待ち) |

+------------------------------------------------------------+

| ハードウェアイベント <── perf_event (CPUサイクル、キャッシュミス) |

+------------------------------------------------------------+

bpftrace文法を5分で入門

bpftraceはawkに似たDSLです。基本構造は「プローブ / フィルタ / アクション」です。

probe /filter/ { action }

probe : どこにアタッチするか (tracepoint, kprobe, uprobe, profile...)

filter : どのイベントだけを見るか (pid == 1234 など、省略可)

action : 何をするか (出力、マップへ集計)

よく使う組み込み変数と関数を知っているだけで、すぐに始められます。

| 要素 | 意味 |

| --- | --- |

| pid, tid, comm | プロセスID、スレッドID、コマンド名 |

| args | tracepointの引数構造体 |

| retval | kretprobe/uretprobeの戻り値 |

| nsecs | ナノ秒タイムスタンプ |

| kstack, ustack | カーネル/ユーザーのスタックトレース |

| count(), sum(), avg() | 集計関数 |

| hist(), lhist() | log2/線形ヒストグラム |

実戦ワンライナー10選

1. ファイルオープン追跡 — 誰がどのファイルを開くか:

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_openat

{ printf("%-16s %s\n", comm, str(args->filename)); }'

2. プロセス実行追跡 — システムで実行されるすべてのコマンド:

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_execve

{ printf("%-16s -> %s\n", comm, str(args->filename)); }'

3. システムコール回数トップ — どのプロセスがどのシスコールを多く呼ぶか:

sudo bpftrace -e 'tracepoint:raw_syscalls:sys_enter

{ @[comm] = count(); }'

4. readシスコール遅延ヒストグラム — シスコール単位の遅延分布:

sudo bpftrace -e '

tracepoint:syscalls:sys_enter_read { @start[tid] = nsecs; }

tracepoint:syscalls:sys_exit_read /@start[tid]/

{ @usecs = hist((nsecs - @start[tid]) / 1000); delete(@start[tid]); }'

5. 新規TCP接続の追跡 — どのプロセスがどこへ接続するか:

sudo bpftrace -e 'kprobe:tcp_connect

{ printf("%-16s pid=%d\n", comm, pid); }'

6. ブロックIOサイズ分布 — ディスク要求サイズのヒストグラム:

sudo bpftrace -e 'tracepoint:block:block_rq_issue

{ @bytes = hist(args->bytes); }'

7. プロセス別ディスクIOバイト合計:

sudo bpftrace -e 'tracepoint:block:block_rq_issue

{ @[comm] = sum(args->bytes); }'

8. CPU 99Hzサンプリング — カーネルスタック基準でどこに時間を使っているか:

sudo bpftrace -e 'profile:hz:99 { @[kstack] = count(); }'

9. ページフォルトの多いプロセス:

sudo bpftrace -e 'software:page-faults:1 { @[comm] = count(); }'

10. シグナル追跡 — 誰が誰にkillを送るか:

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_kill

{ printf("%s (pid %d) -> pid %d, sig %d\n",

comm, pid, args->pid, args->sig); }'

この10個が手に馴染むだけで、「推測」ではなく「測定」から会話を始められます。使用可能なプローブの一覧は次のように探索します。

sudo bpftrace -l 'tracepoint:syscalls:*' | head -20

sudo bpftrace -lv 'tracepoint:syscalls:sys_enter_openat' # 引数構造を確認

BCCツールボックスツアー

bpftraceが即席の質問用だとすれば、BCCツール集(およびlibbpfで書き直されたlibbpf-tools)はよく磨かれた既製ツールです。ほとんどのディストリビューションでbpfcc-toolsまたはbcc-toolsパッケージとしてインストールできます。

状況別ツール選択テーブル

| 症状/質問 | ツール | 見せてくれるもの |

| --- | --- | --- |

| どんなプロセスが起動し続けるか | execsnoop | すべてのexecveと引数 |

| どのファイルを開いているか | opensnoop | open呼び出しと結果コード |

| ディスクが遅いのか | biolatency | ブロックIO遅延ヒストグラム |

| どのIOが遅いのか | biosnoop | 個別IOの遅延/サイズ/プロセス |

| TCP接続の寿命は | tcplife | 接続ごとの寿命、送受信バイト |

| 誰が接続を作るのか | tcpconnect | 能動的connectの追跡 |

| 誰が接続を受けるのか | tcpaccept | 受動的acceptの追跡 |

| 再送はあるのか | tcpretrans | TCP再送イベント |

| シスコールが遅いのか | syscount | シスコール別回数/遅延 |

| ランキュー待ちが長いのか | runqlat | スケジューラのランキュー待ちヒストグラム |

| キャッシュミスが多いのか | cachestat | ページキャッシュのヒット/ミス |

| ファイルシステムが遅いのか | ext4slowerなど | しきい値以上の遅いFS操作 |

典型的な使用例は次のとおりです。

10msより遅いext4操作のみ出力

sudo ext4slower-bpfcc 10

1秒間隔でブロックIO遅延ヒストグラムを出力

sudo biolatency-bpfcc -m 1

コンテナ込みの全TCPセッション寿命を観察

sudo tcplife-bpfcc

60秒診断ルーチン

障害の初動対応で私が使う順序です。

sudo execsnoop-bpfcc # 想定外のプロセス急増の有無 (cron、ヘルスチェックなど)

sudo runqlat-bpfcc 5 1 # CPU競合: ランキュー待ち分布

sudo biolatency-bpfcc 5 1 # ディスク: IO遅延分布

sudo tcpretrans-bpfcc # ネットワーク: 再送発生の有無

sudo syscount-bpfcc -L -d 5 # シスコール遅延トップ

5つのコマンド、1分で問題のレイヤ(CPU/ディスク/ネットワーク/シスコール)を絞り込めます。

遅延ヒストグラムの読み方

eBPFツールの出力で最も情報量が多いのがlog2ヒストグラムです。biolatencyの出力例を見てみましょう。

usecs : count distribution

128 -> 255 : 1402 |************************** |

256 -> 511 : 2012 |****************************************|

512 -> 1023 : 803 |*************** |

1024 -> 2047 : 95 |* |

...

65536 -> 131071 : 41 | |

131072 -> 262143 : 17 | |

読むポイントは三つです。

1. 本体(mode)の位置: ほとんどのIOが256〜511マイクロ秒に集まっています。これがデバイスの「正常」な特性です。

2. テール(tail)の存在: 13万〜26万マイクロ秒(130ms以上)の区間に17件あります。平均にはほとんど現れませんが、p99.9のユーザー体験を台無しにする主犯です。

3. 山が二つあるか(bimodal): 山が二つなら「キャッシュヒット vs ミス」「ローカル vs リモート」「正常経路 vs リトライ」のように、異なる二つの経路が混ざっている強いシグナルです。平均値は二つの山の間の、実際には誰も経験しない値を指すことになります。

要約すると、平均を捨てて分布を見よ。これがeBPF可観測性の中心的な教訓です。

CPUプロファイリングとフレームグラフ

perfベース vs eBPFベース

| 項目 | perf record | eBPF (profileプローブ / profile-bpfcc) |

| --- | --- | --- |

| 収集方式 | サンプルをファイルにダンプ後、後処理 | カーネル内マップでスタック別に集計 |

| データ量 | perf.dataが数GBまで肥大化し得る | 集計結果のみ渡されるため小さい |

| オーバーヘッド | ディスク書き込みコストを含む | 一般的により低い |

| 柔軟性 | 標準化されたワークフロー、幅広いPMUサポート | 条件付き収集などカスタムロジックが可能 |

99Hzで全CPUスタックをサンプリングしてフレームグラフを作る二つの経路です。

経路A: perfベース

sudo perf record -F 99 -a -g -- sleep 30

sudo perf script | stackcollapse-perf.pl | flamegraph.pl > cpu.svg

経路B: eBPFベース (カーネル内集計、folded形式を直接出力)

sudo profile-bpfcc -F 99 -af 30 > out.folded

flamegraph.pl out.folded > cpu.svg

フレームグラフの読み方はシンプルです。横幅がCPU時間の占有率で、上に行くほどコールスタックが深くなります。最も広い「高原」を見つけ、その関数がなぜ呼ばれるのか下へたどっていけばよいのです。ユーザースタックまで見るには、対象プロセスがフレームポインタを保持するようにビルドされている(-fno-omit-frame-pointer)か、最近のツールのようにDWARF/BTFベースのアンワインドをサポートしている必要があります。

オフCPU分析

CPUフレームグラフは「回っている間」だけを見せます。しかし遅延の大部分は待ち時間(ディスク、ロック、ネットワーク)から来ます。そこでオフCPU分析を使います。

スレッドがCPUを手放した(ブロックされた)時間をスタック別に集計

sudo offcputime-bpfcc -df 30 > offcpu.folded

flamegraph.pl --colors=io offcpu.folded > offcpu.svg

CPUフレームグラフでは見えなかった「ロック待ち80%」のような真実が、オフCPUグラフで明らかになることがよくあります。オンCPUとオフCPUをペアで見る習慣をお勧めします。

コンテナとKubernetes環境で

原理: eBPFはノードレベルの技術

eBPFプログラムはカーネルにアタッチされるため、一つのノードのすべてのコンテナを一度に観察します。コンテナは結局cgroup + 名前空間で隔離されたプロセスなので、PIDやcgroup IDでフィルタすれば特定のPodだけを選んで見られます。ノードで直接実行する場合の典型的な方法は次のとおりです。

特定コンテナのPIDを探してそのプロセスのみフィルタ

PID=$(crictl inspect --output go-template \

--template '{{.info.pid}}' CONTAINER_ID)

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_openat /pid == '$PID'/

{ printf("%s\n", str(args->filename)); }'

DaemonSetでデバッグツールのイメージを配置しておくか、kubectl debug node機能でノードに一時Podを立てて作業する方式が一般的です。

エコシステムツール (知っている範囲で)

| ツール | アプローチ | 特徴 |

| --- | --- | --- |

| Pixie | クラスタ内eBPFエージェント | プロトコル自動キャプチャ(HTTP、DBなど)、スクリプトベースの照会 |

| Parca | eBPF継続プロファイリング | 常時稼働の低オーバーヘッドプロファイラ、時系列フレームグラフ |

| Grafana Beyla | eBPF自動計装 | コード修正なしでHTTP/gRPCのREDメトリクスとトレースを生成 |

| Cilium Hubble | CNI統合の可観測性 | ネットワークフローの可視化、サービスマップ |

| Inspektor Gadget | BCC系ツールのk8sパッケージング | kubectlプラグインでノードツールをPod単位に実行 |

共通パターンは「サイドカーではなくノードエージェント」という点です。eBPFのおかげで、Podごとにプロキシやエージェントを注入しなくても、ノードあたり一つのDaemonSetで全体を観察できます。

USDTとuprobeでアプリケーションを追跡

カーネルだけでなくユーザー空間も同じ方法で追跡できます。

uprobeはバイナリの任意の関数にアタッチします。例えば特定のC/C++/Go/Rustバイナリの関数遅延を測れます。

バイナリで追跡可能なシンボルを探す

sudo bpftrace -l 'uprobe:/usr/local/bin/myapp:*' | grep -i order

特定関数の遅延ヒストグラム

sudo bpftrace -e '

uprobe:/usr/local/bin/myapp:process_order { @start[tid] = nsecs; }

uretprobe:/usr/local/bin/myapp:process_order /@start[tid]/

{ @latency_us = hist((nsecs - @start[tid]) / 1000);

delete(@start[tid]); }'

USDT(User Statically-Defined Tracing)は、アプリケーションが事前に埋め込んだ安定したトレースポイントです。PostgreSQL、JVM、Python、Node.jsなどがUSDTを提供しています。

プロセスのUSDTプローブを一覧

sudo bpftrace -lp $(pgrep -o postgres) 'usdt:*' | head

PostgreSQLクエリ開始の追跡 (USDTの例)

sudo bpftrace -e 'usdt:/usr/lib/postgresql/16/bin/postgres:query__start

{ printf("query: %s\n", str(arg0)); }'

注意点は二つです。uprobeは関数がインライン化されると捕捉できず、シンボルがストリップされたバイナリではシンボルテーブルが必要です。また、呼び出し頻度が非常に高いユーザー関数にuprobeを仕掛けるとトラップコストが累積するため、まず頻度を確認するのが安全です。

実戦トラブルシューティングシナリオ3つ

シナリオ1: ディスクIO急増

症状: 特定の時間帯ごとにディスク使用率が跳ね上がり、サービス遅延を伴います。

ステップ1: 遅延分布の確認 — 本当にディスクが遅いのか、どの程度か?

sudo biolatency-bpfcc -m 5 3

ステップ2: 犯人プロセス — 誰がIOを生んでいるのか?

sudo biotop-bpfcc 5

ステップ3: 個別IOの観察 — どのファイル/パターンか?

sudo biosnoop-bpfcc | head -50

ステップ4: ファイルレベルへ — どのファイルに読み書きが集中しているか?

sudo filetop-bpfcc -C 5

ステップ5: 書き込みの誘発元を追跡 — ページキャッシュのフラッシュか、直接書き込みか?

sudo bpftrace -e 'tracepoint:block:block_rq_issue

{ @[comm, args->rwbs] = count(); }'

典型的な結論の例: バックアップジョブやログローテーションが同じディスクでシーケンシャル書き込みを起こし、DBのランダム読み取りのテールレイテンシを膨らませるパターンです。解決はIOスケジューリングクラスの分離(ionice)、cgroup io.maxの制限、またはボリュームの分離です。

シナリオ2: 断続的な遅延 (p99スパイク)

症状: 平均レスポンスは正常なのにp99が周期的に跳ねます。APMには手がかりがありません。

ステップ1: レイヤの特定 — CPU待ちなのか?

sudo runqlat-bpfcc 5 12 # 1分間に12回: スパイク時点と重なるか

ステップ2: CPU泥棒を探す — 誰が突然CPUを使うのか?

sudo profile-bpfcc -F 99 -af 30 > spike.folded

ステップ3: ブロッキングの確認 — オフCPU時間はどこで?

sudo offcputime-bpfcc -df 30 -p $(pgrep -o myapp) > offcpu.folded

ステップ4: GC/ミューテックス仮説の検証 (例: futex待ち時間の分布)

sudo bpftrace -e '

tracepoint:syscalls:sys_enter_futex { @start[tid] = nsecs; }

tracepoint:syscalls:sys_exit_futex /@start[tid]/

{ @futex_ms = hist((nsecs - @start[tid]) / 1000000);

delete(@start[tid]); }'

典型的な結論の例: cronで回るメトリクス収集器が1分ごとにCPUを占有してランキュー待ちが増えるケース、あるいは特定ロックのコンボイ現象。runqlatのヒストグラムがスパイク時点だけ右に寄るなら、CPU競合側の仮説が強まります。

シナリオ3: コネクションリーク

症状: 時間が経つにつれてファイルディスクリプタが増加し、最終的にtoo many open filesで障害になります。

ステップ1: 接続の寿命を観察 — 閉じられない接続があるか?

sudo tcplife-bpfcc -p $(pgrep -o myapp)

ステップ2: 生成 vs 終了のバランス — どちら側が漏れているか?

sudo bpftrace -e '

kprobe:tcp_connect { @open[comm] = count(); }

kprobe:tcp_close { @close[comm] = count(); }

interval:s:10 { print(@open); print(@close);

clear(@open); clear(@close); }'

ステップ3: リーク地点のスタック — どこで作られた接続が閉じられないのか?

sudo bpftrace -e 'kprobe:tcp_connect /comm == "myapp"/

{ @[ustack] = count(); }'

ステップ4: FD増加の一般確認 (ソケットでない可能性もあるため)

sudo opensnoop-bpfcc -p $(pgrep -o myapp) -d 30

典型的な結論の例: エラー経路でHTTPクライアントのレスポンスボディを閉じておらず、コネクションプール外の接続が蓄積するパターンです。ステップ3のユーザースタックが、リークを起こしている正確なコードパスを指し示してくれます。

オーバーヘッド管理と安全ルール

本番マシンでeBPFツールを動かす際の原則です。

1. まず頻度を見積もります。プローブを仕掛ける前に、そのイベントが毎秒何回発生するかカウントだけ先に測ります。

sudo bpftrace -e 'kprobe:vfs_read { @ = count(); }

interval:s:1 { print(@); clear(@); }'

2. カーネル内で集計し、出力はサマリだけ受け取ります。printfでイベントごとに出力する方式は、イベントが多いとそれ自体が負荷になります。count/hist集計を基本とします。

3. 時間を制限します。ほとんどのBCCツールは回数/時間の引数を受け取ります。無期限の実行を避け、測定が終わったら即座に終了します。

4. フィルタをできるだけ前に置きます。PID、cgroup、ポートなどでカーネルサイドで先に絞ります。

5. カナリアから始めます。フリート全体に一度に適用せず、1台でオーバーヘッドを測定してから拡大します。

6. マップのメモリを意識します。キーのカーディナリティが爆発し得る集計(例: スタックトレースキー)はマップサイズの上限を確認します。

7. 権限を分離します。フルrootの代わりにCAP_BPF + CAP_PERFMONで十分なツールが多くあります。詳細は基礎編を参照してください。

運用チェックリスト

- [ ] ノードにbpftraceとbccツールがインストールされ、バージョンがカーネルと互換である

- [ ] カーネルでBTFが有効である (/sys/kernel/btf/vmlinux が存在)

- [ ] 障害初動用の60秒診断ルーチンがランブックに整理されている

- [ ] 主要サービスのバイナリがフレームポインタを保持するようにビルドされている

- [ ] プロファイリング成果物(フレームグラフ)を保管/共有する場所が決まっている

- [ ] コンテナ環境なら、ノードアクセスまたはInspektor Gadget系ツールの経路が準備されている

- [ ] eBPFツールの実行権限ポリシー(誰が、どの権限で)が定義されている

- [ ] 高頻度プローブへのガードレール(まず頻度を見積もる)がチーム内で合意されている

おわりに

eBPF可観測性の本質はツールのリストではなく、問いの立て方の転換です。「たぶんディスクだろう」と推測する代わりに、biolatencyのヒストグラムで30秒で確認します。「GCのせいだろう」と言う代わりに、オフCPUフレームグラフで証明します。カーネルがもはやブラックボックスでなくなれば、障害対応の会話全体がデータの上で行われるようになります。

基礎編で扱ったプログラム/マップ/Verifierの原理を知っていれば、この記事のすべてのツールが「tracepointにアタッチしてpercpuマップに集計し、ringbufで渡すプログラム」として読めるようになるはずです。次の記事では、同じ技術がセキュリティへ向かいます。TetragonとFalco、BPF LSMで、観測を超えて検知とブロックまで進みます。

参考資料

- [bpftrace公式ドキュメント](https://bpftrace.org/)

- [bpftraceワンライナーチュートリアル (GitHub)](https://github.com/bpftrace/bpftrace/blob/master/docs/tutorial_one_liners.md)

- [BCC (BPF Compiler Collection) ツール集](https://github.com/iovisor/bcc)

- [Brendan Gregg — eBPFトレーシング資料](https://www.brendangregg.com/ebpf.html)

- [Brendan Gregg — フレームグラフ](https://www.brendangregg.com/flamegraphs.html)

- [Brendan Gregg — オフCPU分析](https://www.brendangregg.com/offcpuanalysis.html)

- [LinuxカーネルBPFドキュメント](https://docs.kernel.org/bpf/)

- [perfウィキ (kernel.org)](https://perf.wiki.kernel.org/)

- [Pixie公式ドキュメント](https://docs.px.dev/)

- [Parca — 継続プロファイリング](https://www.parca.dev/)

- [Grafana Beylaドキュメント](https://grafana.com/docs/beyla/latest/)

- [Inspektor Gadget](https://www.inspektor-gadget.io/)

- [Cilium Hubbleドキュメント](https://docs.cilium.io/en/stable/observability/hubble/)

현재 단락 (1/225)

深夜2時、「APIレスポンスが断続的に3秒かかる」というアラートが鳴ります。APMダッシュボードを開いても、アプリケーションコードの中では何も遅くありません。CPU使用率もメモリも正常です。問題はアプ...

작성 글자: 0원문 글자: 11,990작성 단락: 0/225