OpenResty XRay による D 言語製注文サービスの P99 レイテンシー異常変動の解明
数ヶ月にわたり安定稼働していた注文サービス(D 言語 + vibe.d)において、P99 応答時間に周期的な変動が発生し始めました。
問題の特性:
- P99 応答時間:トラフィックのピーク時に、ベースラインの 120ms から 350ms へと急変動し、一部のユーザーが体感できるほどの遅延となっていました。
- 通常の監視項目:エラー率、スループット、平均応答時間、スロークエリログのいずれにも異常は見られませんでした。
- 外部依存:ヘルスチェックはすべて成功しており、呼び出しチェーンにおけるレイテンシー分布も正常でした。
- サービス状態:OOM(Out of Memory)や panic は発生していませんでした。
これは、パフォーマンス問題の中でも特に解決が困難な「表面的には正常に見えながら、内部に異常を抱えている」ケースです。通常の監視では問題の発生は検知できても、その原因までは特定できません。データベース、外部依存、並行処理の設定といった経験則に基づく調査を一つずつ実施したものの、P99 の値に改善は見られませんでした。考えうる全ての仮説が否定されたとき、問題は外部コンポーネントではなく、サービス自身のランタイムの挙動にあると結論付けられます。
本番環境に影響を与えることなく根本原因を特定するため、OpenResty XRay を導入しました。OpenResty XRay は非侵入的な動的トレース技術を活用しているため、コードの変更、再コンパイル、サービスの再起動を一切行うことなく、実行中のバイナリプロセスを直接サンプリング・分析し、パフォーマンスのホットスポットを特定するためのフレームグラフを自動生成します。
フレームグラフから読み解く GC の罠と業務処理のホットスポット
OpenResty XRay が収集・自動生成したフレームグラフを開くと、すぐに 2 つの幅の広いブロックが目に留まります。
- 業務ロジックのコールスタック (
OrderManager関連):~73% - GC 関連のコールスタック (
Gcx.scanBackground):~26%
直感の罠: ほとんどのエンジニアは、全体の 73% を占める業務ロジックに注目し、業務コードを最適化すれば GC の負荷も自然に低下する、と考えがちです。
なぜこの直感が間違いなのか:
GC による休止(Stop-the-World)が、業務コードのサンプリング時間を引き延ばすためです。 GC がバックグラウンドでメモリをスキャンしている間、業務スレッドは待機状態になります。GC が業務コードの実行中にトリガーされると、業務コード自体が遅くなったわけではなく、GC によってその実行時間が引き延ばされた結果として、プロファイラから「過剰にサンプリング」されてしまうのです。
したがって、まず GC の挙動を理解する必要があります。GC はシステムレベルの動作であり、その存在はすべての業務ホットスポットの解釈に影響を及ぼします。この 2 つの数値を単純に合算したり、その大きさだけで最適化の優先順位を判断したりすることはできません。
ホットスポット①:GC が 26.4% を占有——しかし、これは単に「GC が遅い」という問題ではない
フレームグラフにおいて、GC 関連のコールスタックの最上位には core.internal.gc.impl.conservative.gc.Gcx.scanBackground があります。ここでのキーワードは conservative(保守的)です。
D 言語の GC は「保守的 GC」であり、JVM や Go 言語の「正確な GC」とは異なります。
- 正確な GC(Precise GC):メモリ上のある値がポインタなのか、それとも単なる整数なのかを正確に識別できるため、不要なメモリのみを確実に解放できます。
- 保守的 GC(Conservative GC):「ポインタ」と「値がたまたまポインタ(メモリアドレス)のように見える整数」を区別できません。このような曖昧な値に遭遇した場合、安全策を取り、その値をポインタとみなして、それが指し示す先のメモリを解放しません。
具体例:
// タイムスタンプや ID など、その値がメモリ上で有効なメモリアドレスのように見えることがある
ulong id = 0x7f8a4c001234;
// 保守的 GC はこの値を見て、0x7f8a4c001234 を指すポインタであると誤解し、
// 結果として、そのアドレスのメモリ(もし存在した場合)が解放されず、メモリリークを引き起こす可能性がある。
このようにメモリ割り当てが頻繁に行われる状況では、危険な正のフィードバックループが形成されます。 一時オブジェクトの頻繁な割り当て → 「偽ポインタ」の増加 → 回収されないメモリの増加 → ヒープサイズの増大 → 次回の GC スキャン時間の増大 → 正のフィードバック
JVM では、ヒープサイズを大きくすると Young GC の発生頻度を遅らせることができます。しかしその代償として、1 回あたりの Full GC による停止時間が長くなります。これは、まさにトレードオフを考慮すべきチューニングの判断と言えるでしょう。それに対し、D言語の保守的なマーク&スイープ GC では、状況はさらに深刻です。この GC はポインタを正確に識別できないため、ヒープ全体をくまなくスキャンする必要があります。その結果、ヒープが大きくなるほどスキャン時間も長くなり、停止時間はヒープサイズにほぼ比例して増加します。
vibe.d のファイバーモデルでは、並行リクエストごとに大量のヒープアロケーション(リクエストのクロージャ、動的バッファ、文字列連結など)が生成されます。これらのオブジェクトが継続的に蓄積されることで、GC のスキャン負荷が増大すると同時に、GC がいつ発生するかの予測もさらに困難になります。このように、「ヒープサイズを大きくする」というチューニング手法は、JVM においてさえ有効性に疑問があるものですが、D 言語においてはほぼ逆効果となってしまうのです。
最適化の方向性:GC の動作方式を最適化するのではなく、GC の作業負荷そのものを削減する。
| 優先度 | アプローチ | 適用シナリオ | コード例 |
|---|---|---|---|
| 高 | @nogc アノテーションの付与 | ヒープ割り当てを完全に避けたい、パフォーマンスクリティカルな関数 | @nogc void processOrderFast(...) |
| 中 | オブジェクトプーリング | ライフサイクルが短く、頻繁に生成・破棄されるオブジェクト | auto order = orderPool.acquire(); |
| 低 | バッファの事前確保 | 出力サイズがある程度予測できる場合 | appender.reserve(4096); |
最大のホットスポット:getUserOrders が 59.4% を占有、根本原因はデータ構造
フレームグラフによると、services.order_manager.OrderManager.getUserOrders が CPU 時間の 59.4% を占有しており、最大のパフォーマンスホットスポットとなっています。
関数名だけを見ると、「注文検索処理が遅い」という結論になりがちです。しかし、どのように最適化すべきかを判断するには、コールスタックをさらに掘り下げて分析する必要があります。
getUserOrders (59.4%)
└─ std.algorithm.iteration.FilterResult ← 配列のフィルタリング処理
└─ __memcmp_avx2_movbe (15.2%) ← メモリ比較命令
根本原因の特定:
getUserOrdersは、すべての注文を含む配列をリニアスキャン(O(n) の計算量)していました。- 配列内の各注文について、
userIdフィールドで文字列比較(__memcmp_avx2_movbe)を実行していました。 - 条件に一致した注文を、新しい結果配列にコピーしていました。
この問題は、コードが簡潔でロジックも明快なため、通常のコードレビューで発見するのはほぼ不可能です。n(注文総数)が十分に大きい状態で、実際に高い並行アクセス負荷がかかったときに初めて、この O(n) のコストが CPU 使用率 59.4% という驚異的な数値にまで増幅されるのです。
最適化案:空間計算量と引き換えに時間計算量を改善する(空間と時間のトレードオフ)、ユーザー ID をキーにしたインデックスを構築する。
// 最適化前:O(n) のリニアスキャン。問い合わせの度に全注文データを走査する。
auto getUserOrders(string userId) {
return allOrders.filter!(o => o.userId == userId).array;
}
// 最適化後:O(1) のハッシュ検索
private Order[][string] userOrdersIndex; // ユーザー ID をキーとする注文のインデックス
auto getUserOrders(string userId) {
if (auto orders = userId in userOrdersIndex) {
return *orders; // インデックスから直接、事前に構築済みの注文リストを返す
}
return [];
}
トレードオフ分析:
- メリット:検索の計算量が O(n) から O(1) に削減され、このホットスポットの CPU 使用率を 59.4% から 5% 未満 にまで低減できると期待されます。
- デメリット:
- メモリコスト:
userOrdersIndexを保持するための追加メモリが必要になります。 - 書き込み時の同期:注文の作成・更新時に、インデックスも同期的に更新する必要があります。
- メモリコスト:
- 適用シナリオ:読み取り処理が書き込み処理よりも圧倒的に多い(今回のケースではリード/ライト比が約 100:1)業務においては、このトレードオフはほぼ常に有効です。
本番環境へ実装する際の考慮事項:
- インデックスへの並行書き込みに対する安全性(ロック機構や
shared型による排他制御)。 - 注文ステータスが変更された際の、インデックスの同期ロジック。
- サービス再起動時におけるインデックスのコールドスタート戦略(どのようにインデックスを再構築するか)。
その他のホットスポット:Appender (14.2%) と JSON (約 8%)
std.array.Appender:見過ごされがちなメモリアロケーション増幅器
フレームグラフでは、std.array.Appender 関連の処理が 14.2% を占めています。しかし、その影響は CPU 使用率の数値だけにとどまりません。
重要な洞察: フレームグラフ上では、Appender と GC は 2 つの独立したホットスポットに見えますが、実際には同一の問題が異なる側面から現れたものです。
因果関係の連鎖:
Appender による小さなデータの頻繁な追記
↓
内部バッファの容量不足により、動的なメモリ拡張が発生
↓
より大きなメモリ領域を新たに確保し、旧データをコピー
↓
古いメモリ領域がガベージ(GC 対象)となる
↓
GC のスキャン・回収負荷が増大 (26.4% のホットスポットに繋がる)
最適化の方向性: データサイズがある程度予測できる場合は、あらかじめ reserve() を呼び出して十分な容量を確保し、実行時の動的なメモリ拡張を回避します。
JSON シリアライズ:分散している約 8% のコスト
JSON の処理コストは parseJson や serializeToJson といった複数の関数に分散しており、合計で約 8% を占めています。このように処理が分散しているため、フレームグラフ上では単一の目立つホットスポットとして現れにくく、見過ごされがちですが、その累計コストは決して無視できません。ただし、最適化に割けるリソースが限られている場合は、より優先度の高い他の最適化を終えた後に着手すべきでしょう。
最適化ロードマップ:なぜ対策そのものより「順序」が重要なのか
すべてのホットスポットを特定した後、最初に最適化すべきはどれでしょうか?もし手順を誤ると、単に効率が低下するだけでなく、先に行った最適化の効果が、後続の最適化によって無効化されてしまうことさえあります。
| 優先度 | ホットスポット | 割合 | 判断根拠 |
|---|---|---|---|
| 高 | GC + getUserOrders | 26.4% + 59.4% | 両者には密接な因果関係があり、同時に最適化すべきです。これにより、パフォーマンスを飛躍的に向上させることが可能です。 |
| 中 | Appender | 14.2% | この項目が持つ実際の重要度は、GC の最適化が完了した後の再サンプリング結果によって判断されます。 |
| 低 | JSON シリアライズ | ~8% | 得られる改善効果は限定的であり、代替ソリューションへの切り替えは開発コストが高すぎます。 |
最適化の各ステップ後には、必ず再サンプリングを実施する
フレームグラフは、特定の負荷状況におけるシステムのスナップショットに過ぎません。最適化を行うと、システムにおけるホットスポットの分布が変化します。そのため、最初のフレームグラフだけを基に後続のすべての最適化計画を立てるのは、非常によくある間違いです。例えば、GC の負荷が軽減されると、これまで GC による停止時間の影響で高く見えていた Appender のサンプリング割合は低下します。その時点で初めて、この項目がパフォーマンスに与える実際のインパクトを正確に評価できるのです。
上記の分析と最適化作業を通じて、パフォーマンスの大幅な向上を実現しました。
| 指標 | 最適化前 | 最適化後 | 改善幅 |
|---|---|---|---|
| P99 応答時間 | 350ms | 95ms | ↓ 73% |
| GC 占有率 | 26.4% | 6.2% | ↓ 76% |
| getUserOrders 占有率 | 59.4% | 3.1% | ↓ 95% |
| Appender 占有率 | 14.2% | 4.8% | ↓ 66% |
まとめ:コードロジックから、ランタイムで起きている「真実」へ
今回のケースを振り返り、最も重要な考察点は、特定の O(n) アルゴリズムの誤りそのものではありません。それは、**「なぜ、適切なコードレビュー体制と標準的な監視が整備されていたにもかかわらず、問題が数ヶ月にもわたって検知できなかったのか?」**という点です。
この事実は、現代のソフトウェアエンジニアリングにおける本質的な盲点を浮き彫りにします。それは、**「静的なコード品質の高さが、動的なランタイム性能の高さを保証するわけではない」**ということです。
getUserOrders のロジックは、ユニットテストや低負荷環境下では全く問題ありません。また、標準的な監視ダッシュボードに表示されるマクロな指標が、ミクロレベルでの性能の揺らぎを覆い隠していました。しかし、本番環境のトラフィック負荷に晒された結果、データ規模の増大が D 言語の GC メカニズムと相互に影響し合い、パフォーマンスの質的な変化、すなわち深刻な性能劣化を引き起こしたのです。このような「コード、データ、ランタイム」という三つの要素が複雑に絡み合って発生する問題は、静的解析や従来型の計装(埋め込み)によるモニタリング手法では捉えることができません。
OpenResty XRay は、今回のケースにおいて、主に二つの重要な技術的価値を提供しました。
- 非侵入的なエンドツーエンドの可視化:開発者による事前の計装(多くの場合、主観的な予測に基づきがちです)を必要とせず、コードの変更やサービスの再起動も不要です。本番環境で実行中のプロセスを直接動的に追跡し、実際の負荷の下でコードが辿るマイクロ秒単位の実行パスを明らかにします。
- 最適化における「確実性」の提供:パフォーマンス問題の調査において最大のコストは、見当違いの対策を試行錯誤することです。今回のケースでも、もしフレームグラフによる正確なデータがなければ、開発チームはヒープメモリを闇雲に増やすといった経験則に頼りがちでした。しかし、D 言語のコンサバティブ GC の特性上、その対策はまさに逆効果となります。OpenResty XRay は、P99 応答時間の揺らぎといった曖昧な現象を、関数レベルの実行時間や GC 占有率といった具体的なデータに定量化することで、推測ではなく、データに基づいた技術的意思決定を可能にします。
パフォーマンス最適化とは、本質的にはシステムリソースの再配分です。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(マイクロサービスおよび分散トラフィックに最適化された多機能
翻訳
英語版の原文と日本語訳版(本文)をご用意しております。読者の皆様による他の言語への翻訳版も歓迎いたします。全文翻訳で省略がなければ、採用を検討させていただきます。心より感謝申し上げます!















