旅行業界のお客様の環境で、一部の web API リクエストに原因不明の 200ms の追加遅延が発生していました。OpenResty XRay は、遅延している TCP 接続のみを対象としたパケットキャプチャを実施し——コードに一切手を加えず、本番環境のパフォーマンスにも影響を与えることなく——Nginx のリクエストボディ読み取り遅延の原因がクライアントアプリ側にあることを特定しました。同社の Android アプリが、リクエストヘッダー送信後に意図的に 200ms 遅らせてからボディを送信していたのです。

本稿では、この分析プロセスの全体を振り返り、OpenResty XRay の「スマートパケットキャプチャ」機能が、遅延の発生している（または他のエラーが発生している）TCP 接続のパケットを自動的に捕捉する仕組みをご紹介します。

OpenResty XRay で稼働中のアプリケーションを分析する

課題

アプリケーションサーバーが本来迅速に処理すべき一部の API リクエストに、200ms もの時間を要していました。

遅延の原因には様々な要因が考えられます。例えば、ディスク I/O の低速化、カーネルのネットワークスタックや他のネットワーク機器におけるパケットロス、CPU 使用率の上昇によるアプリケーションや web サーバーの応答速度低下、あるいは単にネットワーク接続の品質低下などが挙げられます。このように複数の要因が疑われる状況では、OpenResty XRay のような動的トレーシングツールを使用することで、より効率的に問題解決を図ることが可能です。

分析プロセス：遅延した TCP 接続のパケットキャプチャ

レスポンス遅延の分布

OpenResty XRay は、まずお客様の本番環境における web サーバー（この場合は OpenResty または Nginx web サーバー）で処理されているリクエストのサンプリングを実施しました。OpenResty XRay の大きな利点は、稼働中のユーザープロセスに変更を加えることなく、オンラインのアプリケーションやサーバーを安全に分析できる点にあります。

その後、レスポンス遅延に関する以下の対数分布図が自動的に生成されました。

Nginx リクエスト遅延分布図：131ms〜262ms の範囲に 5 件の遅延リクエスト

注目すべき点として、131ms から 262ms の範囲で遅延が発生している 5 件のリクエストが確認されました。

最も遅延の大きいリクエスト

OpenResty XRay は、最も遅延の大きいリクエストの URI やその他の情報も自動的に収集しました。

最も遅延の大きいリクエストの詳細テーブル：すべての遅延接続が /view/shopcart/ の URI に集中

プライバシー保護の観点から、Host 名は変更して表示しています。

上記の表から、すべての遅延リクエストが URI /view/shopcart/ に対するものであることが判明しました。

スマート Nginx パケットキャプチャ

OpenResty XRay の特徴的な機能の一つとして、関心のある遅延した接続のみを対象とした TCP パケットのキャプチャ・分析が可能です。例えば今回のケースでは、リクエスト遅延が 100ms を超える TCP 接続のみを対象にパケットをキャプチャしました。

OpenResty XRay は遅延の発生している TCP 接続を自動的に識別し、そのパケットをキャプチャしました。OpenResty XRay の web コンソールに表示されたサンプルの一つが以下の通りです。

遅延した接続の TCP パケットキャプチャタイムライン：ACK+PUSH の受信パケットの前に 200ms の間隔

このグラフでは、小さな円がサーバー側の受信（ingress）パケットを、四角が送信（egress）パケットを表しています。

グラフ上で、約 200ms の著しい遅延を示すパケットが確認されました。これは「ACK+PUSH」パケットで、小さな円で表示されていることから、クライアントから送信された受信（ingress）パケットであることが分かります。

この点から、アプリケーションサーバーやゲートウェイ web サーバーに起因する問題ではないことが判明しました。この追加の 200ms の遅延は、クライアント側もしくはクライアントとサーバー間のネットワーク接続に起因するものと考えられます。（Java Tomcat スタックにおける同様のリクエスト単位のパケットキャプチャ診断事例については、Java Tomcat のレスポンスが遅い：リクエスト単位の PCAP で遅いリクエストをピンポイント特定をご参照ください。）

根本原因：クライアント側のリクエストボディ送信遅延

クライアントとサーバー間のネットワーク接続に問題がないことの確認は容易でした。お客様は Android モバイルアプリケーションのクライアントサイドの調査に着手されました。

その結果、クライアントソフトウェアが意図的にリクエストヘッダーとリクエストボディの送信間に 200ms の遅延を挿入していたことが判明しました。これこそが Nginx のリクエストボディ読み取り遅延の根本原因でした。これで謎が解けました。

修正後の遅延状況

お客様がクライアントアプリケーションの追加遅延を修正された後の OpenResty XRay による新しいリクエスト遅延分布図では、200ms の長時間遅延が解消されていることが確認できます。

クライアント側の遅延修正後のリクエスト遅延分布図：200ms の外れ値が解消

よくある質問

遅延した接続のみを対象に TCP パケットをキャプチャする仕組みは？

OpenResty XRay のスマートパケットキャプチャは、接続レベルでフィルタリングを行います。遅延のしきい値（例えば 100ms）を設定すると、リクエスト遅延がそのしきい値を超えた TCP 接続のみでパケットをキャプチャします。すべての接続でキャプチャを行うわけではないため、本番サーバーのパフォーマンスに影響を与えません。

Nginx のリクエストボディ読み取り遅延の原因は？

本稿のケースでは、クライアントアプリがリクエストヘッダー送信後に意図的に 200ms 遅らせてからボディを送信していたことが原因でした。このほかにも、ディスク I/O の低速化、カーネルのネットワークスタックや他のネットワーク機器におけるパケットロス、CPU 使用率の上昇、ネットワーク接続の品質低下などが遅延の原因となり得ます。遅延した接続を対象とした TCP パケットキャプチャにより、どの要因が原因かを絞り込むことができます。

パケットキャプチャから遅延がクライアント側にあると判断する方法は？

パケットキャプチャのタイムラインで、遅延したパケットをどちら側が送信したかを確認します。クライアントからの受信（ingress）パケット——例えばリクエストボディを運ぶ ACK+PUSH パケット——が大きな時間間隔の後に到着している場合、遅延はクライアント側またはネットワーク側にあります。本稿のケースでは、200ms の間隔が受信の ACK+PUSH パケットの前に現れており、ネットワーク接続にも問題がないことが確認されたため、遅延の原因はクライアントアプリに絞り込まれました。

スマートパケットキャプチャは本番サーバーのパフォーマンスに影響しますか？

影響しません。OpenResty XRay は、リクエスト遅延が設定したしきい値を超えた接続のみでパケットをキャプチャするため、大多数の接続には一切触れません。本稿のお客様も本番環境でそのまま実行しましたが、パフォーマンスへの影響はありませんでした。

完全自動化された分析

OpenResty XRay は、対象プロセスのサンプリングに適切なアナライザを自動選択し、生成されたフレームグラフを自動分析した上で、分析結果を理解しやすい形式で自動分析レポートとして提示します。これにより、お客様はサーバーを常時監視する必要がなく、適切なアナライザを手動で実行する必要もなく、さらにはアナライザによるサンプリング結果を理解する必要もありません。

OpenResty XRay 日報

OpenResty XRay でアプリケーションとサーバーをスキャンする

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 以上のオープンソースソフトウェアライブラリを開発しています。

翻訳

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