本番環境におけるボトルネックの謎
先週の火曜日、ある本番サーバーで1つのバックグラウンドワーカーがCPUコアを99%消費し始めました。APIのレスポンスタイムは、軽快な150msから一気に4秒以上に跳ね上がりました。ログは沈黙しており、表面上はアプリケーションは動作しているように見えましたが、とにかく動作が非常に遅かったのです。まるでコードが計算上のブラックホールに落ちてしまったかのようでした。
多くの人が最初に思いつくのは、サービスの再起動でしょう。再起動は時間を稼ぐことはできますが、バグそのものを修正するわけではありません。ロジックが非効率であれば、そのCPUスパイクは必ず再発します。これを根本的に解決するには、具体的にどの関数がサイクルを消費しているのかを確認する必要がありました。一般的なモニタリングツールは、プロセスが「忙しい」ことは教えてくれますが、*なぜ*忙しいのかを教えてくれることは滅多にありません。
従来のツールでは不十分な理由
私たちは通常、まず top や htop を使います。これらは一目で状況を把握するには最適ですが、プロセスレベルの情報しか提供してくれません。myserver.py が100%で張り付いていることはわかっても、その原因が複雑な正規表現なのか、遅いJSONシリアライズなのか、あるいはサードパーティ製ライブラリ内の密なループなのかまではわかりません。
パフォーマンスの低下は、一般的に次の3つの問題に起因します:
- CPUホットスポット: 関数が必要以上に数千回も実行されている。
- システムコールオーバーヘッド: 頻繁すぎる4KBディスク書き込みや冗長なネットワークポーリングなどにより、アプリのコンテキストスイッチが多発している。
- キャッシュミス: データ構造がL1/L2キャッシュに最適化されていないため、CPUがRAMからのデータを待ってアイドル状態になっている。
これらを解決するには、エンジンを停止させることなく中身を覗き見ることができるツールが必要です。
現場で使われるツール:選択肢の比較
perf の詳細に入る前に、高トラフィック環境で他の一般的な選択肢がなぜ不十分なのかを知っておくことが役立ちます。
Strace
strace はシステムコールの追跡に最適です。アプリがファイルロックで停止している場合、 strace で特定できます。しかし、オーバーヘッドが非常に大きいです。すべてのシステムコールをインターセプトするため、アプリの速度が20倍以上低下することもあります。負荷の高い本番サーバーで strace を実行すると、遅いサービスを完全に停止させてしまう恐れがあります。
GDB (GNUデバッガ)
GDBをアタッチすれば、実行を停止してスタックを検査できます。これは外科的な精密さを持ちますが、非常に侵襲的です。本番環境でプロセスを一時停止するとトラフィックの処理が止まってしまうため、ユーザーが待機している状況では現実的な選択肢ではありません。
Perf (Linuxプロファイラ)
perf はLinuxカーネル自体に組み込まれています。すべての動作をインターセプトするのではなく、「サンプリング」という手法を用います。数ミリ秒ごとに、CPUが何をしているかの小さなスナップショットを撮ります。これにより、オーバーヘッドを驚驚的に低く(通常1%未満)抑えることができ、稼働中のサーバーでも安全に使用できます。ハードウェアカウンタとソフトウェアスタックを同時に追跡可能です。
Linux Perfを使いこなして深い洞察を得る
ほとんどのディストリビューションには perf がプリインストールされていませんが、通常はコマンド一つでインストールできます。実行中のカーネルとバージョンが一致していることを確認してください。
# Ubuntu/Debianの場合
sudo apt update
sudo apt install linux-tools-common linux-tools-$(uname -r)
# RHEL/AlmaLinuxの場合
sudo yum install perf
Perf Topによるリアルタイムモニタリング
サーバーが悲鳴を上げているとき、 perf top は最高の味方です。 top のように動作しますが、プロセス名の代わりに関数シンボルを表示します。
sudo perf top -p [PID]
リストの上部にあるシンボルを探してください。 __strstr_sse2_unaligned が見えるなら、アプリは非効率な文字列検索に陥っている可能性があります。 zlib_compress が画面の60%を占めているなら、圧縮処理がボトルネックであることは明らかです。
解析のためのデータキャプチャ
真の威力は perf record で発揮されます。これはシステムの状態を perf.data ファイルに保存し、後で検査できるようにします。私は通常、信頼できる統計サンプルを得るために30秒間のウィンドウをキャプチャします。
# -g はコールグラフを有効化、-F 99 は安全なサンプリング周波数を設定
sudo perf record -g -F 99 -p [PID] -- sleep 30
完了したら、 perf report を実行します。先ほど使用した -g フラグにより、関数を展開して完全なコールチェーンを表示できます。どの関数が重い関数を呼び出したのか、時間がどこで消費されたのかをようやく正確に特定できます。
sudo perf report
ケーススタディ:PHPサーバーの救出
数ヶ月前、Ubuntu 22.04上で4GBのRAMを搭載したレガシーなPHP-FPMサーバーが、ランダムに10分間のCPUスパイクを起こすようになりました。すべてが順調に見えていたのに、突然ロードアベレージが1.0から40.0に跳ね上がるのです。
スパイクが発生した瞬間に perf record -g を実行しました。データの結果、全CPU時間の45%がXMLパースに費やされていることが判明しました。調べてみると、外部ベンダーが通常の100KBのスニペットではなく、50MBもの巨大なXMLを送り始めていたのです。SimpleXMLがその巨大なファイルを一度にメモリに読み込もうとしていました。これをストリーミング方式の XMLReader に置き換えたところ、CPU使用率は即座に100%からわずか5%へと激減しました。
perf がなければ、さまざまなPHPスクリプトを試行錯誤して数日を費やしていたでしょう。しかしこれを使えば、60秒で答えが出ました。
プロファイリングのベストプラクティス
長年のプロファイリング経験から、プロセスをスムーズに進めるための3つのルールを見つけました。
1. デバッグシンボルを省略しない
レポートに 0x00007f823 のような謎の16進数アドレスが表示される場合、バイナリが「ストリップ(stripped)」されています。実際の関数名を見るには、デバッグシンボル( libc6-dbg など)が必要です。GoやRustでビルドする場合、将来的にプロファイリングを行う予定があるなら、本番ビルドのパイプラインでシンボルを削除していないか確認してください。
2. 周波数のスイートスポット
サンプリング周波数をちょうど100Hzや1000Hzにするのは避けましょう。 -F 99 を使うのは、システムクロックや定期的なカーネルタスクとの同期を避けるための古典的なテクニックです。システムのハートビートと同じ間隔でサンプリングすると、データが偏り、信頼性が低くなってしまいます。
3. フレームグラフで可視化する
テキストレポートも良いですが、複雑なアプリにはフレームグラフ(Flame Graphs)が欠かせません。 perf.data をインタラクティブなSVGに変換でき、各ボックスの幅が使用されたCPU時間の割合を示します。
# データをスタックトレースに変換
sudo perf script > out.perf
# Brendan Gregg氏のスクリプトを使用してSVGを生成
./stackcollapse-perf.pl out.perf > out.folded
./flamegraph.pl out.folded > flamegraph.svg
アプリのリソース使用状況を視覚的に捉えることで、ボトルネックを無視できなくなります。開発チーム全体にとって「目から鱗が落ちる瞬間」になることも少なくありません。
結論
コードの最適化とは、より懸命に働くことではなく、正しい場所を見ることです。Linux perf を使えば、コード、ランタイム、そしてカーネルの抽象化レイヤーの先を見通すことができます。まずは今日、開発マシンで perf top を実行することから始めてみてください。次に本番サーバーが悲鳴を上げたとき、あなたは絶対的な自信を持って「手術」に臨むことができるはずです。

