Linuxサーバーの性能問題やアプリケーションのボトルネック調査で、「なぜこの処理が重いのか？」「どこで時間がかかっているのか？」という疑問に直面したことはありませんか？
従来のtopやhtop、vmstatといった静的な監視ツールでは、表面的な情報しか得られず、根本的な原因までは見えないことが多いですよね。
そんな時に威力を発揮するのが「動的トレーシング」です！
特に、BPF（Berkeley Packet Filter）、その発展形であるeBPF、そして実用的なbpftraceツール、従来からあるFtraceを組み合わせることで、Linuxシステムの深い部分まで詳細に分析できるようになります。
今回は、これらの動的トレーシング技術を実践的に活用する方法について、基礎から応用まで分かりやすく解説していきます。特に、どの場面でどのツールを使えば良いかという「使い分け」の部分も詳しくお伝えしますので、実際の業務で迷わず活用できるようになりますよ！
目次
動的トレーシングって何がすごいの？
従来の静的分析ツールの限界
まず、従来の監視ツールでは何が見えないのかを整理してみましょう。
topコマンドで分かること：
# 基本的なリソース使用状況
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1234 apache 20 0 500000 50000 10000 R 95.0 2.5 5:23.45 httpdこの結果から分かるのは「httpdプロセスがCPUを95%使っている」という事実だけです。
でも、本当に知りたいのは：
- なぜこんなにCPUを使っているのか？
- プロセス内のどの関数が重いのか？
- システムコールは何回呼ばれているのか？
- カーネル内部では何が起きているのか？
- メモリアクセスパターンはどうなっているのか？
従来のツールでは、この「なぜ」の部分が見えないんです。
同様に、sar、iostat、netstatなども：
- 結果は教えてくれるが、原因は教えてくれない
- スナップショット的な情報のみで、動的な変化が見えない
- アプリケーション固有の動作は分析できない
動的トレーシングで見える世界
動的トレーシングを使うと、システムの動作をリアルタイムで詳細に観察できます。
例えば、以下のような分析が可能に：
1. 関数レベルでの実行時間測定
# bpftraceでHTTPリクエスト処理時間を測定
bpftrace -e 'uprobe:/usr/sbin/httpd:ap_process_request { @start[tid] = nsecs; }
uretprobe:/usr/sbin/httpd:ap_process_request {
@duration = hist(nsecs - @start[tid]); delete(@start[tid]); }'2. システムコール頻度の動的分析
# どのシステムコールが頻繁に呼ばれているか
bpftrace -e 'tracepoint:syscalls:sys_enter_* { @syscalls[probe] = count(); }'3. カーネル内部の状態変化追跡
# プロセススケジューリングの詳細分析
bpftrace -e 'tracepoint:sched:sched_switch {
printf("%s -> %s\n", args->prev_comm, args->next_comm); }'これらは従来のツールでは絶対に見ることができない情報です！
BPF・bpftrace・Ftraceの位置づけ
動的トレーシングの世界では、主に3つのアプローチがあります：
Ftrace（Function Tracer）
- Linuxカーネルに組み込まれた従来の仕組み
- カーネル関数のトレースに特化
- 設定が複雑だが、オーバーヘッドが低い
BPF/eBPF（Extended Berkeley Packet Filter）
- カーネル内で安全にプログラムを実行する仕組み
- 非常に柔軟で高機能
- プログラミングが必要で学習コストが高い
bpftrace
- BPF/eBPFを簡単に使えるようにしたツール
- 直感的なスクリプト言語
- 実用的で覚えやすい
この分野をしっかり学びたい方には、Brendan Gregg氏の「詳解 システム・パフォーマンス 第2版」が最適です。
特に第14章「Ftrace」と第15章「BPF」では、今回解説する内容がさらに詳しく、実践的な事例とともに学べます。BPFプログラミングの基礎から高度な応用まで、体系的に理解できる貴重な書籍です。
Ftraceから始める動的トレーシング
Ftraceの基本操作をマスターしよう
Ftraceは、動的トレーシングの入門として最適です。Linuxカーネルに標準で組み込まれているため、追加のインストールが不要で、すぐに始められます。
Ftraceの基本設定：
# Ftraceが利用可能か確認
ls /sys/kernel/debug/tracing/
# 現在利用可能なトレーサーを確認
cat /sys/kernel/debug/tracing/available_tracers
# 結果例：
# blk function_graph wakeup_dl wakeup_rt wakeup function nop基本的な関数トレースの開始：
# rootユーザーで実行
cd /sys/kernel/debug/tracing
# 関数トレーサーを有効化
echo function > current_tracer
# 特定の関数のみをトレース（例：ファイルシステム関連）
echo 'vfs_*' > set_ftrace_filter
# トレース開始
echo 1 > tracing_on
# 5秒間トレース
sleep 5
# トレース停止
echo 0 > tracing_on
# 結果確認
head -20 trace結果の例：
# tracer: function
#
# entries-in-buffer/entries-written: 1234/1234 #P:4
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
httpd-1234 [001] .... 123.456789: vfs_read <-sys_read
httpd-1234 [001] .... 123.456790: vfs_write <-sys_write関数トレースとイベントトレース
Ftraceには大きく分けて2つのトレース方式があります。
1. 関数トレース（Function Trace）
すべての関数呼び出しを追跡する方式：
# function_graphトレーサーで呼び出し階層を可視化
echo function_graph > current_tracer
echo 'do_sys_open' > set_ftrace_filter
echo 1 > tracing_on
sleep 2
echo 0 > tracing_on
cat trace結果例：
1) | do_sys_open() {
1) | getname() {
1) 0.123 us | getname_flags();
1) 0.456 us | }
1) | get_unused_fd_flags() {
1) 0.089 us | __alloc_fd();
1) 0.234 us | }
1) 2.345 us | }2. イベントトレース（Event Trace）
特定のイベント発生時の詳細情報を記録：
# 利用可能なイベントを確認
find /sys/kernel/debug/tracing/events -name enable | head -10
# システムコール関連のイベントを有効化
echo 1 > /sys/kernel/debug/tracing/events/syscalls/sys_enter_open/enable
echo 1 > /sys/kernel/debug/tracing/events/syscalls/sys_exit_open/enable
# トレース実行
echo 1 > tracing_on
ls /tmp # 何かファイル操作を実行
echo 0 > tracing_on
# 結果確認
cat trace | grep openトレースデータの読み方と活用法
Ftraceの出力を効果的に分析する方法を見てみましょう。
基本的な出力フォーマット：
TASK-PID CPU# |||| TIMESTAMP FUNCTION
| | | |||| | |
httpd-1234 [001] .... 123.456789: function_name <-caller_function各フィールドの意味：
- TASK-PID: プロセス名とプロセスID
- CPU#: 実行されたCPUコア番号
- FLAGS: 割り込み状態やプリエンプション状態
- TIMESTAMP: 高精度タイムスタンプ
- FUNCTION: 実行された関数と呼び出し元
パフォーマンス分析での活用例：
# I/O遅延の詳細分析
echo 1 > /sys/kernel/debug/tracing/events/block/enable
echo 1 > tracing_on
# 重いI/O操作を実行
dd if=/dev/zero of=/tmp/testfile bs=1M count=100
echo 0 > tracing_on
# ブロックI/Oイベントの分析
grep block_rq trace | head -10結果から分かること：
- どのプロセスがI/Oを発行したか
- ディスクI/Oのキューイング時間
- I/O完了までの時間
- 複数のI/O要求の並列性
このような詳細なトレース分析の手法は、「詳解 システム・パフォーマンス 第2版」で豊富な実例とともに学ぶことができます。
BPF・eBPFの仕組みを理解しよう
BPFとは何か？カーネル内プログラミングの革命
BPF（Berkeley Packet Filter）は、もともとネットワークパケットをフィルタリングするために開発された技術でした。しかし、現在のeBPF（Extended BPF）は、その枠を大きく超えて、カーネル内で安全にプログラムを実行できる汎用的な仕組みに進化しています。
従来のカーネルプログラミングの問題：
- カーネルモジュールは危険（システムクラッシュのリスク）
- デバッグが困難
- 動的な変更ができない
- セキュリティリスクが高い
BPF/eBPFが解決すること：
- 安全性の保証（Verifierによる事前検証）
- 動的なプログラム挿入・削除
- 高いパフォーマンス
- 豊富なヘルパー関数
BPFプログラムの実行フロー：
1. BPFプログラム作成（C言語または専用言語）
2. コンパイル（バイトコードに変換）
3. Verifier検証（安全性チェック）
4. JITコンパイル（ネイティブコードに変換）
5. カーネル内実行eBPFの進化と可能性
eBPF（Extended BPF）は、従来のBPFを大幅に拡張した技術です。
eBPFの主要な特徴：
1. 豊富なプログラムタイプ
// ネットワークフィルタリング
BPF_PROG_TYPE_SOCKET_FILTER
// システムコールトレーシング
BPF_PROG_TYPE_TRACEPOINT
// カーネル関数トレーシング
BPF_PROG_TYPE_KPROBE
// ユーザー空間関数トレーシング
BPF_PROG_TYPE_UPROBE
// XDP（高速ネットワーク処理）
BPF_PROG_TYPE_XDP2. マップによるデータ共有
// ハッシュマップ
BPF_MAP_TYPE_HASH
// 配列
BPF_MAP_TYPE_ARRAY
// LRUハッシュマップ
BPF_MAP_TYPE_LRU_HASH
// リングバッファ
BPF_MAP_TYPE_RINGBUF3. ヘルパー関数の活用
// 現在時刻取得
bpf_ktime_get_ns()
// プロセス情報取得
bpf_get_current_pid_tgid()
// 文字列操作
bpf_probe_read_str()
// ログ出力
bpf_trace_printk()安全性とパフォーマンスの両立
eBPFが革新的な理由の一つは、安全性とパフォーマンスを高いレベルで両立していることです。
Verifierによる安全性保証：
eBPFプログラムは、カーネルに読み込まれる前に厳密なVerifier検証を通過します：
// 無限ループは禁止
for (int i = 0; i < MAX_LOOP; i++) { // MAX_LOOP は制限値
// 処理
}
// ポインタアクセスは事前チェック必須
if (data + sizeof(struct iphdr) > data_end)
return XDP_DROP; // 境界チェック主な安全性チェック項目：
- 無限ループの禁止
- メモリ境界チェック
- 未初期化変数の検出
- スタックオーバーフローの防止
- 許可されないカーネル関数呼び出しの禁止
JITコンパイルによる高速実行：
VerifierでOKが出たBPFプログラムは、JIT（Just-In-Time）コンパイラによってネイティブマシンコードに変換され、カーネル内で直接実行されます。
# JITコンパイルの有効化確認
cat /proc/sys/net/core/bpf_jit_enable
# 1: JIT有効, 0: インタープリター実行
# JITコンパイル統計情報
cat /proc/sys/net/core/bpf_jit_kallsymsこれにより、従来のカーネルモジュールとほぼ同等のパフォーマンスを実現しています。
bpftraceによる実践的システム分析
bpftraceのインストールと基本操作
bpftraceは、BPF/eBPFの強力な機能を簡単に使えるようにしたツールです。複雑なBPFプログラミングを知らなくても、直感的なスクリプト言語で高度な分析ができます。
Ubuntu/Debianでのインストール：
# パッケージ情報更新
sudo apt update
# bpftraceインストール
sudo apt install bpftrace
# 必要な場合はLinuxヘッダーもインストール
sudo apt install linux-headers-$(uname -r)CentOS/RHELでのインストール：
# EPELリポジトリを有効化
sudo yum install epel-release
# bpftraceインストール
sudo yum install bpftrace
# または新しいバージョンでは
sudo dnf install bpftrace動作確認：
# bpftraceのバージョン確認
bpftrace --version
# 利用可能なプローブポイント確認
bpftrace -l 'tracepoint:syscalls:*' | head -5基本的な実行権限設定：
# CAP_SYS_ADMIN権限が必要
sudo bpftrace -e 'BEGIN { printf("Hello, BPF World!\n"); exit(); }'
# 一般ユーザーでの実行を許可する場合（セキュリティに注意）
echo 'kernel.unprivileged_bpf_disabled = 0' | sudo tee -a /etc/sysctl.confワンライナーで始める簡単分析
bpftraceの魅力は、複雑な分析をワンライナーで実行できることです。
1. システムコール監視
# 最も頻繁に呼ばれるシステムコールTop 10
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_* { @syscalls[probe] = count(); } END { print(@syscalls, 10); clear(@syscalls); }'2. プロセス別CPU使用時間
# プロセス別のCPU使用時間を測定
sudo bpftrace -e 'profile:hz:99 { @cpu[comm] = count(); } END { print(@cpu); clear(@cpu); }'3. ファイルアクセス監視
# ファイルopen()システムコールの監視
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_openat { printf("PID %d (%s) opened: %s\n", pid, comm, str(args->filename)); }'4. ネットワーク接続追跡
# TCP接続の監視
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_connect { printf("PID %d connecting\n", pid); }'5. メモリ割り当て分析
# malloc()の呼び出し頻度とサイズ
sudo bpftrace -e 'uprobe:/lib/x86_64-linux-gnu/libc.so.6:malloc { @size = hist(arg0); @count = count(); }'スクリプトを書いて高度な分析を実現
より複雑な分析では、bpftraceスクリプトファイルを作成します。
例1: HTTPリクエスト分析スクリプト
# http_monitor.bt
#!/usr/bin/env bpftrace
BEGIN {
printf("Monitoring HTTP requests...\n");
}
uprobe:/usr/sbin/httpd:ap_process_request {
@start[tid] = nsecs;
@requests = count();
}
uretprobe:/usr/sbin/httpd:ap_process_request /@start[tid]/ {
$duration = nsecs - @start[tid];
@latency = hist($duration / 1000000); // Convert to milliseconds
delete(@start[tid]);
}
tracepoint:syscalls:sys_enter_write /comm == "httpd"/ {
@writes = count();
@write_bytes = sum(args->count);
}
interval:s:10 {
printf("\n=== HTTP Statistics (last 10 seconds) ===\n");
printf("Total requests: %d\n", @requests);
printf("Total writes: %d\n", @writes);
printf("Total bytes written: %d\n", @write_bytes);
printf("\nRequest latency distribution (ms):\n");
print(@latency);
printf("\n");
clear(@requests);
clear(@writes);
clear(@write_bytes);
clear(@latency);
}
END {
clear(@start);
clear(@requests);
clear(@writes);
clear(@write_bytes);
clear(@latency);
}実行方法：
# スクリプトの実行
sudo bpftrace http_monitor.bt
# 10秒間実行して自動終了
sudo timeout 60 bpftrace http_monitor.bt例2: ディスクI/O分析スクリプト
# disk_io.bt
#!/usr/bin/env bpftrace
BEGIN {
printf("Analyzing disk I/O patterns...\n");
}
tracepoint:block:block_rq_insert {
@io_queue[args->dev] = count();
@io_size[args->dev] = sum(args->bytes);
}
tracepoint:block:block_rq_issue {
@rq_start[args->dev, args->sector] = nsecs;
}
tracepoint:block:block_rq_complete /@rq_start[args->dev, args->sector]/ {
$latency = nsecs - @rq_start[args->dev, args->sector];
@io_latency = hist($latency / 1000); // Convert to microseconds
delete(@rq_start[args->dev, args->sector]);
}
interval:s:5 {
printf("\n=== Disk I/O Analysis ===\n");
printf("I/O Operations by Device:\n");
print(@io_queue);
printf("\nI/O Size by Device:\n");
print(@io_size);
printf("\nI/O Latency Distribution (μs):\n");
print(@io_latency);
printf("\n");
clear(@io_queue);
clear(@io_size);
clear(@io_latency);
}
END {
clear(@rq_start);
}これらのスクリプトを活用することで、従来のツールでは見えなかった詳細な性能情報を取得できます。
さらに詳しい分析手法やBPFプログラミングの基礎については、「詳解 システム・パフォーマンス 第2版」で体系的に学習できます。
3つのツールの使い分けガイド
場面別ツール選択の考え方
動的トレーシングでは、Ftrace、BPF/eBPF、bpftraceそれぞれに得意分野があります。適切な使い分けが重要です。
Ftraceが適している場面：
- カーネル関数の基本的なトレース
# シンプルなカーネル関数トレーシング
echo function > /sys/kernel/debug/tracing/current_tracer
echo 'vfs_*' > /sys/kernel/debug/tracing/set_ftrace_filter- 低オーバーヘッドでの長時間監視
# CPUオーバーヘッドを最小限に抑えた監視
echo function_graph > current_tracer
echo 10 > max_graph_depth # 深度制限でオーバーヘッド軽減- 既存のトレースポイントの活用
# 利用可能なトレースポイントが豊富
find /sys/kernel/debug/tracing/events -name enable | wc -lbpftraceが適している場面：
- ユーザー空間プログラムの分析
# アプリケーション固有の関数トレース
sudo bpftrace -e 'uprobe:/usr/bin/myapp:critical_function { printf("Called with arg: %d\n", arg0); }'- 複雑な条件付きトレース
# 特定の条件でのみトレース実行
sudo bpftrace -e 'syscall:open /comm == "myapp" && str(arg1) =~ /\.log$/ { printf("Log file access: %s\n", str(arg1)); }'- 統計データの集計・可視化
# ヒストグラムによる分布分析
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_read { @size = hist(args->count); }'生のBPF/eBPFプログラミングが必要な場面：
- 高度なカスタム分析ロジック
- 既存ツールでは実現できない複雑な処理
- 最大限のパフォーマンスが要求される場面
- 本格的なシステム監視ツールの開発
パフォーマンス重視 vs 詳細分析重視
目的によって適切なツール選択が変わります。
パフォーマンス重視の場合：
# Ftrace + 最小限の設定
echo function > current_tracer
echo 'schedule*' > set_ftrace_filter # 対象関数を限定
echo 5 > buffer_size_kb # バッファサイズを小さく利点：
- CPUオーバーヘッド最小
- メモリ使用量も最小
- 本番環境での使用に適している
欠点：
- 分析できる情報が限定的
- 複雑な条件指定ができない
詳細分析重視の場合：
# bpftrace + 詳細なスクリプト
sudo bpftrace -e '
tracepoint:syscalls:sys_enter_* /comm == "target_app"/ {
@syscall_start[tid, probe] = nsecs;
@syscall_count[probe] = count();
}
tracepoint:syscalls:sys_exit_* /@syscall_start[tid, probe]/ {
$duration = nsecs - @syscall_start[tid, probe];
@syscall_latency[probe] = hist($duration);
delete(@syscall_start[tid, probe]);
}
profile:hz:99 /comm == "target_app"/ {
@cpu_samples[ustack] = count();
}
interval:s:10 {
printf("=== System Call Analysis ===\n");
print(@syscall_count);
printf("\n=== Latency Distribution ===\n");
print(@syscall_latency);
printf("\n=== CPU Profile ===\n");
print(@cpu_samples, 10);
clear(@syscall_count);
clear(@syscall_latency);
clear(@cpu_samples);
}
'利点：
- 非常に詳細な分析が可能
- 柔軟な条件指定
- 複数の観点からの同時分析
欠点：
- CPUオーバーヘッドが大きい
- メモリ使用量も多い
- 本番環境では注意が必要
組み合わせて使う実践テクニック
実際の問題解決では、複数のツールを組み合わせて使うことが効果的です。
段階的アプローチの例：
第1段階：Ftraceで概要把握
# まず基本的な問題箇所を特定
echo function_graph > current_tracer
echo 'sys_*' > set_ftrace_filter
echo 1 > tracing_on
# 問題再現
echo 0 > tracing_on
grep -A5 -B5 "long_duration" trace第2段階：bpftraceで詳細分析
# 特定した問題箇所をbpftraceで詳しく調査
sudo bpftrace -e '
tracepoint:syscalls:sys_enter_write {
@start[tid] = nsecs;
@write_size[pid] = hist(args->count);
}
tracepoint:syscalls:sys_exit_write /@start[tid]/ {
@write_latency = hist((nsecs - @start[tid]) / 1000);
delete(@start[tid]);
}
'第3段階：必要に応じてカスタムBPFプログラム
// 特殊な分析要件がある場合のみBPFプログラミング
// 例：特定のデータ構造の詳細な追跡など並行監視の例：
# Terminal 1: Ftraceで全体監視
echo function > current_tracer
echo 1 > tracing_on
# Terminal 2: bpftraceで特定プロセス監視
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_* /pid == 1234/ { @calls = count(); }'
# Terminal 3: 通常の監視ツールも併用
htop -p 1234このような複合的なアプローチにより、問題の全体像から詳細まで効率的に把握できます。
実際のトラブルシューティング事例
ネットワーク遅延の原因究明
問題状況：
Webアプリケーションのレスポンスが突然悪化。pingは正常だが、HTTPレスポンスが異常に遅い。
分析手順：
Step 1: bpftraceでネットワーク系システムコール監視
# ネットワーク関連システムコールの遅延測定
sudo bpftrace -e '
tracepoint:syscalls:sys_enter_sendto {
@send_start[tid] = nsecs;
@send_size = hist(args->len);
}
tracepoint:syscalls:sys_exit_sendto /@send_start[tid]/ {
$duration = nsecs - @send_start[tid];
@send_latency = hist($duration / 1000); // μs
delete(@send_start[tid]);
}
tracepoint:syscalls:sys_enter_recvfrom {
@recv_start[tid] = nsecs;
}
tracepoint:syscalls:sys_exit_recvfrom /@recv_start[tid]/ {
$duration = nsecs - @recv_start[tid];
@recv_latency = hist($duration / 1000); // μs
delete(@recv_start[tid]);
}
interval:s:5 {
printf("=== Network I/O Analysis ===\n");
printf("Send size distribution:\n");
print(@send_size);
printf("Send latency (μs):\n");
print(@send_latency);
printf("Recv latency (μs):\n");
print(@recv_latency);
clear(@send_size); clear(@send_latency); clear(@recv_latency);
}
'Step 2: TCP接続状態の詳細監視
# TCP接続の詳細状態変化を追跡
sudo bpftrace -e '
#include <net/sock.h>
tracepoint:tcp:tcp_probe {
printf("TCP: saddr=%x daddr=%x sport=%d dport=%d snd_cwnd=%d ssthresh=%d\n",
args->saddr, args->daddr, args->sport, args->dport,
args->snd_cwnd, args->ssthresh);
}
tracepoint:tcp:tcp_retransmit_skb {
printf("TCP Retransmit: saddr=%x daddr=%x sport=%d dport=%d\n",
args->saddr, args->daddr, args->sport, args->dport);
@retransmits = count();
}
'発見された問題：
@recv_latencyで受信時に異常な遅延を検出- TCP retransmitが頻発していることを確認
- 特定の接続先でのみ問題が発生
原因：
上流のロードバランサーの設定ミスによるパケットドロップが判明。
メモリリークの動的検出
問題状況：
長時間稼働後にメモリ使用量が異常に増加し、OOM Killerが発動する。
分析手順：
Step 1: malloc/freeの監視
# メモリ割り当て・解放の詳細追跡
sudo bpftrace -e '
uprobe:/lib/x86_64-linux-gnu/libc.so.6:malloc /comm == "target_app"/ {
@malloc_calls = count();
@malloc_size = sum(arg0);
@malloc_hist = hist(arg0);
@malloc_stack[ustack] = count();
}
uprobe:/lib/x86_64-linux-gnu/libc.so.6:free /comm == "target_app"/ {
@free_calls = count();
}
uprobe:/lib/x86_64-linux-gnu/libc.so.6:realloc /comm == "target_app"/ {
@realloc_calls = count();
@realloc_size = sum(arg1);
}
interval:s:30 {
printf("=== Memory Allocation Analysis ===\n");
printf("malloc calls: %d, total size: %d bytes\n", @malloc_calls, @malloc_size);
printf("free calls: %d\n", @free_calls);
printf("realloc calls: %d, total size: %d bytes\n", @realloc_calls, @realloc_size);
printf("Net allocation: %d bytes\n", @malloc_size + @realloc_size);
printf("\nTop allocation stack traces:\n");
print(@malloc_stack, 5);
printf("\nAllocation size distribution:\n");
print(@malloc_hist);
clear(@malloc_calls); clear(@malloc_size); clear(@free_calls);
clear(@realloc_calls); clear(@realloc_size);
clear(@malloc_hist); clear(@malloc_stack);
}
'Step 2: カーネルメモリ割り当ての監視
# カーネル側のメモリ割り当てを監視
sudo bpftrace -e '
tracepoint:kmem:kmalloc {
@kmalloc_calls = count();
@kmalloc_size = sum(args->bytes_alloc);
@kmalloc_by_caller[ksym(args->call_site)] = count();
}
tracepoint:kmem:kfree {
@kfree_calls = count();
}
interval:s:10 {
printf("=== Kernel Memory Analysis ===\n");
printf("kmalloc: %d calls, %d bytes\n", @kmalloc_calls, @kmalloc_size);
printf("kfree: %d calls\n", @kfree_calls);
printf("\nTop kernel allocation sources:\n");
print(@kmalloc_by_caller, 10);
clear(@kmalloc_calls); clear(@kmalloc_size); clear(@kfree_calls);
clear(@kmalloc_by_caller);
}
'発見された問題：
- malloc()呼び出し数に対してfree()呼び出しが明らかに少ない
- 特定のスタックトレースからの割り当てが異常に多い
- カーネル側では問題なし（ユーザー空間の問題と判明）
原因：
特定のライブラリ関数でのメモリリークを特定し、修正版への更新で解決。
ファイルI/O性能問題の解決
問題状況：
データベースアプリケーションの応答が遅く、ディスクI/Oが疑われる。
分析手順：
Step 1: ファイルI/O系システムコールの詳細分析
# ファイルI/Oの詳細パフォーマンス分析
sudo bpftrace -e '
tracepoint:syscalls:sys_enter_read /comm == "mysqld"/ {
@read_start[tid] = nsecs;
@read_size = hist(args->count);
@read_fd[tid] = args->fd;
}
tracepoint:syscalls:sys_exit_read /@read_start[tid]/ {
$duration = nsecs - @read_start[tid];
@read_latency = hist($duration / 1000); // μs
// ファイル記述子別の分析
@read_latency_by_fd[@read_fd[tid]] = hist($duration / 1000);
delete(@read_start[tid]);
delete(@read_fd[tid]);
}
tracepoint:syscalls:sys_enter_write /comm == "mysqld"/ {
@write_start[tid] = nsecs;
@write_size = hist(args->count);
}
tracepoint:syscalls:sys_exit_write /@write_start[tid]/ {
$duration = nsecs - @write_start[tid];
@write_latency = hist($duration / 1000); // μs
delete(@write_start[tid]);
}
tracepoint:syscalls:sys_enter_fsync /comm == "mysqld"/ {
@fsync_start[tid] = nsecs;
@fsync_calls = count();
}
tracepoint:syscalls:sys_exit_fsync /@fsync_start[tid]/ {
$duration = nsecs - @fsync_start[tid];
@fsync_latency = hist($duration / 1000); // μs
delete(@fsync_start[tid]);
}
'Step 2: ブロックI/Oレイヤーでの分析
# ブロックデバイスレベルでの詳細分析
sudo bpftrace -e '
tracepoint:block:block_rq_insert {
@rq_insert[args->dev, args->sector] = nsecs;
@io_size = hist(args->bytes);
@io_count = count();
}
tracepoint:block:block_rq_issue /@rq_insert[args->dev, args->sector]/ {
$queue_time = nsecs - @rq_insert[args->dev, args->sector];
@queue_latency = hist($queue_time / 1000); // μs
@rq_issue[args->dev, args->sector] = nsecs;
}
tracepoint:block:block_rq_complete /@rq_issue[args->dev, args->sector]/ {
$service_time = nsecs - @rq_issue[args->dev, args->sector];
@service_latency = hist($service_time / 1000); // μs
delete(@rq_insert[args->dev, args->sector]);
delete(@rq_issue[args->dev, args->sector]);
}
interval:s:10 {
printf("=== Block I/O Analysis ===\n");
printf("Total I/O operations: %d\n", @io_count);
printf("\nI/O size distribution:\n");
print(@io_size);
printf("\nQueue latency (μs):\n");
print(@queue_latency);
printf("\nService latency (μs):\n");
print(@service_latency);
clear(@io_count); clear(@io_size);
clear(@queue_latency); clear(@service_latency);
}
'発見された問題：
fsync()の呼び出し頻度が異常に高い- 小さなサイズのランダムI/Oが多発
- ディスクのキューイング時間は正常だが、アプリケーション層での遅延が大きい
原因と対策：
- データベースの設定でfsync頻度を最適化
- インデックス設計の見直しでランダムI/Oを削減
- SSDへの移行でランダムI/O性能を向上
このような実践的なトラブルシューティング手法は、「詳解 システム・パフォーマンス 第2版」の様々な章で詳しく解説されています。特に実際の本番環境での活用事例が豊富で、非常に参考になります。
動的トレーシングを業務で活用するために
チーム導入のステップ
動的トレーシングをチーム全体で活用するには、段階的なアプローチが重要です。
Phase 1: 基礎知識の共有
まずはチーム全体で基本概念を理解することから始めましょう。
# チーム学習用の簡単なデモスクリプト
# demo_basic.bt
BEGIN {
printf("=== Dynamic Tracing Demo ===\n");
printf("Monitoring system calls for 30 seconds...\n");
}
tracepoint:syscalls:sys_enter_* {
@syscalls[comm] = count();
}
interval:s:10 {
printf("\nTop processes by syscall count:\n");
print(@syscalls, 5);
clear(@syscalls);
}
END {
printf("Demo completed!\n");
}チーム学習のポイント：
- まずは観察から始める（システムを変更しない）
- 実環境ではなく開発環境で練習
- 簡単なワンライナーから慣れる
- 結果の読み方を共有する
Phase 2: 実用的なスクリプト集の作成
チーム共通で使えるスクリプト集を作成します。
# scripts/web_monitor.bt - Webサーバー監視用
#!/usr/bin/env bpftrace
tracepoint:syscalls:sys_enter_accept* /comm =~ /(httpd|nginx|apache)/ {
@connections = count();
}
# scripts/db_monitor.bt - データベース監視用
#!/usr/bin/env bpftrace
tracepoint:syscalls:sys_enter_read /comm =~ /(mysql|postgres)/ {
@db_reads = count();
@read_bytes = sum(args->count);
}
# scripts/memory_check.bt - メモリリーク検出用
#!/usr/bin/env bpftrace
uprobe:/lib/x86_64-linux-gnu/libc.so.6:malloc {
@malloc_total = sum(arg0);
}Phase 3: 運用ルールとベストプラクティスの確立
# チーム運用ガイドライン例
# 1. 本番環境での実行ルール
# - 必ず事前にテスト環境で動作確認
# - 実行時間は原則10分以内
# - CPU使用率が5%を超える場合は即座に停止
# 2. スクリプト命名規則
# - 目的_対象_日付.bt (例: debug_mysql_20250815.bt)
# - 作成者とレビュー者を明記
# 3. 結果の共有方法
# - 重要な発見は必ずドキュメント化
# - スクリプトと結果をセットで保管継続的監視への組み込み方法
動的トレーシングを日常的な運用監視に組み込む方法を見てみましょう。
自動化されたトレーシングシステムの構築：
#!/bin/bash
# automated_tracing.sh - 自動トレーシングスクリプト
TRACE_DIR="/var/log/tracing"
DATE=$(date +%Y%m%d_%H%M%S)
# ログディレクトリ作成
mkdir -p ${TRACE_DIR}
# システム全体の基本メトリクス収集
timeout 300 bpftrace -e '
tracepoint:syscalls:sys_enter_* {
@syscalls[probe] = count();
}
profile:hz:99 {
@cpu[comm] = count();
}
tracepoint:kmem:kmalloc {
@memory_alloc = sum(args->bytes_alloc);
}
interval:s:60 {
time();
printf("=== System Metrics ===\n");
printf("Top syscalls:\n");
print(@syscalls, 10);
printf("\nTop CPU consumers:\n");
print(@cpu, 10);
printf("Memory allocated: %d bytes\n", @memory_alloc);
printf("\n");
clear(@syscalls);
clear(@cpu);
clear(@memory_alloc);
}
' > ${TRACE_DIR}/system_metrics_${DATE}.log 2>&1 &
# アプリケーション固有の監視
timeout 300 bpftrace -e '
uprobe:/usr/bin/myapp:critical_function {
@app_calls = count();
@call_time[tid] = nsecs;
}
uretprobe:/usr/bin/myapp:critical_function /@call_time[tid]/ {
$duration = nsecs - @call_time[tid];
@app_latency = hist($duration / 1000000); // ms
delete(@call_time[tid]);
}
interval:s:60 {
time();
printf("=== Application Metrics ===\n");
printf("Function calls: %d\n", @app_calls);
printf("Latency distribution:\n");
print(@app_latency);
printf("\n");
clear(@app_calls);
clear(@app_latency);
}
' > ${TRACE_DIR}/app_metrics_${DATE}.log 2>&1 &
echo "Tracing started. Logs in ${TRACE_DIR}"Systemdサービスとしての自動実行：
# /etc/systemd/system/dynamic-tracing.service
[Unit]
Description=Dynamic Tracing Monitor
After=network.target
[Service]
Type=forking
ExecStart=/usr/local/bin/automated_tracing.sh
ExecStop=/usr/bin/pkill -f bpftrace
Restart=always
RestartSec=60
User=root
[Install]
WantedBy=multi-user.targetアラート機能付きの監視：
#!/bin/bash
# alert_tracing.sh - 閾値監視とアラート機能
# 閾値設定
CPU_THRESHOLD=80
MEMORY_THRESHOLD=1000000000 # 1GB
LATENCY_THRESHOLD=1000 # 1秒
bpftrace -e '
profile:hz:99 {
@cpu[comm] = count();
}
uprobe:/usr/bin/myapp:slow_function {
@start[tid] = nsecs;
}
uretprobe:/usr/bin/myapp:slow_function /@start[tid]/ {
$duration = (nsecs - @start[tid]) / 1000000; // ms
if ($duration > '$LATENCY_THRESHOLD') {
printf("ALERT: Slow function detected: %d ms\n", $duration);
}
delete(@start[tid]);
}
interval:s:30 {
$max_cpu = 0;
$top_process = "";
// CPU使用率チェック（簡易版）
// 実際の実装ではより詳細な計算が必要
if ($max_cpu > '$CPU_THRESHOLD') {
printf("ALERT: High CPU usage detected: %s (%d%%)\n", $top_process, $max_cpu);
system("echo \"High CPU Alert\" | mail -s \"Performance Alert\" admin@example.com");
}
clear(@cpu);
}
' | while read line; do
echo "$(date): $line"
if [[ "$line" =~ "ALERT:" ]]; then
logger "Dynamic Tracing Alert: $line"
fi
doneさらなるスキルアップのために
動的トレーシングのスキルをさらに向上させるための学習方向性をご紹介します。
1. 高度なBPFプログラミング
bpftraceで物足りなくなったら、C言語でのBPFプログラミングに挑戦してみましょう：
// sample_bpf.c - カスタムBPFプログラム例
#include <linux/bpf.h>
#include <bpf/bpf_helpers.h>
struct {
__uint(type, BPF_MAP_TYPE_HASH);
__uint(max_entries, 1024);
__type(key, __u32);
__type(value, __u64);
} process_map SEC(".maps");
SEC("tracepoint/syscalls/sys_enter_openat")
int trace_openat(struct trace_event_raw_sys_enter *ctx) {
__u32 pid = bpf_get_current_pid_tgid() >> 32;
__u64 *count = bpf_map_lookup_elem(&process_map, &pid);
if (count) {
__sync_fetch_and_add(count, 1);
} else {
__u64 initial = 1;
bpf_map_update_elem(&process_map, &pid, &initial, BPF_ANY);
}
return 0;
}
char LICENSE[] SEC("license") = "GPL";2. 他のツールとの連携
# Prometheus + Grafanaとの連携例
bpftrace -e '
interval:s:10 {
printf("cpu_usage{process=\"%s\"} %d\n", "myapp", @cpu_count);
clear(@cpu_count);
}
' | while read line; do
curl -X POST http://prometheus-pushgateway:9091/metrics/job/bpftrace \
--data-binary "$line"
done3. クラウド環境での活用
# Kubernetes環境でのPod監視
kubectl exec -it monitoring-pod -- bpftrace -e '
tracepoint:syscalls:sys_enter_* /comm =~ /container_process/ {
@syscalls[comm] = count();
}
'4. セキュリティ分析への応用
# 不審なプロセス動作の検出
bpftrace -e '
tracepoint:syscalls:sys_enter_execve {
printf("EXEC: %s -> %s\n", comm, str(args->filename));
}
tracepoint:syscalls:sys_enter_connect {
printf("NETWORK: %s attempting connection\n", comm);
}
'これらの高度な技術については、「詳解 システム・パフォーマンス 第2版」で詳しく学ぶことができます。特に第15章「BPF」では、基礎から応用まで実践的な事例とともに解説されており、本格的なBPF活用への道筋が明確に示されています。
BPF、bpftrace、Ftraceという強力な動的トレーシング技術を使いこなすことで、従来では見えなかったシステムの詳細な動作を把握し、効果的な性能改善やトラブルシューティングが可能になります。
まずは簡単なワンライナーから始めて、徐々に複雑な分析にチャレンジしてみてください。きっと、システム分析の新しい世界が開けることでしょう！
皆さんのシステムがより快適に、より効率的に動作するよう、心から応援しています。
コメント