Posted inCentos

CentOS Stream 9でbpftraceとBCC Toolsを使う：eBPFによるパフォーマンスデバッグガイド

CentOS tutorial - IT technology blog
CentOS tutorial - IT technology blog

本番サーバーで不思議な症状が出始めた：load averageは正常、CPUも高くないのに、毎朝7時になるとresponse timeが急上昇する。topやhtop、iostat -x 1を1時間眺め続けても原因が掴めなかった。従来のツールはスナップショットを見せてくれるだけで、なぜは教えてくれない。

少し背景を説明すると：CentOS 8のEOLを受けて急いでCentOS Stream 9に移行したサーバー群を管理していた時期の話で、同時並行で5台をRocky Linuxへ移行する作業も走っており、ちょうど1週間かかった。その作業を通じて気づいたのは、vmstatやsarは綺麗な数字を表示していてもシステムが詰まっている場合があるということだ — ツールが悪いのではなく、集計値しか計測していないのが原因だ。bpftraceとBCCなら、個々のsyscall・I/Oリクエストが何をしているかをリアルタイムで把握できる。

eBPF・BCC・bpftrace — 3つの違いとは？

この3つはよく混同される。最初に違いを把握しておくと、ドキュメントを調べる時間をかなり節約できる。

eBPF（extended Berkeley Packet Filter）は、kernel moduleを書かずにLinux kernelの中でコードを実行できる技術だ。具体的には、syscall・network packet・disk I/O・function callなど、システム上のあらゆるものをオーバーヘッド極小でinstrumentできる。eBPF verifierがコードをkernelにロードする前に検証し、システムのクラッシュを防ぐ仕組みになっている。

BCC（BPF Compiler Collection）は、eBPFを基盤としたフレームワークと、あらかじめ用意された100以上のツール群だ。各ツールが特定の問題を解決する：biolatencyはdisk I/O用、execsnoopはprocess execution用、tcpconnectはnetwork connection用。BCC toolsを使うためにeBPFの内部知識は不要だ。

bpftraceは、awk/DTraceに似た構文を持つハイレベルなtracingランゲージだ。BCCに既存ツールがない機能をカスタマイズしたいときや、素早くone-linerでトレースしたいときに使う。

シンプルな使い分け：既存ツールで済む場合はBCC、カスタマイズが必要な場合はbpftrace。

CentOS Stream 9へのインストール

# BCC toolsとPython bindingをインストール
sudo dnf install -y bcc bcc-tools python3-bcc

# bpftraceをインストール
sudo dnf install -y bpftrace

# Kernel headers — kernelにBTFがない場合に必要
sudo dnf install -y kernel-devel-$(uname -r) kernel-headers-$(uname -r)

# BTFサポートを確認（kernel >= 5.8では通常利用可能）
ls /sys/kernel/btf/vmlinux && echo "BTF available" || echo "Need kernel headers"

/sys/kernel/btf/vmlinuxファイルが存在する場合、kernel headersは不要だ — BTFベースのツールがそのまま動く。CentOS Stream 9はkernel 5.14+を標準搭載しており、通常はすでに利用可能な状態になっている。

# インストールの確認
bpftrace --version
ls /usr/share/bcc/tools/ | head -20

実践：よくあるパフォーマンス問題のデバッグ

biolatencyでI/Oレイテンシを分析する

ディスクが原因だと疑ったときに最初に実行するツールだ。biolatencyはレイテンシの分布をマイクロ秒単位のヒストグラムで表示する：

# sdaディスクを10秒間モニタリング
sudo /usr/share/bcc/tools/biolatency -d sda 10

# プロセス別にI/Oを分析
sudo /usr/share/bcc/tools/biosnoop -d sda

biolatencyの出力例は以下の通りだ：

     usecs               : count     distribution
         0 -> 1          : 1203     |********                        |
         2 -> 3          : 4521     |********************************|
         4 -> 7          : 2109     |***************                 |
         8 -> 15         : 892      |*******                         |
        16 -> 31         : 45       |                                |
     32768 -> 65535      : 12       |                                | <-- 異常なスパイク

最後のバケット — 12リクエストが32〜65msかかっている — は問題のサインだ。続けてbiosnoopを実行すれば、どのプロセスが原因かを正確に特定できる。

execsnoopでプロセスの実行を追跡する

謎のプロセスがforkされている？execsnoopはすべてのexec() syscallをリアルタイムでキャプチャする：

sudo /usr/share/bcc/tools/execsnoop

出力例：

PCOMM            PID    PPID   RET ARGS
bash             12345  12344    0 /bin/bash -c /usr/local/bin/check-disk.sh
python3          12346  12345    0 python3 /usr/local/bin/check-disk.sh

このツールのおかげで、毎朝のレイテンシの原因を突き止められた：誰も存在を覚えていない古いバックアップスクリプトが毎分実行されて15〜20個のsubprocessをforkし、web serverとI/Oを奪い合っていたのだ。

opensnoopでfile open callsをデバッグする

# オープンされるすべてのファイルを表示（リターンコード付き）
sudo /usr/share/bcc/tools/opensnoop

# nginxプロセスのみ追跡
sudo /usr/share/bcc/tools/opensnoop -n nginx

# 特定のPIDでフィルタ
sudo /usr/share/bcc/tools/opensnoop -p 1234

アプリレベルの「file not found」エラーのデバッグや、アプリが予想外のパスからconfigを読んでいる場面の検出に便利だ — 移行後に古いパスがconfigにhardcodeされたまま残っている場合によく起きる。

tcpconnectでTCP接続を監視する

# アウトバウンドTCP接続を表示
sudo /usr/share/bcc/tools/tcpconnect

# データベースとキャッシュのポートのみフィルタ
sudo /usr/share/bcc/tools/tcpconnect -P 5432,6379,3306

実際にこんなケースがあった：データベース移行後、アプリが静かに古いIPへ接続し続けていた — connection timeoutが遅いせいで明確なエラーは出ず、ただレイテンシが異常に上がるだけだった。tcpconnectは実行から10秒以内で即座に露わにした。

プロセスを再起動せずにCPUプロファイリングする

# 30秒間、99HzでCPUスタックトレースをサンプリング
sudo /usr/share/bcc/tools/profile -F 99 30 > /tmp/profile.out

# 特定のPIDをプロファイリング
sudo /usr/share/bcc/tools/profile -F 99 -p 1234 30

出力はfolded stack traceで、flamegraph.plでの可視化に対応している。debug symbolsを付けてバイナリを再コンパイルすることなく、CPUボトルネックをデバッグする最も効果的な方法だ。

bpftrace：ニーズに合わせたカスタムトレーシング

よく使うone-liner

# syscallを名前別にカウントし、Ctrl+Cで表示
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_* { @[probe] = count(); }'

# read() syscallのレイテンシを計測 — ナノ秒ヒストグラム
sudo bpftrace -e '
  tracepoint:syscalls:sys_enter_read { @start[tid] = nsecs; }
  tracepoint:syscalls:sys_exit_read  /@start[tid]/ {
    @latency_ns = hist(nsecs - @start[tid]);
    delete(@start[tid]);
  }'

# 最も多くオープンされたファイルTop 10
sudo bpftrace -e '
  tracepoint:syscalls:sys_enter_openat { @[str(args->filename)] = count(); }
  END { print(@, 10); }'

低速ディスク書き込みをトレースするスクリプト

#!/usr/bin/env bpftrace
// 実行方法: sudo bpftrace slow_writes.bt
// 10ms以上かかったext4書き込みを報告

kprobe:ext4_file_write_iter
{
    @start[tid] = nsecs;
}

kretprobe:ext4_file_write_iter
/@start[tid]/
{
    $dur_ms = (nsecs - @start[tid]) / 1000000;
    if ($dur_ms > 10) {
        printf("[SLOW WRITE] PID=%d COMM=%s duration=%dms\n",
               pid, comm, $dur_ms);
    }
    delete(@start[tid]);
}

kprobeで関数のレイテンシをトレースする

# VFS readオペレーションのレイテンシを計測
sudo bpftrace -e '
  kprobe:vfs_read    { @start[tid] = nsecs; }
  kretprobe:vfs_read /@start[tid]/ {
    @us = hist((nsecs - @start[tid]) / 1000);
    delete(@start[tid]);
  }'

本番環境で使用する際の注意事項

  • オーバーヘッド：eBPFのオーバーヘッドは非常に低いがゼロではない。hot pathの継続的なトレース（全パケット・全syscall）は避け、intervalやPID/processフィルタを活用すること。
  • コンパイルの遅延：BCC toolsは起動時にBPF programをコンパイルするため、1〜5秒かかることがある。これは正常な動作でエラーではない。
  • アクセス権限：rootまたはCAP_BPF + CAP_PERFMONのcapabilitiesが必要。
  • Kernelバージョン：一部の機能にはkernel >= 5.8が必要。CentOS Stream 9はkernel 5.14+で条件を満たしている。

実際のところ、デバッグのためにBCC toolsを15〜30秒実行して停止する分には、顕著なオーバーヘッドを感じたことはない。フィルタなしで高負荷なシステムにツールを何時間も走らせ続けた場合にのみ問題が生じる。

まとめ

以前は同じ種類の問題に2〜3日かかっていた。bpftraceとBCCなら数分で特定できる — ツールが魔法のようなのではなく、集計メトリクスから推測するのではなく、kernelが実際に何をしているかを直接見られるからだ。

最も実践的な始め方：テストサーバーでbiolatencyとexecsnoopを実行し、実際の出力を見てから、自分の問題に合ったツールを探していくといい。まずBCC、次にbpftrace — bpftraceの構文はeBPF Cを直接書くより格段に簡単で、BCCの基礎があればすぐに馴染める。最良のリファレンス：GitHub上のbpftrace reference guideと、Brendan Greggの書いたBPF Performance Tools — 彼は今あなたが使ったBCC toolsの大部分の作者でもある。

Share:
Tags: