はじめに
深夜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使用率もメモリも正常です。問題はアプ...