高並行性 Web サービスにおいて、開発者や運用担当者は、アプリケーションの実際のパフォーマンスが期待値を大きく下回るという喫緊の課題にしばしば直面します。典型的なシナリオとして、単一の nginx worker プロセスが 1 秒あたりに処理するリクエスト数（RPS）が 300 未満であるにもかかわらず、サーバーのシステム負荷が論理 CPU のコア数に近づいているケースが挙げられます。さらに深く調査すると、Nginx のイベント・ループ（Event Loop）に数十ミリ秒にも及ぶ深刻なブロッキングが発生していることが判明する場合があります。これらの問題は、「目に見えないパフォーマンスのボトルネック」として、システムの全体的なスループット能力に静かに影響を及ぼしています。

従来の監視ツールは、CPU 使用率の高さや応答遅延の増加といった表面的な現象を示すことはできますが、コード実行レベルまで深く掘り下げて分析し、ブロッキングを引き起こしている具体的な関数や操作を正確に特定することは困難な場合が多くあります。

OpenResty XRay は、強力な動的トレーシング製品であり、このような複雑な off-CPU 問題の分析・解決に非常に適しています。本製品は、アプリケーション・コードに手を加えることなく、また本番環境の安定性に影響を与えることなく、システムを詳細に分析することが可能です。本稿では、実際の事例を通して、OpenResty アプリケーションにおける off-CPU パフォーマンスのボトルネックを、OpenResty XRay を用いてどのように特定し、解決するかを詳細にご紹介します。

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

パフォーマンスのボトルネック：CPU リソース競合の顕在化

分析の第一歩として、OpenResty XRay の C レベル off-CPU フレームグラフを用いて、プロセスの待機イベントを調査しました。

Screenshot

分析結果によると、予期された epoll_wait によるネットワーク I/O 待機に加え、かなりの off-CPU 時間が、mpi_mul_hlp や free といった純粋な CPU 計算に関連する関数で消費されていることが判明しました。

これは、プロセスが実行準備が整っているにもかかわらず、タイムリーに CPU タイムスライスを獲得できていないことを示しており、これは CPU リソース競合の典型的な特徴です。

専門の分析ツールを用いて、問題の根本原因を特定しました。それは、nginx の設定ファイルに worker_cpu_affinity ディレクティブが欠落していたことでした。

no cpu affinity set.
no cpu affinity set.

この設定の欠落は、複数の nginx worker プロセスが、Linux カーネルによって異なる CPU コア間で頻繁にスケジューリングされ、不要なコンテキストスイッチのオーバーヘッドが発生し、その結果、CPU の実効利用率が低下していました。

根本原因の特定：ブロッキング Lua I/O 操作

CPU 競合問題の解決後、引き続き off-CPU 時間の分析を進めました。

Screenshot

分析の結果、off-CPU ブロッキング時間の大部分が、ユーザー定義の customize.lua ファイルの 15 行目に起因していることが判明しました。

この行のコードは、file_list という関数を呼び出して、この関数内部では Lua 標準ライブラリが提供する io.popen および read 関数を使用してシェルコマンドを実行しています。

これらはすべて同期ブロッキング I/O 操作であり、外部コマンドの実行が完了し、結果が返されるまで Nginx イベントループ全体を停止させます。これこそが、システムのスループット低下を引き起こす主要な原因の一つです。

定量分析：ファイル I/O 性能への影響

ブロッキング ファイル I/O 操作

サンプル 1

io.popen に加え、C レベル仮想ファイルシステムにおける読み書き回数のフレームグラフからも、他に二つの潜在的な性能ボトルネックが発見されました。

Screenshot

上記のフレームグラフから見て取れるように、apr_generate_random_bytes 関数がファイル読み取り回数の 59.8% を占めています。

Screenshot

また、二枚目のフレームグラフによりますと、apr_sdbm_fetch 関数がファイル読み取り回数の 24% を占めています。

サンプル 2

Screenshot

上記の図から確認できますように、Apache ランタイムにおける apr_generate_random_bytes という C 関数がファイル読み取り回数の 51.8% を占めています。

Screenshot

そして、二枚目の図では、apr_sdbm_fetch 関数が合計でファイル読み取り回数の 20.7% を占めていることが示されています。

性能評価

これらのファイル I/O 操作が与える影響を正確に評価するため、当社では専用のレイテンシー測定ツールを用いて apr_generate_random_bytes のレイテンシー分布を測定しました。

3110 samples' latency: min=10, avg=17, max=1494 (us)
value |-------------------------------------------------- count
    2 |                                                      0
    4 |                                                      0
    8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  1540
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   1499
   32 |@@                                                   64
   64 |                                                      4
  128 |                                                      1
  256 |                                                      1
  512 |                                                      0
 1024 |                                                      1
 2048 |                                                      0
 4096 |                                                      0

この関数は最大で 1494 マイクロ秒、つまり約 1.5 ミリ秒のレイテンシーに達することが判明しました。これは無視できない数値です。この遅延は Nginx のイベントループをブロックし、現在処理中のすべての同時接続におけるリクエストのレイテンシーに影響を及ぼします。

また、apr_sdbm_fetch についても、時には 1 ミリ秒近くに達することがあります。

1570 samples' latency: min=5, avg=10, max=953 (us)
value |-------------------------------------------------- count
    1 |                                                      0
    2 |                                                      0
    4 |@@@@@@@@@@@@@@@@@                                   383
    8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  1080
   16 |@@@@                                                100
   32 |                                                      4
   64 |                                                      2
  128 |                                                      0
  256 |                                                      0
  512 |                                                      1
 1024 |                                                      0
 2048 |                                                      0

高並行性と低レイテンシーを追求する Nginx にとって、ミリ秒単位の同期ブロッキングは決して無視できません。

イベントループのブロッキング状況の包括的な評価

最後に、Nginx イベントループ全体のブロッキング状況について包括的な評価を実施しました。

20 秒間のサンプリング期間中に、43952 件のブロックサンプルを捕捉しました。その中で、単一のブロック時間の最大値は驚くべきことに75165 マイクロ秒、すなわち 75 ミリ秒以上に達していました。

distribution of epoll loop blocking latencies (us): 43952 samples: min/avg/max: 754/0/75165
 value |-------------------------------------------------- count
     0 |                                                      31
     1 |                                                     149
     2 |                                                      33
     4 |                                                     166
     8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@                        6094
    16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  10839
    32 |@@@@@@@@@@@@@@@                                     3278
    64 |@@@@@@@@@                                           2060
   128 |@@@@@@@@@@@                                         2530
   256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@     10082
   512 |@@@@@@@@@@@                                         2544
  1024 |@@@@@                                               1162
  2048 |@@@@@@@@@@                                          2343
  4096 |@@@@@@@@@@                                          2377
  8192 |                                                     199
 16384 |                                                      55
 32768 |                                                       8
 65536 |                                                       2
131072 |                                                       0
262144 |                                                       0

このデータは、アプリケーションのパフォーマンスがこれほどまでに低下している理由を明確に説明しています。イベントループが 75 ミリ秒間ブロックされるということは、その間、当該 worker プロセスが新規リクエストを一切処理できないことを意味します。

以下のサンプル分析と合わせてご説明します。

found 3237 in reqs and 3238 done reqs in 3.103 sec (1043.07 r/s and 1043.39 r/s).
in reqs:
  pid 3101: 255.21 r/s
  pid 3102: 285.82 r/s
  pid 3103: 227.82 r/s
  pid 3106: 274.22 r/s
done reqs:
  pid 3102: 286.47 r/s
  pid 3103: 227.50 r/s
  pid 3101: 254.89 r/s
  pid 3106: 274.54 r/s

個々の worker プロセスの RPS (Requests Per Second) は 227 から 286 の間に留まっており、これは非常に低い数値です。1 秒あたり 300 件未満のリクエストしか処理できていません。一方で、マシン負荷はすでに 4 に近く、これは論理 CPU コア数に匹敵します。この状況は、観測された深刻なブロッキング状況と完全に一致しています。

まとめ

詳細な分析を進める中で、システムパフォーマンスに影響を与える複数の重要な問題が明らかになりました。

  • nginx worker プロセス間のCPUリソース競合が大量のコンテキストスイッチ (Context Switch) を引き起こし、CPUの有効利用率を著しく低下させていました。
  • customize.lua ファイル内で頻繁に呼び出される io.popen や read といったブロッキング (Blocking) Lua I/O 操作が、システムパフォーマンスの最大のボトルネック (Bottleneck) となっていました。
  • apr_generate_random_bytes および apr_sdbm_fetch 関数によるファイルI/O操作も、イベントループ (Event Loop) に顕著なブロッキング影響を与えていました。
  • Nginx イベントループの1回あたりのブロッキング時間が最大75ミリ秒に達し、これが直接的に単一の worker プロセスのRPS (Requests Per Second) を227〜286という、期待値を大幅に下回る数値に留めていました。

これらの問題の存在こそが、システムパフォーマンス低下の根本原因です。OpenResty XRay の精密な診断により、これらのボトルネックを特定できただけでなく、その後の最適化に向けた明確な方向性も得られました。

OpenResty XRay で Nginx パフォーマンスの悪夢に終止符を打つ

OpenResty XRay は、複雑なパフォーマンス問題を解決するための究極のツールです。その比類なき動的トレーシング (Dynamic Tracing) 能力により、パフォーマンスボトルネックを正確に特定できるだけでなく、企業に計り知れない価値をもたらします。

  • 画期的な診断効率：従来の長期にわたるトラブルシューティング (Troubleshooting) プロセスに別れを告げ、OpenResty XRay は問題特定時間を数日から数時間へと短縮し、貴社チームを常に一歩先へと導きます。
  • 究極のハードウェアリソース最適化：パフォーマンスボトルネックを解消することで、単一サーバーの処理能力を数倍に向上させ、より少ないサーバーリソースでより大きなビジネス負荷を処理可能にします。
  • シームレスな事業継続性確保：潜在的なパフォーマンス上の懸念を事前に特定し解消することで、システムの安定稼働を確保し、過負荷によるサービス中断を回避します。
  • 包括的な技術的負債 (Technical Debt) の解消：過去からのパフォーマンス問題を体系的に明らかにし解決することで、コード品質とシステムアーキテクチャ (System Architecture) 全体の健全性を向上させます。

ミリ秒単位で勝敗が決まるデジタル経済時代において、アプリケーションパフォーマンス (Application Performance) は、ユーザーエクスペリエンス (User Experience) とビジネスの成功に直接影響します。OpenResty XRay は、その先進的な動的トレーシング技術により、従来のパフォーマンス最適化手法を根本から覆し、貴社の技術的意思決定に確固たる科学的根拠を提供します。

もし貴社のアプリケーションがパフォーマンスの課題に直面しているならば、OpenResty XRay は比類なき精密な洞察力をご提供し、パフォーマンスをビジネス成長を推進する強力なエンジンへと変革いたします。

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

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 XRay（マイクロサービスおよび分散トラフィックに最適化された多機能ゲートウェイソフトウェア）は、世界中の多くの上場企業および大企業から高い評価を得ております。OpenResty 以外にも、章亦春は Linux カーネル、Nginx、LuaJIT、GDB、SystemTap、LLVM、Perl など、複数のオープンソースプロジェクトに累計 100 万行以上のコードを寄与し、60 以上のオープンソースソフトウェアライブラリを執筆しております。

翻訳

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