OpenResty XRay を使用してソフトウェアの問題を迅速に可視化し解決する

どの PHP 関数が高 CPU 使用率の原因かを特定するには、OpenResty XRay を既に実行中の PHP プロセスにアタッチします。再コンパイルも再起動も必要ありません。その Guided Analysis が、稼働中プロセスの CPU フレームグラフを生成します。本ケースで最もホットだったのは、業務ロジック関数 processOrders 内の preg_match 呼び出しであり、Laravel の callAction 経由で到達していました。つまり、正規表現こそが CPU ボトルネックだったのです。

本日は、OpenResty XRay を使用して PHP アプリケーションを分析する、もう一つの段階的な例をご紹介いたします。既に実行中の PHP プロセスにおいて、CPU 使用率が最も高いコードパスを迅速に特定します。これらのコードパスは、アプリケーションの CPU 時間の大半を消費している可能性があります。OpenResty XRay は真の非侵入型の動的分析ツールであり、対象アプリケーションに特別なモジュールやプラグインをインストールする必要はなく、対象アプリケーションを再コンパイルする必要もなく、さらには実行中のプロセスを再起動する必要もありません。

問題：高 CPU 使用率

まず、top コマンドを実行して CPU 使用状況を確認します。ご覧のとおり、php プロセスが CPU コアの 100% を消費しています。

PHP プロセスが CPU コアの 100% を消費していることを示す top コマンドの出力

続いて ps コマンドを実行し、このプロセスの完全なコマンドラインを確認します。これは Linux ディストリビューションに付属する標準的な PHP バイナリ実行ファイルであることがわかります。

PHP プロセスの完全なコマンドラインを示す ps コマンドの出力

どの PHP 関数が CPU を消費しているかを特定する

OpenResty XRay を使用して、この未修正のプロセスをリアルタイムで検査し、何が起きているのかを突き止めましょう。

OpenResty XRay の Web コンソールを開き、ホットな PHP プロセスが稼働しているマシンを選択していることを確認します（必要であればリストから別のマシンを選択できます）。そして「Guided Analysis」ページに移動し、問題タイプの一覧から「High CPU usage」を選択します。

High CPU usage の問題タイプがハイライトされた OpenResty XRay の Guided Analysis ページ

次に、分析対象を先ほどの PHP アプリケーションに向け、CPU の 100% を消費しているプロセス、つまり先ほど top で確認したものと同じプロセスを選択します。OpenResty XRay は複数の言語レベルを同時に分析できるため、PHP と C/C++ の両レベルを選択したままにし、最大分析時間はデフォルトの 300 秒のままにします。分析を開始すると、連続したラウンドが自動的に実行されます。最初の数ラウンドで十分なデータが得られるので、分析を停止してレポートを生成させます。

PHP プロセス向けに OpenResty XRay が自動生成した高 CPU 分析レポート

これが、これから分析する問題タイプ CPU です。

診断された問題タイプが CPU であることを示すレポート上部

これが、最も CPU 時間を消費している第 1 位のホットな PHP コードパスであり、CPU 時間の 56.2% を占めています。

CPU 時間の 56.2% を占める、レポート中の第 1 位のホットな PHP コードパス

最もホットな関数呼び出しは preg_match です。これは正規表現マッチングの PHP レベルのラッパーです。

コードパス中でハイライトされた preg_match 関数

processOrders 関数は業務コードに属します。

コードパス中でハイライトされた業務ロジック関数 processOrders

callAction は、コントローラー内の指定されたアクションを呼び出す Laravel フレームワークのメソッドです。

コードパス中でハイライトされた Laravel の callAction メソッド

processOrders 関数の緑色のボックスにマウスカーソルを合わせます。ツールチップには、この PHP ソースファイルのフルパスが表示されます。

processOrders のソースファイル ProductServiceProvider.php のフルパスを示すツールチップ

このソース行の行番号は 437 です。

このソース行の行番号が 437 であることを示すツールチップ

そのソースファイルのパスをコピーします。

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

Vim エディタでソースファイルを開き、このファイル内の PHP コードを確認します。お好みのエディタを使っていただいて構いません。

ターミナルで vim を使って ProductServiceProvider.php のソースファイルを開く

OpenResty XRay の助言に従って、437 行目にジャンプします。

vim でソース 437 行目にジャンプし、その行の preg_match 呼び出しをハイライト表示

preg_match の呼び出しがレポートと一致していることがわかります。この正規表現はループ内で繰り返しマッチングされているため、正規表現をプリコンパイルすることで CPU コストを削減できます。これは具体的で実行可能な最適化です。

processOrders のループ内にある preg_match 呼び出しを示す PHP ソース 437 行目

このソース行は processOrders 関数の内部にあります。

437 行目が processOrders 関数の内部にあることを示す vim のステータスライン

「More」をクリックして、このコードパスの詳細を確認します。

More リンクをクリックしてコードパスのさらなる詳細を表示

このホットコードパスは、以下の PHP 言語レベルの CPU フレームグラフから自動的に導き出されたものです。フレームグラフは、プロセスが実際にどこで CPU 時間を費やしているかを可視化します。

実行中プロセスの最もホットなコードパスを示す PHP 言語レベルの CPU フレームグラフ

以下は、この問題に関するより詳細な説明と推奨事項です。先ほど確認した preg_match 関数について言及し、不要なミドルウェアの削減、正規表現の最適化（バックトラッキングの回避、非キャプチャグループの使用、貪欲な量指定子の削減）などの助言を示しています。

preg_match の根本原因を説明し最適化の助言を示すレポートの Explanation と Suggestions のセクション

最も CPU 時間を消費している C コードパスを見てみましょう。CPU 時間の 34.7% を占めており、PHP 側のパスと一致しています。

CPU 時間の 34.7% を占める、最もホットな関数が pcre2_match_8 である第 1 位のホットな C コードパス

pcre2_match_8 関数は PCRE2 ライブラリの一部です。

C コードパス中でハイライトされた PCRE2 ライブラリの関数 pcre2_match_8

php_pcre_match_impl 関数は内部で PCRE2 を呼び出し、正規表現マッチング機能を実装しています。

C コードパス中でハイライトされた php_pcre_match_impl 関数

php_do_pcre_match は preg_match 関数を実装するために使用され、正規表現を文字列に対してマッチングします。

C コードパス中でハイライトされた php_do_pcre_match 関数

zend_execute_scripts 関数は PHP スクリプトの実行に使用されます。明らかに、これは先ほど確認した PHP ホットコードパスと類似しています。これにより、正規表現マッチングが真の CPU ボトルネックであることが C レベルからも裏付けられます。

PHP スクリプトを実行するために使用される、C コードパス中でハイライトされた zend_execute_scripts 関数

これは、姉妹的な問題である PHP プロセスのメモリ使用量が多すぎるケースや、本番環境での PHP 例外のトレースで使用するものと同じ PHP プロファイリングのワークフローです。いずれも、稼働中の未修正プロセスに対して実行します。

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

OpenResty XRay は、オンラインのプロセスを自動的に監視し、分析レポートを生成することもできます。「Insights」ページに移動します。

左側ナビゲーションバー中でハイライトされた Insights ページの入り口

「Insights」ページでは、日次および週次の自動レポートを確認できます。そのため、Guided Analysis を自分で実行する必要すらありません。

日次および週次の自動分析レポートを表示する OpenResty XRay の Insights ページ

もちろん、Guided Analysis はアプリケーションの開発やデモンストレーションには引き続き有用です。

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

よくある質問

なぜ PHP プロセスの CPU 使用率が 100% になるのか？

CPU 使用率が 100% に張り付いた PHP プロセスは CPU バウンドです。つまり、I/O 待ちではなくホットなコードでサイクルを消費しています。本例では、processOrders 関数内のループで繰り返しマッチングされる preg_match の正規表現が原因でした。OpenResty XRay を稼働中のプロセスにアタッチして CPU フレームグラフを読み解けば、どの関数が CPU を消費しているのかを、再コンパイルも再起動もせずに正確に特定できます。

どの PHP 関数が高 CPU 使用率の原因かを特定するには？

OpenResty XRay を既に実行中の PHP プロセスにアタッチし、「High CPU usage」の Guided Analysis を開始します。プロセスをリアルタイムで読み取るため、アプリケーションへの計測コードの埋め込み、再コンパイル、再起動は不要です。結果として、最もホットな PHP コードパスをランク付けし、原因となっている正確な関数、ソースファイル、行番号を示すレポートと CPU フレームグラフが得られます。

preg_match や正規表現は PHP で高 CPU を引き起こすか？

引き起こします。preg_match は PCRE2 エンジン上で動作し、正規表現を繰り返し（たとえばループ内で）マッチングすると CPU 時間の大半を占める可能性があります。本記事では、最もホットな PHP パスが processOrders 内の preg_match であり、最もホットな C パス（php_do_pcre_match 経由の pcre2_match_8）がそれを裏付けました。反復ごとに正規表現を再構築しないよう、あらかじめプリコンパイルしておくのが素直な解決策です。

OpenResty XRay について

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

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

このチュートリアルが役立ちましたら、当ブログや YouTube チャンネルのご登録をお願いいたします。ありがとうございます！

著者について

章亦春（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 以上のオープンソースソフトウェアライブラリを執筆しております。

翻訳

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