NGINXおよびNGINX Plus向けOpenTracing

NGINX | 2019年6月17日

多くのメリットがある一方で、マイクロサービスアーキテクチャは新たな複雑さももたらします。その1つが、アプリケーションを構成するすべてのマイクロサービス間でデータが流れる中、処理されるリクエストを追跡するという課題です。この目的のために、分散（リクエスト）トレーシングと呼ばれる新しい手法が考案されました。また、OpenTracingは、分散トレーシングツールの設計と実装の指針となる仕様および標準APIセットです。

NGINX Plus Release 18（R18）では、NGINX OpenTracingモジュールを動的モジュールリポジトリに追加しました（このモジュールは、GitHub上のサードパーティ製モジュールとして数年前から提供されています）。NGINX OpenTracingモジュールの大きな利点は、分散トレーシング用にNGINXとNGINX Plusを計装することで、各アプリケーションを個別に計装しなくても、プロキシ経由のすべてのアプリケーションのトレースデータを取得できることです。

このブログでは、NGINXまたはNGINX Plusでリクエストの分散トレーシングを有効にする方法を紹介します（以降、簡潔にするため、単に「NGINX Plus」と表記します）。また、2つの分散トレーシングサービス（OpenTracingの用語では「トレーサー」）、すなわちJaegerとZipkinの使用手順を説明します。（その他のトレーサーの一覧については、OpenTracingのドキュメントを参照してください。）トレーサーから得られる情報の例として、NGINX Plusのキャッシュを有効にする前と後で、リクエスト処理を比較します。

トレーサーには、2つの基本コンポーネントがあります。

エージェントは、自身が稼働するホスト上のアプリケーションからトレースデータを収集します。ここでの「アプリケーション」はNGINX Plusであり、エージェントはプラグインとして実装されます。
1つ以上のエージェントからトレースデータを受信し、中央のUIに表示するサーバー（コレクターとも呼ばれます）。このサーバーは、必要に応じてNGINX Plusホストまたは別のホストで実行できます。

トレーサーサーバーのインストール

最初に、使用するトレーサー用のサーバーをインストールして設定します。ここではJaegerとZipkinの手順を説明します。その他のトレーサーについては、必要に応じて手順を調整してください。

Jaegerサーバーのインストール

Jaegerサーバーのインストールには、次の方法を推奨します。ステップ1に記載されているURLからDockerイメージをダウンロードすることもできます。

Navigate to the Jaegerダウンロードページに移動し、Linuxバイナリ（執筆時点ではjaeger-1.12.0-linux-amd64.tar）をダウンロードします。
バイナリを/usr/bin/jaegerに移動し（必要に応じて、先にディレクトリを作成します）、実行します。

$ mkdir /usr/bin/jaeger$ mv jaeger-1.12.0-linux-amd64.tar /usr/bin/jaeger
$ cd /usr/bin/jaeger
$ tar xvzf jaeger-1.12.0-linux-amd64.tar.gz
$ sudo rm -rf jaeger-1.12.0-linux-amd64.tar.gz
$ cd jaeger-1.12.0-linux-amd64
$ ./jaeger-all-in-one

ブラウザーで http://Jaeger-server-IP-address:16686/ にアクセスし、Jaeger UIが表示されることを確認します（16686はJaegerサーバーのデフォルトポートです）。

Zipkin Serverのインストール

ZipkinのDockerイメージをダウンロードして実行します（ここではデフォルトのポート9411を使用します）。

$ docker run -d -p 9411:9411 openzipkin/zipkin

ブラウザーで http://Zipkin-server-IP-address:9411/ にアクセスし、Zipkin UIが表示されることを確認します。

Tracerプラグインのインストールと設定

JaegerまたはZipkin用のプラグインをインストールするには、NGINX Plusホストで次のコマンドを実行します。

Jaegerプラグインのインストール

Jaegerプラグインをインストールします。次のwgetコマンドはx86-64 Linuxシステム用です：

$ cd /usr/local/lib
$ wget https://github.com/jaegertracing/jaeger-client-cpp/releases/download/v0.4.2/libjaegertracing_plugin.linux_amd64.so -O /usr/local/lib/libjaegertracing_plugin.so

ソースからプラグインをビルドする手順については、GitHubをご覧ください。
プラグイン用に、以下の内容でJSON形式の設定ファイル/etc/jaeger/jaeger-config.jsonを作成します。Jaegerサーバーにはデフォルトポート6831を使用します。

{  "service_name": "nginx",
  "sampler": {
    "type": "const",
    "param": 1
  },
  "reporter": {
    "localAgentHostPort": "Jaeger-server-IP-address:6831"
  }
}

For details about the samplerオブジェクトの詳細については、Jaegerドキュメントを参照してください。

Zipkin Plug‑Inのインストール

Zipkinプラグインをインストールします。次の「wget」コマンドは、x86-64 Linuxシステム用です。

$ cd /usr/local/lib$ wget -O - https://github.com/rnburn/zipkin-cpp-opentracing/releases/download/v0.5.2/linux-amd64-libzipkin_opentracing_plugin.so.gz | gunzip -c > /usr/local/lib/libzipkin_opentracing_plugin.so

プラグイン用に、以下の内容を含むJSON形式の設定ファイルを作成し、/etc/zipkin/zipkin-config.jsonという名前で保存します。Zipkinサーバーにはデフォルトポート9411を使用します。

{  "service_name": "nginx",
  "collector_host": "Zipkin-server-IP-address",
  "collector_port": 9411
}

構成オブジェクトの詳細については、GitHubのJSONスキーマを参照してください。

NGINX Plusの設定

NGINX Plusホストで以下の手順を実行します。

次のガイドの手順に従って、NGINX OpenTracingモジュールをインストールします。NGINX Plus Admin Guide.
NGINX Plusのメイン設定ファイル（load_module）のmain（最上位）コンテキストに、次の/etc/nginx/nginx.confディレクティブを追加します：

load_module modules/ngx_http_opentracing_module.so;

NGINX Plusの設定に次のディレクティブを追加します。従来の設定方式を使用する場合は、ディレクティブを新しいファイル/etc/nginx/conf.d/opentracing.confに記述します。また、次のincludeディレクティブが/etc/nginx/nginx.confのhttpコンテキストに含まれていることも確認してください。

http {
    include /etc/nginx/conf.d/*.conf;
}

# Load a vendor tracer#opentracing_load_tracer /usr/local/libjaegertracing_plugin.so 
#                        /etc/jaeger/jaeger-config.json;
#opentracing_load_tracer /usr/local/lib/libzipkin_opentracing_plugin.so
#                        /etc/zipkin/zipkin-config.json;

# Enable tracing for all requests
opentracing on;

# Set additional tags that capture the value of NGINX Plus variables
opentracing_tag bytes_sent $bytes_sent;
opentracing_tag http_user_agent $http_user_agent;
opentracing_tag request_time $request_time;
opentracing_tag upstream_addr $upstream_addr;
opentracing_tag upstream_bytes_received $upstream_bytes_received;
opentracing_tag upstream_cache_status $upstream_cache_status;
opentracing_tag upstream_connect_time $upstream_connect_time;
opentracing_tag upstream_header_time $upstream_header_time;
opentracing_tag upstream_queue_time $upstream_queue_time;
opentracing_tag upstream_response_time $upstream_response_time;

#uncomment for debugging
# log_format opentracing '$remote_addr - $remote_user [$time_local] "$request" '
#                        '$status $body_bytes_sent "$http_referer" '
#                        '"$http_user_agent" "$http_x_forwarded_for" '
#                        '"$host" sn="$server_name" '
#                        'rt=$request_time '
#                        'ua="$upstream_addr" us="$upstream_status" '
#                        'ut="$upstream_response_time" ul="$upstream_response_length" '
#                        'cs=$upstream_cache_status';
#access_log /var/log/nginx/opentracing.log opentracing;
 
server {
    listen 9001;

    location / {
        # The operation name used for OpenTracing Spans defaults to the name of the
        # 'location' block, but uncomment this directive to customize it.
        #opentracing_operation_name $uri;

        # Propagate the active Span context upstream, so that the trace can be 
        # continued by the backend.
        opentracing_propagate_context;

        # Make sure that your Ruby app is listening on port 4567
        proxy_pass http://127.0.0.1:4567;
    }
}

The opentracing_load_tracerディレクティブは、トレーサープラグインを有効にします。必要に応じて、JaegerまたはZipkinのいずれかのディレクティブをコメント解除してください。
The opentracing_tagディレクティブにより、NGINX Plus変数をトレーサーUIに表示されるOpenTracingタグとして使用できるようになります。
OpenTracingのアクティビティをデバッグするには、log_formatディレクティブとaccess_logディレクティブのコメントを解除します。デフォルトのNGINXアクセスログとログ形式をこの設定に置き換える場合は、これらのディレクティブのコメントを解除し、「opentracing」と記述されている3か所を「main」に変更します。別の方法として、ポート9001のトラフィックに限定してOpenTracingのアクティビティをログに記録できます。その場合は、log_formatディレクティブとaccess_logディレクティブのコメントを解除し、serverブロック内に移動します。
The serverブロックでは、次のセクションで説明するサンプルRubyアプリケーション用にOpenTracingを設定します。

NGINX Plusの設定を検証し、再読み込みします：

$ nginx -t$ nginx -s reload

サンプルRubyアプリのセットアップ

トレーサーとNGINX Plusの設定が完了したら、OpenTracingデータがどのように表示されるかを確認できるサンプルRubyアプリを作成します。このアプリでは、NGINX Plusのキャッシュによって応答時間がどの程度短縮されるかを測定できます。アプリは、次のようなHTTP GETリクエストを / に対して受信すると、2～5秒の範囲でランダムな時間待機してから応答します。

$ curl http://NGINX-Plus-IP-address:9001/

Install and set up both RubyとSinatra（他のRuby Webアプリケーションフレームワークに代わる、Rubyで記述されたオープンソースのWebアプリケーションライブラリおよびドメイン固有言語）の両方をインストールしてセットアップします。
次の内容で「app.rb」というファイルを作成します。

#!/usr/bin/ruby

require 'sinatra'

get '/*' do
    out = "<h1>Ruby simple app</h1>" + "\n"

    #Sleep a random time between 2s and 5s
    sleeping_time = rand(4)+2
    sleep(sleeping_time)
    puts "slept for: #{sleeping_time}s."
    out += '<p>some output text</p>' + "\n"

    return out
end

Make app.rbを実行可能にして、実行します：

$ chmod +x app.rb$ ./app.rb

キャッシュを使用しない場合の応答時間のトレース

JaegerとZipkinを使用して、キャッシュが有効になっていない場合にNGINX Plusがリクエストに応答するまでの時間を示します。各トレーサーで5件のリクエストを送信します。

キャッシュを使用しない場合のJaegerの出力

Jaeger UIに表示される5件のリクエストは次のとおりです（新しい順）。

Rubyアプリのコンソールでも同じ情報を確認できます。

- -> /slept for: 3s. 
127.0.0.1 - - [07/Jun/2019: 10:50:46 +0000] "GET / HTTP/1.1" 200 49 3.0028
127.0.0.1 - - [07/Jun/2019: 10:50:43 UTC] "GET / HTTP/1.0" 200 49
- -> /
slept for: 2s. 
127.0.0.1 - - [07/Jun/2019: 10:50:56 +0000] "GET / HTTP/1.1" 200 49 2.0018 
127.0.0.1 - - [07/Jun/2019: 10:50:54 UTC] "GET / HTTP/1.0"1 200 49
- -> /
slept for: 3s. 
127.0.0.1 - - [07/Jun/2019: 10:53:16 +0000] "GET / HTTP/1.1" 200 49 3.0029 
127.0.0.1 - - [07/Jun/2019: 10:53:13 UTC] "GET / HTTP/1.0" 200 49
- -> /
slept for: 4s.
127.0.0.1 - - [07/Jun/2019: 10:54:03 +0000] "GET / HTTP/1.1" 200 49 4.0030 
127.0.0.1 - - [07/Jun/2019: 10:53:59 UTC] "GET / HTTP/1.0" 200 49
- -> /
slept for: 3s.
127.0.0.1 - - [07/Jun/2019: 10:54:11 +0000] "GET / HTTP/1.1" 200 49 3.0012
127.0.0.1 - - [07/Jun/2019: 10:54:08 UTC] "GET / HTTP/1.0" 200 49

Jaeger UIで最初の（最新の）リクエストをクリックし、タグとして追加したNGINX Plus変数の値を含む詳細を確認します。

キャッシュを使用しない場合のZipkinの出力

Zipkin UIに表示された、さらに5件のリクエストを以下に示します。

Rubyアプリのコンソールにも同じ情報が表示されます。

- -> /slept for: 2s.
127.0.0.1 - - [07/Jun/2019: 10:31:18 +0000] "GET / HTTP/1.1" 200 49 2.0021 
127.0.0.1 - - [07/Jun/2019: 10:31:16 UTC] "GET / HTTP/1.0" 200 49
- -> /
slept for: 3s.
127.0.0.1 - - [07/Jun/2019: 10:31:50 +0000] "GET / HTTP/1.1" 200 49 3.0029 
127.0.0.1 - - [07/Jun/2019: 10:31:47 UTC] "GET / HTTP/1.0" 200 49
- -> /
slept for: 3s.
127.0.0.1 - - [07/Jun/2019: 10:32:08 +0000] "GET / HTTP/1.1" 200 49 3.0026 
127.0.0.1 - - [07/Jun/2019: 10:32:05 UTC] "GET / HTTP/1.0" 200 49
- -> /
slept for: 3s.
127.0.0.1 - - [07/Jun/2019: 10:32:32 +0000] "GET / HTTP/1.1" 200 49 3.0015 
127.0.0.1 - - [07/Jun/2019: 10:32:29 UTC] "GET / HTTP/1.0" 200 49
- -> /
slept for: 5s.
127.0.0.1 - - [07/Jun/2019: 10:32:52 +0000] "GET / HTTP/1.1" 200 49 5.0030 
127.0.0.1 - - [07/Jun/2019: 10:32:47 UTC] "GET / HTTP/1.0" 200 49

Zipkin UIで最初のリクエストをクリックし、タグとして追加したNGINX Plus変数の値を含む詳細を確認します。

キャッシュ使用時の応答時間のトレース

NGINX Plusのキャッシュ設定

「キャッシュ」を有効にするため、「opentracing.conf」で作成したファイルにディレクティブを追加します。NGINX Plusの設定.

In the httpコンテキストに、次のproxy_cache_pathディレクティブを追加します：

proxy_cache_path /data/nginx/cache keys_zone=one:10m;

In the serverブロックに、次のproxy_cacheディレクティブとproxy_cache_validディレクティブを追加します：

proxy_cache one;
proxy_cache_valid any 1m;

設定を検証して再読み込みします：

$ nginx -t$ nginx -s reload

キャッシュを有効にしたJaegerの出力

2回のリクエスト後のJaeger UIは次のとおりです。

最初のレスポンス（ラベル：13f69db）には4秒かかりました。NGINX Plusがこのレスポンスをキャッシュしたため、約15秒後にリクエストを再送した際はNGINX Plusのキャッシュからレスポンスが返され、所要時間は2ミリ秒（ms）未満でした。

2つのリクエストを詳しく確認すると、応答時間に差が生じた理由がわかります。最初のリクエストでは、upstream_cache_statusがMISSとなっており、リクエストされたデータがキャッシュになかったことを示しています。Rubyアプリによって4秒の遅延が追加されました。

2回目のリクエストでは、upstream_cache_statusはHITです。データはキャッシュから取得されるため、Rubyアプリによる遅延は発生せず、応答時間は2 ms未満です。また、upstream_*の値が空であることからも、この応答にアップストリームサーバーが関与していないことがわかります。