要点:標準的な Prometheus プロセスが 160% を超える CPU を消費していました。OpenResty XRay で未修正の Go プロセスをガイド付き分析したところ、Go のガベージコレクション(GC)が CPU 時間の 99% 以上を占めていることが判明しました。GC 負荷の主な原因は loadWAL 関数で、先行書き込みログ(WAL)からデータを読み込む際に大量の GC オブジェクトを高速に割り当てています。最も多くのオブジェクトを割り当てるこのコードパスだけで、新規割り当て総数の 19% 以上を占めています。以下で特定の手順を詳しく説明します。

このチュートリアルでは、OpenResty XRay を使用して Prometheus アプリケーション内で最も CPU を消費する Go(golang)コードパスを特定する方法を段階的にご説明いたします。これらのコードパスは最も多くの CPU 時間を消費し、Prometheus アプリケーションのパフォーマンスに重大な影響を与えています。

問題:高 CPU 使用率

まず、top コマンドを実行して CPU 使用状況を確認します。この Prometheus プロセスが CPU コアの 160% を超えて消費していることがわかります。

top コマンドの出力:prometheus プロセスが CPU 160% を消費

次に ps コマンドで完全なコマンドラインを確認すると、これは Linux ディストリビューション付属の標準 Prometheus バイナリ実行ファイル(/usr/bin/prometheus)であり、一切改変していないことがわかります。

ps コマンドの出力:標準 Prometheus バイナリ /usr/bin/prometheus

CPU 使用率が最も高い Go コードパスを特定

OpenResty XRay を使用して、この未修正のプロセスをリアルタイムで分析します。Web コンソールで対象マシンを確認したら、「Guided Analysis」ページに移動し、システムが診断可能な問題タイプの中から「High CPU usage」を選択します。

OpenResty XRay のガイド付き分析で診断可能な問題タイプ一覧。High CPU usage を選択

続いて、先ほど top で確認した Go プロセス(PID 50785、CPU 使用率 125%、実行ファイルは /usr/bin/prometheus)を選択します。言語レベルは「Go」を選び、最大分析時間はデフォルトの 300 秒のままにして、分析を開始します。

OpenResty XRay で対象の Go プロセスを選択:PID 50785、CPU 使用率 125%

OpenResty XRay は対象プロセスに対して複数ラウンドのサンプリングを継続的に実行します。この例では 2〜3 ラウンドで十分で、その後システムが自動的に分析レポートを生成します。

これが分析対象の問題タイプ、「CPU」です。

Screenshot

Go のガベージコレクションが CPU 時間の 99% 以上を消費していることが確認できます。

Screenshot

例えば、このガベージコレクションを実行している Go コードパスが CPU 時間の 21% 以上を占めています。

Screenshot

scanobject は Go 言語のランタイム関数で、ガベージコレクションの作業を担当します。ヒープメモリ内で GC オブジェクトを探し、それらがアクセスできるオブジェクトをすべてマークします。

Screenshot

gcDrain 関数は、ワークキュー内の GC オブジェクトをすべてマークして除去する役割を果たします。

Screenshot

多数の GC オブジェクトを急速に割り当てると、GC のオーバーヘッドが非常に高くなります。そのため、レポートではオブジェクトを最も多く、最も速く割り当てている Go コードパスが示されています。

Screenshot

最も多くの GC オブジェクトを割り当てているこの Go コードパスを見てみましょう。

Screenshot

loadWAL 関数は、Prometheus の先行書き込みログからデータをロードします。

Screenshot

Series 関数は、バッファから時系列データをデコードし、指定されたスライスに追加します。

Screenshot

slicebytetostring 関数は、バイトスライスを文字列に変換します。

Screenshot

「More」をクリックすると、さらに詳細が表示されます。

Screenshot

このコードパスは、Go GC オブジェクト割り当てのフレームグラフから自動的に導き出されたものです。

Screenshot

以下は、現在の問題についてのより詳細な説明と提案です。

Screenshot

loadWAL 関数について言及しています。

Screenshot

この関数は先行書き込みログからデータをロードします。

Screenshot

また、Series 関数についても言及しています。

Screenshot

そして slicebytetostring 関数についても触れています。

Screenshot

先ほどのコードパスに戻りましょう。loadWAL 関数の緑色のボックスにマウスカーソルを合わせてください。

Screenshot

この関数のソースファイル名が表示されます。ツールチップにはファイルの完全なパスも表示されています。

Screenshot

ソースコードの行番号は 141 です。

Screenshot

このアイコンをクリックすると、関数の完全な Go ソースファイルパスがコピーされます。

Screenshot

vim エディタを使用してソースファイルを開き、このファイル内の golang コードを確認します。

Screenshot

OpenResty XRay が提案したように、141 行目に注目してください。

Screenshot

dec.Series 関数は、1 つのレコードから一連の時系列データをデコードします。

Screenshot

ステータスバーでは、このコード行が先ほどのレポートで言及されていた通り、loadWAL 関数内にあることが確認できます。

Screenshot

Prometheus の TSDB は、最新のデータを管理するためにメモリ内シリーズを作成します。このコードパスで新しく割り当てられた GC オブジェクトの数は、新規割り当て総数の 19% を超えています。

Screenshot

ここでは、新しい GC オブジェクトの動的割り当て操作が CPU 時間の約 11% を占めていることがわかります。これはガベージコレクタの負担を増やすだけでなく、それ自体も大量の CPU リソースを消費しています。

Screenshot

完全自動化された分析とレポート

ガイド付き分析に加えて、OpenResty XRay はオンラインプロセスを自動的に監視し、レポートを定期的に生成することもできます。「Insights」ページでは、日次および週次の分析レポートを確認でき、手動の操作なしに Go のガベージコレクションや最も CPU を消費するコードパスを同様に特定できます。

OpenResty XRay の Insights ページに表示される日次・週次の自動分析レポート

そのため、「Guided Analysis」機能を手動で使用する必要は必ずしもありません。もちろん、アプリケーションの開発やデモンストレーションにおいては依然として非常に有用です。

よくある質問

Prometheus サーバーの CPU 使用率が高いのはなぜですか?

今回のケースでは、標準的で未修正の Prometheus バイナリ(/usr/bin/prometheus)が 160% を超える CPU を消費していました。OpenResty XRay のガイド付き分析により、Go のガベージコレクションが CPU 時間の 99% 以上を占めていることが判明しました。GC 負荷の原因は、loadWAL 関数が先行書き込みログ(WAL)からデータを読み込む際に大量の GC オブジェクトを高速に割り当てていたことで、このコードパスだけで新規割り当て総数の 19% 以上を占めていました。

Go のガベージコレクションが大量の CPU を消費するのはなぜですか?

多数の GC オブジェクトを高速に割り当てると、GC のオーバーヘッドが高くなります。ガベージコレクタはそれらのオブジェクトのスキャンとマーキングに CPU 時間を費やします。分析レポートでは、ヒープ内の GC オブジェクトをスキャンして到達可能なものをマークする scanobject や、マーク対象オブジェクトのワークキューを処理する gcDrain といったランタイム関数が目立っていました。さらに、割り当て自体もコストが高く、今回のケースでは新しい GC オブジェクトの動的割り当てだけで CPU 時間の約 11% を占めていました。

Prometheus の高 CPU の原因となる Go コードパスを見つけるにはどうすればよいですか?

実行中のプロセスに対して OpenResty XRay のガイド付き分析を使用します。プログラムの修正も計装も不要です。レポートには、最も多く・最も速くオブジェクトを割り当てている Go コードパスが表示され、これらは Go の GC オブジェクト割り当てフレームグラフから自動的に推定されます。loadWAL などの関数ボックスにマウスカーソルを合わせるとソースファイルのパスと行番号(今回のケースでは 141 行目)が表示されるので、そのファイルを任意のエディタで開いて該当コードを確認できます。Insights ページの日次・週次レポートでも、同じ結論を自動的に得られます。

このチュートリアルがお役に立ちましたら、当ブログおよび YouTube チャンネルのご購読をお願いいたします。ありがとうございます!

OpenResty XRay について

OpenResty XRay動的トレーシング製品であり、実行中のアプリケーションを自動的に分析して、パフォーマンスの問題、動作の問題、セキュリティの脆弱性のトラブルシューティングを行い、実行可能な提案を提供いたします。基盤となる実装において、OpenResty XRay は弊社の Y 言語によって駆動され、Stap+、eBPF+、GDB、ODB など、様々な環境下で複数の異なるランタイムをサポートしております。

著者について

章亦春(Zhang Yichun)は、オープンソースの OpenResty® プロジェクトの創始者であり、OpenResty Inc. の CEO および創業者です。

章亦春(GitHub ID: agentzh)は中国江蘇省生まれで、現在は米国ベイエリアに在住しております。章亦春は中国における初期のオープンソース技術と文化の提唱者およびリーダーの一人であり、Cloudflare、Yahoo!、Alibaba など、国際的に有名なハイテク企業に勤務した経験があります。「エッジコンピューティング」、「動的トレーシング」、「機械プログラミング」 の先駆者であり、22 年以上のプログラミング経験と 16 年以上のオープンソース経験を持っております。世界中で 4000 万以上のドメイン名を持つユーザーを抱えるオープンソースプロジェクトのリーダーとして、章亦春は OpenResty® オープンソースプロジェクトをベースに、米国シリコンバレーの中心部にハイテク企業 OpenResty Inc. を設立いたしました。同社の主力製品である OpenResty XRay動的トレーシング技術を利用した非侵入型のプロファイリング・トラブルシューティングツール)と OpenResty Edge(マイクロサービスおよび分散トラフィックに最適化された多機能ゲートウェイソフトウェア)は、世界中の多くの上場企業および大企業から高い評価を得ております。OpenResty 以外にも、章亦春は Linux カーネル、Nginx、LuaJITGDBSystemTapLLVM、Perl など、複数のオープンソースプロジェクトに累計 100 万行以上のコードを寄与し、60 以上のオープンソースソフトウェアライブラリを執筆しております。

翻訳

英語版の原文と日本語訳版(本文)をご用意しております。読者の皆様による他の言語への翻訳版も歓迎いたします。全文翻訳で省略がなければ、採用を検討させていただきます。心より感謝申し上げます!