原因不明の遅延を追う:標準ツールが嘘をつくとき
計算上はすべて正常に見えます。topはCPU使用率5%を示し、iostatは無視できるほどのディスク待機を報告しているのに、APIのレスポンスタイムは数百ミリ秒に跳ね上がっています。標準的なユーザースペースのツールでボトルネックが見つからない場合、問題はカーネル内に潜んでいる可能性があります。ここで、Ftraceが最も強力な診断ツールとなります。
straceのような従来のトレーサーはロジックのデバッグには最適ですが、負荷が高いのが難点です。トラフィックの多い本番環境のプロセスでstraceを実行すると、速度が10倍から50倍も低下することがあります。Ftrace(”Function Tracer”)は、Linuxカーネル(バージョン2.6.27以降)に直接組み込まれています。これは最小限のオーバーヘッド(通常1〜2%未満)で動作し、パフォーマンスを損なうことなくシステムコールやスケジューリングの遅延をリアルタイムで観察できます。
アーキテクチャ:Ftraceが他と異なる理由
Ftraceはスタンドアロンのバイナリではなく、トレーシングフレームワークです。関数の呼び出し状況の追跡、実行時間の計測、そしてプロセスがハードウェアとどのように相互作用しているかを正確に把握できます。perfはハイレベルなプロファイリングに優れていますが、Ftraceは特定のレイテンシスパイクの背後にある「理由」を見つけるのに適しています。プロセスが特定のネットワークドライバによってブロックされているのか、あるいはスケジューラが非効率なコンテキストスイッチを行っているのかを確認できます。
50台以上の高トラフィックノードを管理してきた経験から、カーネルレベルのトレーシングは精密な作業であることを学びました。トレースは慎重にフィルタリングする必要があります。適切なフィルタがないと、負荷の高いサーバーでは10秒足らずで500MBものトレースデータが生成され、関連するイベントを見つけるのがほぼ不可能になります。
初期化:Tracefsマウントの場所を特定する
Ubuntu 22.04やAlmaLinux 9のような最新のディストリビューションでは、Ftraceがデフォルトで有効になっています。これは仮想ファイルシステムを介してユーザーとやり取りします。カーネル4.1以降、これは通常tracefsですが、互換性のために依然としてdebugfs内にマウントされていることもよくあります。
次のコマンドでトレーシングディレクトリを確認してください:
ls /sys/kernel/tracing
そのパスが存在しない場合は、レガシーな場所を試してください:
ls /sys/kernel/debug/tracing
ディレクトリが空の場合は、手動でdebugファイルシステムをマウントする必要があるかもしれません:
mount -t debugfs nodev /sys/kernel/debug
実行:調査対象を絞り込む
Ftraceは仮想ファイルを使用してロジックを制御します。これらのファイルに文字列をエコーすることで設定を行います。まず、使用しているカーネルがサポートしているトレーサーを確認します。
cat /sys/kernel/tracing/available_tracers
# 期待される出力: function_graph function blk mmiotrace nop
1. コールスタックの可視化
function_graphトレーサーはデバッグの黄金律です。これは、入り口と出口の時間を含む、すべてのカーネル関数呼び出しのC言語スタイルの視覚的階層を提供します。これにより、どのサブ関数が実際に親関数の速度を低下させているかを簡単に特定できます。
# グラフ・トレーサーを有効にする
echo function_graph > /sys/kernel/tracing/current_tracer
2. ピンポイントなフィルタリング
膨大なデータに埋もれないよう、スコープを絞ります。ディスクレイテンシが疑われる場合は、仮想ファイルシステム(VFS)レイヤーに焦点を当てます。ワイルドカードを使用して、関連するすべての関数をキャッチできます。
# トレース対象をVFS関連の関数に限定する
echo 'vfs_*' > /sys/kernel/tracing/set_ftrace_filter
特定の動作不良プロセスを特定している場合は、PIDでフィルタリングして、他のサービスからのバックグラウンドノイズを無視します:
# 1234を実際のプロセスIDに置き換える
echo 1234 > /sys/kernel/tracing/set_ftrace_pid
3. データのキャプチャ
トレーサーは瞬時に切り替えることができます。設定中はオフにしておき、異常をキャプチャするために5〜10秒間だけオンにするのがベストプラクティスです。
# キャプチャを開始
echo 1 > /sys/kernel/tracing/tracing_on
# ラグが発生するまで待ち、直ちに無効化する
echo 0 > /sys/kernel/tracing/tracing_on
分析:決定的な証拠を見つける
キャプチャされたデータはtraceファイルに保存されます。less -Sを使用して表示してください。-Sフラグは長い行の折り返しを防ぎ、視覚的な階層構造を維持するために不可欠です。
less -S /sys/kernel/tracing/trace
出力は明確な実行タイムラインを提供します:
# CPU 実行時間 関数呼び出し
# | | | | | | |
0) | vfs_write() {
0) | rw_verify_area() {
0) 0.124 us | security_file_permission();
0) 0.512 us | }
0) 1.230 us | }
レイテンシシンボルの解読
Ftraceは、duration列の特定のマーカーを使用して、遅い関数を自動的にフラグ付けします:
+: 10マイクロ秒(us)以上!: 100マイクロ秒以上#: 1ミリ秒(ms)以上*: 10ミリ秒以上@: 100ミリ秒以上
ハイパフォーマンスな環境では、日常的なファイル書き込み操作で!や#が表示されるのは危険信号です。かつて、サードパーティのセキュリティモジュールがパケット処理の全ステップに2ミリ秒の遅延(#)を追加していたサーバーをデバッグしたことがありますが、Ftraceを使えば一目で原因が判明しました。
デバッグ後のクリーンアップ
トレーサーを有効にしたままにしないでください。tracing_onを0に設定しても、フィルタやトレーサーの選択内容はメモリに残ります。次の管理者がクリーンな状態で作業できるよう、すべてをリセットしてください。
# デフォルト状態にリセットする
echo nop > /sys/kernel/tracing/current_tracer
echo > /sys/kernel/tracing/set_ftrace_filter
echo > /sys/kernel/tracing/set_ftrace_pid
プロのヒント:Trace-cmdラッパー
echoコマンドが手動すぎると感じる場合は、trace-cmdユーティリティを使用してください。tcpdumpに似たワークフローで、記録とレポート作成のプロセスを簡素化できます。
# インストール
sudo apt install trace-cmd
# コマンドの特定の関数呼び出しを記録する
sudo trace-cmd record -p function_graph -g vfs_write ls /home
# レポートを生成する
trace-cmd report
Ftraceは広範なフレームワークですが、これらの基本を押さえるだけで「原因不明」のレイテンシ問題の90%は解決できます。ステージング環境のVMでフィルタリング構文に慣れておけば、次に本番環境のメトリクスが異常を示したときにすぐに対応できるでしょう。

