NGINX と NGINX Plus によるアプリケーション トレース

アプリケーションパフォーマンス管理のための変数の使用

変数は、NGINX 構成において重要な側面ですが、見落とされてしまうこともあります。 約150 個の変数が用意されており、構成のあらゆる部分を強化できます。 このブログ記事では、アプリケーションのパフォーマンスのボトルネックを明らかにすることに重点を置いて、アプリケーション トレースとアプリケーション パフォーマンス管理 (APM) に NGINX 変数を使用する方法について説明します。 この投稿は、NGINX Open Source と NGINX Plus の両方に適用されます。 簡潔にするために、2 つのバージョンに違いがある場合を除き、全体を通じて NGINX Plus を参照します。

アプリケーション配信環境

サンプル アプリケーション配信環境では、NGINX Plus がアプリケーションのリバース プロキシとして機能しています。 アプリケーション自体は、Web フロントエンドと、その背後に多数のマイクロサービスが配置された構成になっています。

エンドツーエンドのリクエスト追跡

NGINX Plus R10 (および NGINX 1.11.0) では、 $request_id変数が導入されました。これは、各 HTTP リクエストが到着すると自動的に割り当てられる、ランダムに生成された 32 個の 16 進文字の文字列です (例: 444535f9378a3dfa1b8604bc9e05a303 )。 この一見単純なメカニズムにより、トレースとトラブルシューティングのための強力なツールが実現します。 NGINX Plus とすべてのバックエンド サービスを設定して$request_id値を渡すことで、すべてのリクエストをエンドツーエンドでトレースできます。 このサンプル設定は、フロントエンドの NGINX Plus サーバー用です。

アップストリーム app_server { server 10.0.0.1:80;
}

server {
listen 80;
add_header X-Request-ID $request_id; # クライアントに返す
location / {
proxy_pass http://app_server;
proxy_set_header X-Request-ID $request_id; # アプリケーション サーバーに渡す
}
}

リクエスト トレース用に NGINX Plus を構成するには、まず、アップストリームブロックでアプリケーション サーバーのネットワークの場所を定義します。 わかりやすくするために、ここでは 1 つのアプリケーションサーバーのみを示しますが、通常は高可用性と負荷分散のために複数のアプリケーション サーバーを使用します。

アプリケーションサーバーブロックは、NGINX Plus が受信 HTTP リクエストを処理する方法を定義します。 listenディレクティブは、NGINX Plus にポート 80 (HTTP トラフィックのデフォルト) でリッスンするように指示しますが、実稼働構成では通常、転送中のデータの保護に SSL/TLS が使用されます。

add_headerディレクティブは、 $request_id値をレスポンスのカスタム ヘッダーとしてクライアントに送り返します。 これはテストに役立ち、モバイル アプリなど独自のログを生成するクライアント アプリケーションにも役立ち、クライアント側のエラーをサーバー ログと正確に一致させることができます。

最後に、 locationブロックはアプリケーション空間全体 ( / ) に適用され、 proxy_passディレクティブはすべてのリクエストをアプリケーション サーバーにプロキシするだけです。 proxy_set_headerディレクティブは、アプリケーションに渡される HTTP ヘッダーを追加して、プロキシされたリクエストを変更します。 この場合、 X-Request-IDという新しいヘッダーを作成し、それに$request_id変数の値を割り当てます。 したがって、アプリケーションは NGINX Plus によって生成されたリクエスト ID を受け取ります。

$request_id のエンドツーエンドのログ記録

アプリケーション トレースの目標は、アプリケーション パフォーマンス管理の一環として、リクエスト処理ライフサイクルにおけるパフォーマンスのボトルネックを特定することです。 処理中に重要なイベントをログに記録することでこれを実行し、後で予期しない遅延や不当な遅延がないか分析できるようにします。

NGINX Plus の設定

まず、フロントエンドの NGINX Plus サーバーを構成して、 access_trace.logファイルに使用されるカスタム ログ形式traceに$request_idを含めます。

log_format trace '$remote_addr - $remote_user [$time_local] "$request" ' '$status $body_bytes_sent "$http_referer" "$http_user_agent" ' '"$http_x_forwarded_for" $request_id '; アップストリーム app_server { server 10.0.0.1; } server { listen 80; add_header X-Request-ID $request_id; # クライアントの場所に戻る / { proxy_pass http://app_server; proxy_set_header X-Request-ID $request_id; # アプリケーションサーバーに渡すaccess_log /var/log/nginx/access_trace.log trace ; # $request_id をログに記録 } }

バックエンドアプリケーションの構成

アプリケーションにリクエスト ID を渡すことは問題ありませんが、アプリケーションがそれを使用して何かを実行しない限り、アプリケーションのトレースに実際には役立ちません。 この例では、 uWSGIによって管理される Python アプリケーションがあります。アプリケーションのエントリ ポイントを変更して、リクエスト ID をログ変数として取得してみましょう。

uwsgiからset_logvarをインポートします。def main (environ, start_response): set_logvar ( 'requestid' , environ[ 'X_REQUEST_ID' ])

次に、uWSGI 構成を変更して、標準ログ ファイルにリクエスト ID を含めることができます。

ログ形式 = %(addr) - %(user) [%(ltime)] "%(method) %(uri) %(proto)" %(status) %(size) "%(referer)" "%(uagent)" %(requestid)

この構成を導入することで、多数のシステムにわたる単一のリクエストにリンクできるログ ファイルが生成されます。

NGINX からのログエントリ:

172.17.0.1 - - [2016/08/02:14:26:50 +0000] "GET / HTTP/1.1" 200 90 "-" "-" "-" 5f222ae5938482c32a822dbf15e19f0f

アプリケーションからのログエントリ:

192.168.91.1 - - [2016/08/02:14:26:50 +0000] "GET / HTTP/1.0" 200 123 "-" "-" 5f222ae5938482c32a822dbf15e19f0f

SplunkやKibanaなどのツールを使用すると、トランザクションをリクエスト ID フィールドと照合することで、アプリケーション サーバーのパフォーマンスのボトルネックを特定できます。 たとえば、完了までに 2 秒以上かかったリクエストを検索できます。 ただし、通常のタイムスタンプのデフォルトの時間分解能である 1 秒は、ほとんどの実際の分析には不十分です。

高精度タイミング

エンドツーエンドでリクエストを正確に測定するには、ミリ秒レベルの精度のタイムスタンプが必要です。 ログ エントリに$msec変数を含めると、各エントリのタイムスタンプの精度がミリ秒になります。 アプリケーション ログにミリ秒のタイムスタンプを追加すると、完了までに 2 秒ではなく 200 ミリ秒以上かかったリクエストを検索できるようになります。

しかし、それでも、NGINX Plus は各リクエストの処理の最後にのみ$msecタイムスタンプを書き込むため、全体像は得られません。 幸いなことに、NGINX Plus にはミリ秒単位の精度を持つタイミング変数が他にもいくつかあり、処理自体についてより詳しい情報を得ることができます。

• $request_time – NGINX Plusがクライアントから最初のバイトを読み取った時点から、NGINX Plusがレスポンス本文の最後のバイトを送信した時点までの完全なリクエスト時間
• $upstream_connect_time – アップストリームサーバーとの接続を確立するのにかかった時間
• $upstream_header_time – アップストリームサーバーへの接続を確立してからレスポンスヘッダーの最初のバイトを受信するまでの時間
• $upstream_response_time – アップストリームサーバーへの接続を確立してからレスポンス本文の最後のバイトを受信するまでの時間

これらのタイミング変数の詳細については、 「アプリケーション パフォーマンス監視のための NGINX ログの使用」を参照してください。

log_formatディレクティブを拡張して、これらの高精度のタイミング変数をすべてトレースログ形式に含めてみましょう。

log_format トレース '$remote_addr - $remote_user [$time_local] "$request" $status ' '$body_bytes_sent "$http_referer" "$http_user_agent" ' '"$http_x_forwarded_for" $request_id $msec $request_time ' '$upstream_connect_time $upstream_header_time $upstream_response_time' ;

推奨のログ分析ツールを使用して変数値を抽出し、次の計算を実行して、NGINX Plus がアプリケーション サーバーに接続する前にリクエストを処理するのにかかった時間を確認できます。

NGINX Plus 処理時間 = $request_time - $upstream_connect_time - $upstream_response_time

また、 $upstream_response_timeの最高値を検索して、それが特定の URI またはアップストリーム サーバーに関連付けられているかどうかを確認することもできます。 そして、これらは同じリクエスト ID を持つアプリケーション ログ エントリに対してさらにチェックできます。

結論

新しい$request_id変数と、一部またはすべてのミリ秒精度変数を利用すると、アプリケーションのパフォーマンスのボトルネックに関する詳細な情報が得られ、重いエージェントやプラグインに頼ることなくアプリケーションのパフォーマンス管理が向上します。

NGINX Plus を使用したアプリケーション トレースをぜひお試しください。今すぐ30 日間の無料トライアルを開始するか、弊社にお問い合わせの上、ユースケースについてご相談ください。