Spring Cloud はマイクロサービスアーキテクチャを構築します: 分散サービス追跡 (追跡原則)

前回の記事「分散サービストレース (入門)」の例を通じて、Spring Cloud Sleuth を介してマイクロサービスアプリケーションに分散トレースを実装するための基本要素を追加しました。この記事では、分散サービストラッキングを実装する際の重要なポイントについて詳しく説明します。

分散システムにおけるサービスの追跡は、理論的には複雑ではありません。主に以下の2つのポイントが含まれます。

リクエスト追跡を実装するには、リクエストが分散システムのエントリエンドポイントに送信されたときに、サービス追跡フレームワークでそのリクエストの一意の追跡識別子を作成する必要があります。同時に、分散システム内を循環する場合、フレームワークは、要求元に返されるまで、常に一意の識別子を渡し続けます。この一意の識別子は、前の記事で説明した Trace ID です。トレース ID を記録することで、すべてのリクエストプロセスログを関連付けることができます。
各処理ユニットの遅延時間をカウントするため、リクエストが各サービスコンポーネントに到達したとき、または処理ロジックが特定の状態に到達したとき、* 識別子を使用してその開始、特定のプロセス、および終了をマークします。この識別子は、前の記事で説明した Span ID です。各スパンには、開始ノードと終了ノードの 2 つのノードが必要です。スパンの始まりと終わりのタイムスタンプを記録することで、スパンの時間遅延をカウントできます。タイムスタンプレコードに加えて、イベント名、リクエスト情報などの他のメタデータも含めることができます。

[[222355]]

クイックスタートの例では、spring-cloud-starter-sleuth コンポーネントの実装により、ログレベルのトレース情報に簡単にアクセスできました。 Spring Boot アプリケーションでは、プロジェクトに spring-cloud-starter-sleuth 依存関係を導入することで、現在のアプリケーションの各通信チャネルの追跡メカニズムが自動的に構築されます。

RabbitMQ、Kafka（またはその他の Spring Cloud Stream バインダー実装）などのメッセージングミドルウェアを介して配信されるリクエスト
Zuulプロキシを通過するリクエスト
RestTemplate を通じて開始されたリクエスト

クイックスタートの例では、trace-1 から trace-2 へのリクエストは RestTemplate を通じて実装されるため、spring-cloud-starter-sleuth コンポーネントがリクエストを処理します。 sleuth は、トレース 2 に送信する前に、トレースに必要な重要な情報をリクエストのヘッダーに追加します。主に次の情報です (ヘッダー情報の定義の詳細については、org.springframework.cloud.sleuth.Span のソースコードを表示することで取得できます)。

X-B3-TraceId: リクエストリンク（トレース）の***識別子。
X-B3-SpanId: 作業単位（Span）の一意の識別子。
X-B3-ParentSpanId: 現在の作業単位が属する前の作業単位を識別します。ルートスパン (リクエストリンクの最初の作業単位) の値が空です。
X-B3-Sampled: サンプル出力フラグが使用されているかどうか。1 は出力が必要であることを意味し、0 は出力が不要であることを意味します。
X-Span-Name: 作業単位の名前

次のように、trace-2 の実装にいくつかの変更を加えることで、これらのヘッダー情報を出力できます。

 @RequestMapping(値 = "/trace-2" 、メソッド = RequestMethod.GET)
パブリック文字列トレース(HttpServletRequest リクエスト) {
    logger.info( "===<call trace-2, TraceId={}, SpanId={}>===" ,
            リクエスト.getHeader( "X-B3-TraceId" )、リクエスト.getHeader( "X-B3-SpanId" ));
戻る  「トレース」 ;
 }

上記の変換後、クイックスタートサンプルコンテンツを再度実行し、trace-1 へのインターフェイスアクセスを開始します。次のような出力が得られます。 trace-2 のコンソールには現在処理中の TraceID と SpanId の情報が出力されます。

 --トレース-1  
 INFO [trace-1,a6e9175ffd5d2c88,8524f519b8a9e399, true ] 10532 --- [nio-9101-exec-2] icationEnhancerBySpringCGLIB27aa9624 : ===<call trace-1>===   
 
 --トレース-2  
 INFO [trace-2,a6e9175ffd5d2c88,ce60dcf1e2ed918f, true ] 1208 --- [nio-9102-exec-3] icationEnhancerBySpringCGLIBa7d84797 : ===<call trace-2、TraceId=a6e9175ffd5d2c88、SpanId=be4949ec115e554e>===

追跡情報をより直感的に観察するために、application.properties に次の構成を追加することもできます。

ログレベル.org.springframework.web.servlet.DispatcherServlet =DEBUG

Spring MVC リクエストディスパッチログレベルを DEBUG レベルに調整すると、より多くのトレース情報を確認できます。

 --トレース-1  
 2016-11-27 09:26:52.663 DEBUG [trace-1,a6e9175ffd5d2c88,a6e9175ffd5d2c88, true ] 10532 --- [nio-9101-exec-2] osweb.servlet.DispatcherServlet: 「dispatcherServlet」という名前の DispatcherServlet が [/trace-1] の GET リクエストを処理しています 
 2016-11-27 09:26:52.666 DEBUG [trace-1,a6e9175ffd5d2c88,a6e9175ffd5d2c88, true ] 10532 --- [nio-9101-exec-2] osweb.servlet.DispatcherServlet : [/trace-1] の Last-Modified 値は -1 です 
 2016-11-27 09:26:52.685 DEBUG [trace-1,a6e9175ffd5d2c88,8524f519b8a9e399, true ] 10532 --- [nio-9101-exec-2] osweb.servlet.DispatcherServlet: Null ModelAndView が 'dispatcherServlet' という名前の DispatcherServlet に返されました: HandlerAdapter がリクエスト処理を完了したと想定しています 
 2016-11-27 09:26:52.685 DEBUG [trace-1,a6e9175ffd5d2c88,a6e9175ffd5d2c88, true ] 10532 --- [nio-9101-exec-2] osweb.servlet.DispatcherServlet: リクエストが正常に完了しました  
 
 --トレース-2  
 2016-11-27 09:26:52.673 DEBUG [trace-2,a6e9175ffd5d2c88,be4949ec115e554e, true ] 1208 --- [nio-9102-exec-3] osweb.servlet.DispatcherServlet: 'dispatcherServlet' という名前の DispatcherServlet が [/trace-2] の GET リクエストを処理しています 
 2016-11-27 09:26:52.679 DEBUG [trace-2,a6e9175ffd5d2c88,be4949ec115e554e, true ] 1208 --- [nio-9102-exec-3] osweb.servlet.DispatcherServlet : [/trace-2] の Last-Modified 値は -1 です 
 2016-11-27 09:26:52.682 DEBUG [trace-2,a6e9175ffd5d2c88,ce60dcf1e2ed918f, true ] 1208 --- [nio-9102-exec-3] osweb.servlet.DispatcherServlet: Null ModelAndView が 'dispatcherServlet' という名前の DispatcherServlet に返されました: HandlerAdapter がリクエスト処理を完了したと想定しています 
 2016-11-27 09:26:52.683 DEBUG [trace-2,a6e9175ffd5d2c88,be4949ec115e554e, true ] 1208 --- [nio-9102-exec-3] osweb.servlet.DispatcherServlet: リクエストが正常に完了しました