MicroProfileによるマイクロサービスの分散トレース（Part2）：MicroProfile OpenTracingとJaegerによる可視化
富士通技術者ブログ～Javaミドルウェア～

はじめに

MicroProfile OpenTracingと可視化ツールJaegerを使って分散トレースをする方法について、Part1に引き続き紹介します。Part1では、JAX-RSのアプリケーションに対して、OpenTracingのAPIを何も使わずにトレースする方法を紹介しました。Part2では、OpenTracing APIを使い、より細かなトレース情報を出力する方法を紹介します。

Part2でもPart1同様にMicroProfileの実装の一つである「Launcher」およびJaegerを使用し説明します。Launcherの準備や起動方法などは、Part1の記事を参照してください。なお、Part2で例として使用するプログラムは、前回使用した3つのServiceA、ServiceB、ServiceCをベースに修正していきます。
なお、ここで紹介するプログラムの完全なソースコードは、以下で参照できます。

• https://github.com/fujitsu/app_blog/tree/master/201010/mptracing2/（GitHub, Inc.）

メソッド呼出しのトレース

JAX-RSを使ったリモート呼出しは、アプリケーションにトレース用の特別コードを記述しなくてもトレースすることができましたが、逆に、プロセス内でのメソッド呼出しは、デフォルトではトレースできません。
以下は、Part1で使用したServiceB.javaの一部ですが、accept()メソッドから呼び出しているServiceClient.call()はトレースされず、accept()メソッドから直接HTTPでリモート呼出しをしているように見えました。

  @GET
  public String accept(@QueryParam("option") String option) {
    return client.call(option);
  }

class ServiceClient {
  public String call(String option) {
    String result = ClientBuilder
      .newClient()
      .target("http://localhost:6060/service?option=" + option) // call ServiceC

このようなJAX-RS以外のメソッド呼出しをトレースするには、トレースしたいメソッドに、@Tracedを付加します。

@RequestScoped
class ServiceClient {
  @Traced
  public String call(String option) {
    String result = ClientBuilder
      .newClient()
      .target("http://localhost:6060/service?option=" + option) // call ServiceC

このように修正したプログラムを実行すると、以下のようなトレースが得られ、ServiceB.accept()からServiceClient.call()が呼ばれていることが分かります。

図1

メソッド内の一部をトレースする

トレースをする際に、メソッド全体ではなく一部のコードに費やす時間を測定したいとか、ifの分岐の状況を確認したい、ということがあります。そういう時には、OpenTracingのAPIを使用することで実現することができます。
Part1で使用した、ServiceCクラスのacceptメソッドのif内だけトレースをしてみます。

public class ServiceC {
  @Inject
  Tracer tracer;
    
  @GET
  public String accept(@QueryParam("option") String option) {
    if (option.equals("sleep")) {
      Span span = tracer.buildSpan("PORTION").start();
      try {
	Thread.sleep(500);   // intentionally delay response
      } catch (Exception e) {}
      span.log("only portion");
      span.finish();
    }
    return "Service accepted : " + option + "¥n";
  }

io.opentracing.Tracerクラスとio.opentracing.Spanクラスを使います。Tracer.buildSpan()で、トレース情報を作成し、start()によりトレースの開始を指示、そして、Span.finish()により、トレースの終了を指示しています。また、Span.log()により、トレースに付加情報をつけることができます。
このように修正したプログラムを実行すると、以下のようなトレースが得られます。

図2

図中のPORTIONというのは、Tracer.buildSpan()に指定した文字列で、トレースに名前を付けることができます。Span.log()に指定した文字列は、Jaegerでは、eventとして表示されています。

JAX-RSの呼出しでログを追加する

前項では、新たに作ったトレースの中でログを入れていましたが、デフォルトのJAX-RSの呼出しトレースの中にログを入れることもできます。
先ほど同様、Tracerクラスを使用します。Tracer.activeSpan()で、現在のSpan、すなわち、デフォルトのJAX-RS呼出しのSpanを取り出すことができます。Part1で使用した、ServiceAクラスのacceptメソッド内に、ログを入れてみます。

public class ServiceA {
  @Inject
  Tracer tracer;
  
  @GET
  public String accept(@QueryParam("option") String option) {
    String result = ClientBuilder
      .newClient()
      .target("http://localhost:7070/service?option=" + option) // call ServiceB
      .request()
      .get(String.class);
    tracer.activeSpan().log("serviceA returns " + result);
    return result;
  }

このように修正したプログラムを実行すると、以下のようなトレースが得られます。

図3

ServiceA.accept()のトレース中のeventに挿入したログが表示されていることが分かります。

まとめ

モノリシックアプリケーションでのトレースは、プロセス内のメソッドトレースが主でしたが、マイクロサービスでのトレースは分散トレースが重要になり、従来のツールや技術とは違うものを使用しなければなりません。Part1、Part2の二回にわたり、MicroProfile OpenTracingとJaegerを使った手法を紹介しましたが、マイクロサービスでの分散トレースの参考になれば幸いです。