OpenResty XRay の試用をすぐに申請する

Rust 製の組み込み型 KV データベース「Sled」をベースにした社内キャッシュサービスが、100% を超える CPU を消費していました。OpenResty XRay による Rust CPU プロファイリングで、その負荷を 2 つのホットなコードパス——sled::tree::Tree::insert と get_inner（CPU 時間の約 40%）——まで追跡し、該当するソースコードの行まで特定しました。コードの変更も再コンパイルも一切不要です。

本チュートリアルでは、この分析の全過程を段階的に解説します。以下に示すホットなコードパスは、OpenResty XRay が Rust 言語レベルの CPU フレームグラフを自動的に分析・解釈して得たものです。

問題：Sled ベースのキャッシュサービスが 100% 超の CPU を消費

Sled は Rust で書かれた組み込み型 KV データベースであり、社内キャッシュサービスはその上に構築されています。top で確認すると、このプロセスの CPU 使用率は 100% を超え続けていました。

Rust Sled ベースのキャッシュサービスプロセスが 100% 超の CPU を消費していることを示す top の出力

Guided Analysis による実行中の Rust プロセスのプロファイリング

OpenResty XRay を使用して、コードに手を加えていないこのプロセスを検査します。コード変更や再コンパイルなしに、リアルタイムで分析して原因を特定できます。この種の分析の実行時オーバーヘッドは非常に小さく、Rust アプリケーションに対する OpenResty XRay の性能影響の実測記事で定量的に測定しています。

OpenResty XRay の Web コンソールを開き、対象マシンが正しいことを確認した上で、「Guided Analysis」ページに移動します。ここでは、診断可能な問題の種類が一覧表示されます。

High CPU Usage を含む診断可能な問題タイプを一覧表示する OpenResty XRay の Guided Analysis ページ

「High CPU Usage」を選択し、先ほどの Sled アプリケーションと、100% 超の CPU リソースを消費しているプロセス——top で確認したもの——を選択します。

100% 超の CPU 使用率を示す Sled プロセスを選択する Guided Analysis のプロセス選択ステップ

アプリケーションタイプはデフォルトで Rust となっており、言語レベルもここでは「Rust」のみです。最大分析時間はデフォルトの 300 秒のままで、分析を開始します。システムは複数ラウンドの分析を継続的に実行しますが、この例では最初のラウンドが完了すれば十分なため、分析を停止すると分析レポートが自動生成されます。

Rust Sled プロセスの高 CPU 使用率問題に対して自動生成された Guided Analysis レポート

Rust CPU フレームグラフの解読：最もホットなコードパス

レポートには、CPU 時間を最も消費している Rust コードパス（#1）が表示されます。

sled::tree::Tree::insert を先頭とする、OpenResty XRay が報告した最もホットな Rust コードパス

最初の関数 sled::tree::Tree::insert は、Sled でデータを挿入するために使用されます。

sled::tree::Tree::insert を最もホットな関数として示すレポート。Sled ツリーへのデータ挿入に使用される

「More」をクリックして詳細を表示します。

レポート項目の More ボタンをクリックし、このホットパスの詳細分析を展開する

上記のホットなコードパスは、以下の Rust 言語レベルの CPU フレームグラフから自動的に導き出されたものです。

OpenResty XRay がホットな insert コードパスを自動的に推論した元となる Rust 言語レベルの CPU フレームグラフ

以下は、レポートが本問題に対して示すより詳細な説明と提案です。Explanation セクションでは insert とその呼び出し連鎖上の各関数を解説し、Suggestions セクションではバッチ書き込み（sled::Batch）、並行化、パラメータチューニングといった最適化の方向性を提示しています。

insert の呼び出し連鎖の各関数を解説し、バッチ書き込み・並行化・チューニングを提案するレポートの Explanation・Suggestions セクション

このアイコンをクリックしてフレームグラフを拡大します。

アイコンをクリックして Rust CPU フレームグラフを拡大し、呼び出しの詳細を確認する

insert 関数のフレームをクリックして詳細を表示します。

拡大したフレームグラフで insert 関数のフレームをクリックし、内部の呼び出しを確認する

左側では view_for_key 関数が大きな割合を占めています。これは Sled ライブラリ内で、指定されたキーのスナップショットビューを取得する関数です。

insert パス内で view_for_key 関数が大きな割合を占めていることを示す拡大フレームグラフ

右側の pagecache は、ページ単位でデータを管理する Sled のコンポーネントです。書き込まれたデータは最初に pagecache のメモリページに保存され、バッチが満杯になるとディスクにフラッシュして永続化されます。

書き込みをページ単位で管理する Sled の pagecache コンポーネントをフレームグラフの右側に示す

さらに拡大します。

pagecache 配下の呼び出しを確認するためにフレームグラフをさらに拡大する

Glibc の realloc 関数が見えてきます。このワークロードでは、libc のメモリ割り当て関数がホットになっています。

このワークロードで Glibc の realloc メモリ割り当て関数がホットスポットになっていることを示すフレームグラフ

フレームグラフから Sled のソースコードへ

ターミナルで find コマンドを使用し、cargo キャッシュ内の Sled ライブラリのソースコードディレクトリを探します。

ターミナルで find コマンドを使い、cargo キャッシュ内の Sled ライブラリのソースディレクトリを特定する

見つかったディレクトリをコピーし、Sled のソースコードディレクトリに移動します。

find で得たパスをコピーし、Sled のソースコードディレクトリに移動する

フレームグラフに戻り、insert 関数の緑色の枠にマウスカーソルを合わせると、ツールチップにこの関数のソースファイル名が表示されます。

insert 関数のソースファイルパスを表示するフレームグラフのツールチップ

ツールチップに表示されるソースコードの行番号は 164 です。

insert 関数に対応するソースコードの行番号 164 を表示するツールチップ

このアイコンをクリックして、この関数のソースファイルパスをコピーします。

insert 関数のソースファイルパスをコピーするためにアイコンをクリックする

お好みのエディタでソースファイルを開き、先ほどコピーしたパスを貼り付けます（ここでは vim を使用しています）。

貼り付けた Sled のソースファイルパスを vim で開く

OpenResty XRay が示した 164 行目にジャンプします。

示されたとおりエディタで Sled ソースコードの 164 行目にジャンプする

この行は insert 関数の内部にあります。

エディタで開いた Sled のソースコード。insert 関数本体内の 164 行目に位置

2 番目にホットなコードパス：get_inner と view_for_key

次に、2 番目のコードパスを確認します。2 番目にホットなコードパスは、CPU 時間の約 40% を消費しています。

get_inner を先頭とする、CPU 時間の約 40% を消費する 2 番目にホットな Rust コードパス

先頭の関数呼び出し get_inner は、Sled でデータを検索する関数です。

get_inner を 2 番目にホットなパスの先頭関数として示すレポート。Sled のデータ検索を担う

get 関数はライブラリがユーザーに公開しているデータ取得インターフェースで、内部で get_inner を呼び出しています。

get は Sled がユーザーに公開するデータ取得インターフェースであり、内部で get_inner を呼び出す

「More」をクリックして詳細を表示します。

More をクリックして get_inner ホットパスの詳細分析を展開する

フレームグラフを拡大し、get_inner 関数呼び出しの詳細を確認します。

get_inner の呼び出しの詳細を確認するためにフレームグラフを拡大する

さらに get_inner を拡大します。

フレームグラフで get_inner 関数の子呼び出しをさらに拡大する

get_inner 関数内の CPU 時間の大部分も、先ほどの view_for_key 関数に占められていることがわかります。

get_inner 内の CPU 時間の大部分が view_for_key 関数に占められていることを示すフレームグラフ

sled::lru::Lru::accessed 関数は、Rust の Sled ライブラリで LRU キャッシュ内のアイテムのアクセス状態を更新し、追い出しが必要なページ ID のリストを返すために使用されます。

get_inner パス内で sled::lru::Lru::accessed が LRU キャッシュの状態を更新していることを示すフレームグラフの詳細

OpenResty XRay の試用をすぐに申請する

自動生成される Rust CPU 分析レポート

OpenResty XRay は、稼働中のプロセスを自動的に監視して分析レポートを表示することもできます。

稼働中のプロセスを自動的に監視し、分析レポートを生成する OpenResty XRay

「Insights」ページに切り替えます。

OpenResty XRay コンソールの Insights ページに切り替える

「Insights」ページでは日次および週次のレポートを確認できるため、必ずしも「Guided Analysis」機能を使う必要はありません。

自動生成された日次・週次の CPU 分析レポートを表示する OpenResty XRay の Insights ページ

もっとも、「Guided Analysis」はアプリケーションの開発やデモンストレーションには非常に有用です。Insights の日次レポートでは、このプロセスの CPU 使用率（最小 102%、平均 107%、最大 113%）と、割合順に並んだ最もホットな Rust コードパスを確認できます。

sled-cache プロセスの CPU 最小 102%/平均 107%/最大 113% と、割合順に並んだ最もホットな Rust コードパスを表示する Insights の日次レポート

CPU 時間の分析に加えて、OpenResty XRay は同じ非侵入型の方式で、Rust プログラムのパニックの追跡や、Rust アプリケーションの高ディスク I/O の診断も行えます。

よくある質問

コードを変更せずに Rust プログラムの CPU 使用率をプロファイリングするには？

動的トレーシングに基づく非侵入型のプロファイラを使用します。OpenResty XRay は、実行中の、手を加えていない Rust プロセスを直接分析します。Guided Analysis 機能で対象プロセスを選択すると、プロセスをサンプリングして Rust 言語レベルの CPU フレームグラフを生成します。再コンパイルも、対象プロセスへの計装も不要です。

どの Rust 関数が最も CPU を消費しているかを特定するには？

プロセスをサンプリングして Rust 言語レベルの CPU フレームグラフを取得し、OpenResty XRay にフレームグラフから最もホットなコードパスを自動的に推論させます。フレームグラフを手作業で読み解く必要はありません。本記事の Sled のケースでは、sled::tree::Tree::insert が最もホットなパスとして報告され、該当するソースコードの行番号（164 行目）まで示されました。

Sled ベースのサービスが 100% 超の CPU を消費していたのはなぜ？

このケースでは、CPU 時間は 2 つのパスに集中していました。1 つは sled::tree::Tree::insert によるデータ挿入で、view_for_key と pagecache への書き込みが大半を占め、Glibc の realloc メモリ割り当て関数もホットになっていました。もう 1 つは get_inner によるデータ検索で、CPU 時間の約 40% を消費しており、こちらも主に view_for_key に費やされていました。

OpenResty XRay について

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

OpenResty XRay の試用をすぐに申請する

著者について

章亦春（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、LuaJIT、GDB、SystemTap、LLVM、Perl など、複数のオープンソースプロジェクトに累計 100 万行以上のコードを寄与し、60 以上のオープンソースソフトウェアライブラリを執筆しております。

翻訳

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