CPU急騰の謎
私が管理していたPythonデータサービスが、先日突然暴走しました。秒間50リクエストという低負荷の状態でも、8つのコアすべてでCPU使用率が98%に達したのです。リクエストのレイテンシは軽快な20msから2秒以上に跳ね上がり、アプリはほとんど使い物にならなくなりました。topやhtopといった標準ツールを使えば、原因となっているプロセスを特定するのは簡単ですが、なぜそのプロセスが苦戦しているのかまでは教えてくれません。どのスクリプトが実行されているかは分かっていても、具体的にどの関数やライブラリの呼び出しがサイクルを浪費しているのか、見当もつきませんでした。
ほとんどの開発者は、いつかこの壁にぶつかります。「CPU高負荷」という症状は見えていても、根本原因は何千行ものコードやサードパーティの依存関係の中に埋もれています。このような場合、従来のロギングは役に立ちません。すべての関数呼び出しを追跡するために十分なログを追加すれば、オーバーヘッドが大きくなりすぎて、アプリケーションは完全に停止してしまうでしょう。たとえTunedプロファイルでLinuxのパフォーマンスを自動最適化していても、こうしたコードレベルの停滞は防げません。
標準的な監視ツールの限界
パフォーマンスのボトルネックは、通常「ホットパス（hot paths）」と呼ばれる、1秒間に数千回実行されるコードセクションに潜んでいます。topはプロセス活動ের有用なスナップショットを提供しますが、深みに欠けます。straceを使用すればシステムコールを確認できますが、Straceのオーバーヘッドなしでカーネルのレイテンシを診断するような手法を使わない限り、ユーザー空間のロジック内だけで発生している事象はすべて見落としてしまいます。
従来のプロファイラによるテキスト主体のレポートは、多くの場合、情報量に圧倒されてしまいます。5,000行のテキストファイルを精査して、親関数と子関数の関係を可視化するのはほぼ不可能です。たとえば、mallocがCPU時間の20%を占めていることは分かっても、ビジネスロジックのどの部分がその過剰なメモリ割り当てを引き起こしたのかを特定するのは、結局のところ推測に頼ることになります。コンテキストがなければ、最適化は暗闇の中で鉄砲を撃つようなものです。
プロファイリング手法の比較
ワークフローを決定する前に、いくつかの一般的なLinuxツールを比較検討しました。
- Gprof: 特定のフラグを立ててコードを再コンパイルする必要があります。侵襲的であり、最近の共有ライブラリではうまく機能しないことが多いです。
- Valgrind (Callgrind): 非常に詳細なデータが得られますが、アプリケーションの動作が10倍から50倍も遅くなります。これでは本番環境のトラブルシューティングには使えません。
- Perf: Linuxプロファイリングの決定版です。軽量でハードウェアカウンタを活用し、コードの変更を一切必要としません。
最適なワークフローは、perfの生データとFlame Graphの可視化を組み合わせすることです。これらのグラフは、bpftraceなどの高度なツールと同様に、複雑なスタックトレースをインタラクティブなSVG画像に変換します。ログを読み込む代わりに、CPUがどこで時間を費やしているのかを一目で正確に把握できるようになります。
解決策：perfによるFlame Graphの作成
まず、カーネルバージョンに一致するlinux-toolsパッケージが必要です。UbuntuまたはDebianでは、次のコマンドを実行します。
sudo apt update
sudo apt install linux-tools-common linux-tools-$(uname -r) -y次に、Brendan Gregg氏が作成したFlameGraphツールキットをクローンします。これらのPerlスクリプトは、プロファイラの出力を理解しやすい画像に変換するための業界標準となっています。
git clone https://github.com/brendangregg/FlameGraph
cd FlameGraphステップ1：プロファイルデータのキャプチャ
オーバーヘッドを低く抑える鍵はサンプリングです。すべてのイベントを記録するのではなく、perfは特定の周波数でCPUをサンプリングします。私は99Hzを使用しています。これは高い精度を得るのに十分な頻度であり、かつ一般的な100Hzのシステムタイマーとの重複を避けることで、サンプリングバイアスを防ぐことができます。
私の本番用Ubuntu 22.04サーバーでは、この方法によりデバッグ時間を数時間から数分に短縮できました。特定のPIDに対して30秒間のデータを記録するには、次のコマンドを実行します。
sudo perf record -F 99 -p [YOUR_PID] -g -- sleep 30注：関数の階層構造を表示するために必要なコールグラフ記録を有効にするため、-gフラグは必須です。
ステップ2：生データの処理
生成されたperf.dataファイルはバイナリ形式であるため、人間が読むことはできません。FlameGraphスクリプトが解析できるテキスト形式に、次のコマンドで変換します。
sudo perf script > out.perfステップ3：可視化の生成
最後に、データをスタック集約スクリプトにパイプし、SVGジェネレーターに渡します。
./stackcollapse-perf.pl out.perf > out.folded
./flamegraph.pl out.folded > cpu_usage.svg結果の読み取り方
ブラウザでcpu_usage.svgを開くと、「炎」のような景観が表示されます。ナビゲート方法は以下の通りです。
- Y軸: スタックの深さを表します。一番上のボックスは、現在CPU上で実行されている関数です。その下の各ボックスは、その関数を呼び出した親関数の系譜を表します。
- X軸: これは時間を表すものではありません。ボックスの幅は、サンプル内でのその関数の出現頻度を示します。ボックスが広いほど、CPUがそのコードパスでより多くの時間を費やしたことを意味します。
- 色: 通常、関数やコードの種類（カーネル空間かユーザー空間かなど）を区別するために使用されます。色の違いは「熱」やエラーを示すものではありません。
私のケースでは、ループ内のjson.loads()に巨大で幅の広いボックスがあるのを見つけました。JSONとYAMLを自在に操る過程で、アプリケーションは静的な2MBの設定ファイルをキャッシュする代わりに、リクエストが来るたびに再パースしていたのです。json.loadsがグラフ全体の幅の約40%を占めていたため、Flame Graphによってこのミスは一目瞭然となりました。
本番環境でのベストプラクティス
稼働中のシステムでツールを実行するには注意が必要です。安定性を維持するために、私は次の3つのルールを守っています。
- 周波数を下げる: CPU使用率がすでに95%に張り付いている場合は、Linux OOM Killerによるプロセス強制終了を防ぐため、
-F 99の代わりに-F 49を使用してください。 - 権限の調整: 非特権ユーザーはカーネルシンボルを参照できないことがよくあります。
sudo sysctl kernel.perf_event_paranoid=-1を実行することで、一時的にアクセスを許可できます。 - シンボルを保持する: グラフに16進数のアドレス（
0x00007f...など）が表示される場合、バイナリが「ストリップ（stripped）」されています。実際の関数名を表示するには、デバッグシンボル付きのビルドを使用するか、-dbgsymパッケージをインストールしてください。
パフォーマンスを可視化することで、「推測」から「確信」へと変わりました。データパイプライン全体をリファクタリングする代わりに、1つの関数にシンプルなキャッシュを追加するだけで済みました。CPU負荷は即座に90%から15%へと低下しました。Linuxサーバーを管理しているなら、perfとFlame Graphをマスターすることは、複雑なパフォーマンス劣化を退治するための最も効果的な方法です。
