プラグインが CPU の 45% を食い潰した際、ソースコードなしで Lua の 93 行目を特定した方法?
本記事では、実際の顧客事例を振り返ります。あるオープンソースの OpenResty を基盤とする API ゲートウェイクラスターが、深刻な CPU ボトルネックに直面しました。従来の perf ツールでは、「ブラックボックス」プラグインの前では全く歯が立ちませんでした。本記事では、OpenResty XRay チームがどのように動的追跡技術を使用し、非侵入的に Lua VM の内部を可視化し、OpenSSL C ライブラリ内の 44.8% の CPU を占める pkey_rsa_decrypt 関数を正確に特定し、そのシステム並行処理能力への真の影響を詳細に明らかにします。
API ゲートウェイは、現代のマイクロサービス アーキテクチャにおける要衝(ボトルネック)であり、その性能と安定性は極めて重要です。
先日、金融業界の お客様からご連絡をいただき、深刻な本番環境の 問題をご報告いただきました。彼らのコアビジネスを支えるゲートウェイクラスターが、ピーク時に CPU 使用率が継続的に 100% に張り付き(100% Saturation)、P99 レイテンシ(99 パーセンタイル レイテンシ)が急激に悪化する事態となりました。
perf が「ブラック ボックス」に直面したとき
お客様の SRE チームは迅速に対応し、以下の手段を試みました。
top/htop: 結果はopenrestyプロセスが CPU 使用率の大部分を占めていることを示すだけで、それ以上の詳細な情報は得られませんでした。perf record: お客様はperf recordとフレーム グラフを試しました。最良のケースでは、perf のフレーム グラフはpkey_rsa_decryptのような C 関数が CPU を消費していることを示すかもしれませんが、JIT 環境ではluajit_vm_dispatchなどの VM シンボルに埋もれてしまいがちです。
しかし、これはすぐに 2 番目の、そしてより致命的な問題を引き起こしました。それは原因の特定ができないという点です。perf はこの C 関数呼び出しを、どの Lua コードが引き起こしたのか、上流の Lua コードと関連付けることができませんでした。結果として得られたのは「孤立したホット スポット」でした。どのプラグイン、どの API ルート、どの Lua コード行がこの負荷の高いC 呼び出しをトリガーしたのか、私たちには不明でした。
これこそが、Lua と C の混合言語スタックにおける perf の根本的な限界です。コンテキストが失われてしまうのです。数十ものプラグインが動作する複雑なゲートウェイにおいて、孤立した C 関数のホットスポットだけでは、具体的な最適化の指針を得ることはできません。
- APM モニタリング: 顧客の APM システム(
ngx.nowとngx.logに基づく)により、ほとんどの処理時間がaccess_by_luaフェーズで費やされていることが判明しました。範囲は絞り込まれましたが、まだ広すぎます。accessフェーズには十数個のプラグインが組み込まれている可能性があります。
顧客チームは一つずつ切り分けを行うことで、セッション検証に使用されるカスタムプラグイン cb-session-validation を特定しました。しかし問題は、このプラグインが第三者サービスプロバイダーによって提供された「ブラックボックス」であり、顧客チームはその完全なソースコードを所有していなかったことです。
これは典型的な「盲点」です:
- マクロ的には、CPU 負荷が高騰していることは把握していました。
- メソ的には、
access_by_luaフェーズであることは判明していました。 - ミクロ的には、どの具体的な関数がリソース消費を引き起こしているのかを特定できませんでした。
「サンプリング」から「フルスタック動的トレーシング」へ
OpenResty XRay の技術専門家チームの分析によると、Lua レベルのプロファイラやシステムレベルの perf のどちらでも解決策が見つからない場合、ボトルネックはほぼ確実にLua VM とネイティブ C ライブラリの境界で発生していると判断できます。
これは従来のサンプリングツールにとっての「盲点」です。perf は C/C++ やカーネルの分析には優れていますが、LuaJIT、V8、JVM といったアプリケーション言語層のコードの呼び出しスタックを取得する手段がないため、得られる情報は非常に限られています。オープンソースの APM ツールは利用のハードルが高く、使いこなせる開発者はごく一部であり、本番環境でのデプロイには適していません。
そこで私たちは、お客様が問題が発生している本番環境で直接 OpenResty XRay を使用し、「CT スキャン」を実施することをお勧めします。
OpenResty XRay の決定的な違いは、サンプリングに依存せず、動的トレーシングを使用する点にあります。これにより、NGINX イベントループから LuaJIT VM、さらに C ライブラリ、そしてカーネルに至るまでの完全な呼び出しスタックを、再起動やコードの変更なしに、非侵入的にリアルタイムで再構築することが可能です。
分析タスクを開始したところ、驚くべき事実が明確に示されました。それは、pkey_rsa_decrypt という C 関数が、CPU 使用率の実に 44.8% を占めていたというものです。
証拠の連鎖を特定する
この pkey_rsa_decrypt 関数は、OpenSSL ライブラリに由来し、RSA 秘密鍵復号を行うために使用されます。しかし、どのように呼び出されたのでしょうか?
OpenResty XRay が提供する完全な呼び出しスタックは、以下の証拠の連鎖を示しました:
@access_by_lua(nginx.conf:310):2
http_access_phase@/usr/local/openresty/app/init.lua:721
run_plugin@/usr/local/openresty/app/plugin.lua:1154
phase_func@/opt/openresty/cb_plugins/openresty/plugins/cb-session-validation.lua:93 <-- 顧客の「ブラックボックス」プラグイン
validate_session@/opt/openresty/cblualib/cbmodules/cb-session-validator.lua:283
verify_session@/opt/openresty/cblualib/cbmodules/cb-session-validator.lua:105
load_jwt@/opt/openresty/cblualib/resty/cb_jwt.lua:624
pcall
[builtin#pcall]
@/opt/openresty/cblualib/resty/cb_jwt.lua:250
...
C:pkey_rsa_decrypt [/usr/lib64/libcrypto.so.1.1.1k] <-- 44.8% CPU ボトルネック
@/usr/src/debug/openssl-1.1.1k-12.el8_9.x86_64/crypto/rsa/rsa_pmeth.c:337
この分析結果の価値は次のとおりです:
- 情報の可視化: perfでは得られない原因特定のためのコンテキストを提供し、C言語のホットスポット
pkey_rsa_decryptが、問題を引き起こしたLuaコードcb-session-validation.luaプラグインの 93 行目にあることを明確に特定しました。 - Lua と C の連携: ブラックボックスのプラグインからJWTライブラリ(Luaコード)を経て、最終的に
libcrypto.so(C ライブラリ)を呼び出すまでの完全なパスを完璧に可視化しました。
ソースコードなし、GDB 不要、サービス再起動なしの状況で、どのファイル、どの行のコードが問題をトリガーしたかを知ることができました。これこそがエンジニアが本当に必要とする、すぐに行動できる洞察です。
「何が起こったか」から「なぜ」へ
pkey_rsa_decrypt を特定することは第一歩に過ぎません。エンジニアがより関心があるのは:なぜそれがボトルネックになったのか?私たちは OpenResty XRay のデータに基づいて、お客様に 2 つのレベルの分析と最適化の仮説を提示しました:
仮説 1:過剰な暗号化(アルゴリズムに起因する問題)
validate_session 段階における非対称復号処理がこれほど時間を要していたため、私たちはまず鍵長の問題を疑いました。もし顧客またはその第三者が 4096-bit あるいはそれより長い RSA 鍵を使用していた場合、その計算オーバーヘッドは驚異的なものとなります。
私たちは openssl speed を用いて迅速にベンチマークテストを実施し、RSA 2048-bit と 4096-bit の性能を比較しました。結果は以下の通りです。
| アルゴリズム | 署名操作 (sign/s) | 検証操作 (verify/s) |
|---|---|---|
| rsa 2048 bits | 1325.3 | 48404.7 |
| rsa 4096 bits | 211.5 | 13877.3 |
| 性能比較 | 2048 は 4096 の 6.2 倍 | 2048 は 4096 の 3.4 倍 |
このデータから、RSA 2048 の検証速度が 4096 の 3.4 倍以上であることが示されています。また、2024 年現在、2048-bit の鍵はほとんどのシナリオにおいて十分に安全であると見なされています。4096-bit の使用は「過剰な安全性」に該当し、その代償として 3〜6 倍の性能低下を招くことになります。
仮説 2:冗長な処理(アーキテクチャ上の問題)
コールスタックを確認すると、この高コストな復号処理はすべてのリクエストの「セッション検証」段階で発生しています。
これはアーキテクチャ上の欠陥である可能性が高いです。有効な、期限切れでない Session/JWT であれば、その復号結果(すなわちユーザーの身元情報)はキャッシュされるべきです。
セッションの有効期間中、例えば 5 分間、同じトークンに対してすべてのリクエストで数万回もの高コストな RSA 復号処理を繰り返し実行する必要は全くありません。
これはシステムの並行処理能力にどのような影響を与えますか?
この 44.8% の CPU 使用率は、本質的にシステムのスループット能力を「半減させる」ものです。
これは、ゲートウェイクラスターのほぼ半分の CPU サイクルが、キャッシュ可能で最適化可能な反復的な暗号処理に浪費されていることを意味します。これにより、CPU 使用率が早期に上限に達し、より多くの並行リクエストを処理できなくなり、P99 遅延が必然的に急上昇します。
事後分析と総括
今回のケースは、従来の 可観測性 ツールや APM ツールの限界を明確に浮き彫りにしました。perf や APM といった一般的な監視手法では対処できなかったのは、ボトルネックが VM と ネイティブ C ライブラリの境界で発生しており、perf が C の呼び出しスタックにしかアクセスできず、Lua の呼び出しスタックを深く掘り下げて取得できなかったため、ラストワンマイルの洞察力が不足していたからです。
前述の通り、perf は pkey_rsa_decrypt が ホットスポットであることを特定できるかもしれません。しかし、オープンソースの OpenResty をベースとした API ゲートウェイのような、高並行処理かつイベント駆動型の JIT 環境では、これはほとんど意味のない情報です。
問題は、原因特定におけるギャップにあります。perf は LuaJIT VM の境界を越えることができません。この C 関数が VM 上のどの Lua コードによってトリガーされたのかを把握できないのです。数十のプラグインがあり、毎秒数万の リクエストを処理するシステムでは、それが プラグイン A によるものなのか、それとも プラグイン B によるものなのかを特定することはできません。
つまり、以下の状況でした:
- perf は C 関数の処理が集中していることは把握できましたが、それを特定の Lua リクエストに関連付けることはできませんでした。
- APM は Lua リクエストの遅延を検知しましたが、C 言語のブラックボックスの内部を「見通す」ことはできませんでした。
一方、OpenResty XRay の核となる強みは、フルスタック 動的 トレーシングにあります。これは、Lua 領域と C 領域を横断する完全な混合呼び出しスタックを再構築し、正確に「cb-session-validation.lua ファイルの 93 行目が、一連の呼び出しを通じて最終的に pkey_rsa_decrypt を実行し、CPU の 44.8% を消費しました」と示します。
Kong のような OpenResty ベースの高性能ミドルウェアにとって、性能最適化の「本質的な課題領域」は、しばしば C 言語レベル、FFI 境界、または システムコール上に存在します。このような複雑なシステムを最適に運用するには、ベテラン エンジニアは新しい ツールを必要とします。それは、フルスタック 動的 トレーシングが可能で、Lua と C の世界をシームレスに接続できるものでなければなりません。
今回の診断において、OpenResty XRay は「CT スキャナー」の役割を果たしました。これにより、お客様のチームは根拠のない推測をやめ、データと証拠に基づいた正確な最適化を実施できるようになりました。私たちがお客さまに提示した最適化の提案も非常に明確でした:
- (根本的解決策)アーキテクチャ最適化:
cb-session-validation.luaにlua-resty-lrucacheを導入し、復号化結果に対して プロセス内キャッシュ (in-process cache) を適用します。 - (性能調整)アルゴリズム最適化: RSA 鍵長を速やかに確認し、4096-bit である場合は、2048-bit への ダウングレードの実現可能性を評価します。
もしあなたのチームも複雑な OpenResty システムを保守しており、perf の結果から膨大な データの中から原因を探し出すことにうんざりしているなら、ぜひ 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(マイクロサービスおよび分散トラフィックに最適化された多機能
翻訳
英語版の原文と日本語訳版(本文)をご用意しております。読者の皆様による他の言語への翻訳版も歓迎いたします。全文翻訳で省略がなければ、採用を検討させていただきます。心より感謝申し上げます!


















