トレースとデバッグ

カバー範囲: ftrace (function/function_graph) → tracepoints → kprobes → perf events → eBPF トレース (bpftrace/bcc) → kdump/crash → KGDB → printk とダイナミックデバッグ カーネルバージョン: 2.6 ~ 6.x

ftrace: カーネル内蔵トレーサー

Function Tracer

# 利用可能なトレーサーの一覧を表示
cat /sys/kernel/debug/tracing/available_tracers

# function: すべての関数呼び出しをトレース (オーバーヘッドが非常に高いので、デバッグ専用)
echo function > /sys/kernel/debug/tracing/current_tracer
echo "tcp_v4_rcv" > /sys/kernel/debug/tracing/set_ftrace_filter
echo 1 > /sys/kernel/debug/tracing/tracing_on
cat /sys/kernel/debug/tracing/trace_pipe

Function Graph: 実行時間を伴う

echo function_graph > /sys/kernel/debug/tracing/current_tracer
# 出力例:
# 0)               |  tcp_v4_rcv() {
# 0)   0.234 us    |    tcp_checksum_complete();
# 0)   0.567 us    |    tcp_v4_do_rcv() {
# 0)   1.234 us    |      tcp_rcv_established();
# 0)   2.345 us    |    }
# 0)   3.456 us    |  }

動的 ftrace: 実行時にオン/オフ

# 動的関数プローブ (debugfs を介して):
echo 'p:tcp_probe tcp_rcv_established state+0x12(%di):u8' \
     > /sys/kernel/debug/tracing/kprobe_events
echo 1 > /sys/kernel/debug/tracing/events/kprobes/tcp_probe/enable
cat /sys/kernel/debug/tracing/trace_pipe

Tracepoints: 安定したプローブポイント

# 利用可能なすべての tracepoint
ls /sys/kernel/debug/tracing/events/
# sched/  syscalls/  net/  block/  irq/  timer/  ...

# すべての exec 呼び出しをトレース:
echo 1 > /sys/kernel/debug/tracing/events/syscalls/sys_enter_execve/enable
cat trace_pipe

# スケジューラーをトレース:
echo 1 > /sys/kernel/debug/tracing/events/sched/sched_switch/enable
echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable

# ブロック I/O をトレース:
echo 1 > /sys/kernel/debug/tracing/events/block/block_rq_issue/enable
echo 1 > /sys/kernel/debug/tracing/events/block/block_rq_complete/enable

Perf Events: ハードウェアパフォーマンスカウンター

# perf stat: プログラム実行中のハードウェアカウンターを統計
perf stat -e cycles,instructions,cache-misses,branch-misses -- ls /

# perf record: サンプリング (プロファイリンググラフの生成元)
perf record -e cycles -g -- sleep 10
perf report

# perf top: リアルタイムのホットスポット
perf top -e cycles

# ハードウェアイベント:
#   cycles, instructions, cache-references, cache-misses,
#   branch-instructions, branch-misses, bus-cycles,
#   stalled-cycles-frontend, stalled-cycles-backend

eBPF トレース: bpftrace

# bpftrace: DTrace スタイルの高レベルトレース言語
# 一行トレース:
bpftrace -e 'kprobe:vfs_read { @[comm] = count(); }'
bpftrace -e 'tracepoint:syscalls:sys_enter_openat { printf("%s %s\n", comm, str(args->filename)); }'

# ヒストグラム:
bpftrace -e 'kprobe:vfs_read { @usecs[comm] = hist(nsecs / 1000); }'
bpftrace -e 'kprobe:submit_bio { @latency = hist(nsecs); @count = count(); }'

# 集計:
bpftrace -e 'kretprobe:vfs_read /retval > 0/ { @bytes[comm] = sum(retval); }'

bcc ツールセット

# bcc: Python + BPF のプリコンパイル済みツールセット (/usr/share/bcc/tools/)
execsnoop        # すべての exec() をトレース
opensnoop        # すべての open() をトレース
biolatency       # ブロック I/O レイテンシのヒストグラム (デバイス/プロセス別)
tcptop           # TCP トラフィックのリアルタイムトップ
tcpretrans       # TCP 再送統計
cachestat        # ページキャッシュのヒット率
runqlat          # スケジューラーのレイテンシ (CPU を待つ時間)

printk とダイナミックデバッグ

printk ログレベル

// include/linux/kern_levels.h
#define KERN_EMERG   "<0>"  // システムクラッシュ
#define KERN_ALERT   "<1>"  // 即時対応が必要
#define KERN_CRIT    "<2>"  // 深刻なエラー
#define KERN_ERR     "<3>"  // エラー
#define KERN_WARNING "<4>"  // 警告
#define KERN_NOTICE  "<5>"  // 通常だが重要
#define KERN_INFO    "<6>"  // 情報
#define KERN_DEBUG   "<7>"  // デバッグ

// 実行時にコンソールログレベルを制御:
echo 4 > /proc/sys/kernel/printk  // ERROR 以上のみを表示

Dynamic Debug (dyndbg)

# 実行時に特定のモジュールのデバッグ出力を有効化 (再コンパイル不要)
echo "module nfs file fs/nfs/* +p" > /sys/kernel/debug/dynamic_debug/control
echo "func tcp_rcv_established +p" > /sys/kernel/debug/dynamic_debug/control

# 現在有効なダイナミックデバッグエントリを表示
cat /sys/kernel/debug/dynamic_debug/control | grep "=p"

kdump: クラッシュダンプ

# 1. キャプチャ用カーネルをロード (ブート時または実行時)
kexec -p /boot/vmlinuz-capture --initrd=/boot/initrd-capture \
      --command-line="root=... irqpoll nr_cpus=1 reset_devices"

# 2. panic をトリガー → キャプチャ用カーネルが起動 → vmcore が生成
# 3. 解析:
crash /usr/lib/debug/boot/vmlinux-$(uname -r) /var/crash/vmcore

# crash コマンド:
crash> bt          # すべてのプロセスのカーネルスタック
crash> log         # panic 時の printk バッファ
crash> ps          # panic 時のプロセスリスト
crash> foreach bt  # すべてのタスクのスタックバックトレース

KGDB: カーネルデバッガー

シリアル経由でカーネルのリモートデバッグ (gdb server に類似):
  → ブレークポイントの設定、ステップ実行、レジスタの読み取り、メモリ読み取り
  → ただし、開発/デバッグ環境でのみ使用可能 (特殊な設定が必要)

有効化: kgdboc=ttyS0,115200 kgdbwait (ブートパラメータ)
接続: gdb vmlinux → target remote /dev/ttyS0

実践: パフォーマンス問題の診断手順

1. perf top で CPU のホットスポットを確認
2. bpftrace/bcc でレイテンシ分布を確認 (biolatency, runqlat, tcpretrans)
3. ftrace function_graph で重要パスの呼び出し時間をトレース
4. tracepoint で仮説を検証 (例: sched_switch の頻度が高すぎるか?)
5. eBPF でカスタムツールを記述 (必要な場合)

参考

• ソースコード⁠: kernel/trace/, kernel/kexec_core.c, kernel/printk/
• 書籍⁠: 「BPF Performance Tools」(Brendan Gregg 著)、「Systems Performance」(同著者)
• ツール⁠: perf, bpftrace, bcc, crash, trace-cmd (ftrace のフロントエンド)

キーワード: ftrace, function_graph, tracepoint, kprobe, perf, bpftrace, bcc, kdump, crash, dynamic debug, KGDB