バッチアプリにおけるOpentelemetryでの分散トレーシング検証メモ

10799 ワード
分散トレーシング Java opentelemetry zipkin Java テキストリンク

はじめに

Opentlemetryの分散トレーシングについていろいろ調査したが基本的にWebアプリのトレーシングに関する内容がほとんどで、APIをコールするBatchアプリについてトレーシングしたい場合の方法がわからなかったので、BatchアプリにおけるOpentelemetryの検証を行った。
今回はその検証内容についてメモとしてまとめる。

実現したい分散トレーシングのイメージは下図のとおりで、Batchアプリの起動から終了までの間を1Traceとしてトレーシングするのが目標。

利用するバージョンは下記の通り。

  • opentelemetry：1.0.1
  • Zipkin：2.23.2
  • Java：OpenJDK 11.0.2

検証1：Webアプリ側のトレーシング検証

WebアプリのWebApp01に対してAPI Callしたときに正しく動作するか確認を行った。
WebApp01およびWebApp02はSpringBootで実装しており、ログにはTraceIdとSpanIdを出力する設定を入れている。
Webアプリの起動時にこちらの記事に記載されている方式を参考にし、あらかじめダウンロードしたAgentのjarを起動オプション指定し実行する。

Webアプリの起動コマンドは下記の通りである。

$ java -javaagent:opentelemetry-javaagent-all.jar -Dotel.traces.exporter=zipkin \ 
       -Dotel.zipkin.endpoint=http://localhost:9411/api/v2/spans \
       -Dotel.exporter.zipkin.service.name=web_app_01 \
       -Dotel.metrics.exporter=none \ # メトリックスはOFFにする
       -jar web-app-01/target/web-app-01.jar

Zipkinでの出力結果は下記のとおりであり、WebApp01 -> WebApp02についてのトレーシングできていることが確認できる。
※SerivceNameを指定しているにも関わらず、Zipkin上でUNKNOWN_SERVICEと表示される事象については現在調査中。

検証2：Batchアプリのトレーシング検証(1)

Batchアプリに検証1と同じようにAgentを組み込んだ場合のトレーシング検証である。
Batchアプリのロギング設定にもWebアプリ同様にTraceId、SpanIdを設定している。
また、アプリの起動オプションははWebアプリと同じ設定としている。

Zipkinでの出力結果は下図の通りであり、バッチアプリ側はAPIのGetメソッド実行部分の処理からがトレーシング対象となっており、ジョブの起動から終了までの全体のトレーシングができていないことが確認できる。

検証3：Batchアプリのトレーシング検証(2)

いろいろ検索した結果、opentelemetry-extension-annotationsを利用することで任意のメソッドをトレーシング対象として設定することが判明したので、その方法でトレーシング検証を行う。

まずは、Batchアプリの依存ライブラリにopentelemetry-extension-annotationsを追加する。

pom.xml
  <dependency>
    <groupId>io.opentelemetry</groupId>
    <artifactId>opentelemetry-extension-annotations</artifactId>
    <version>1.0.1</version>
  </dependency>

その後、BatchアプリでSpanとして計測したいメソッドに@WithSpanを設定する。

  • 設定例
SampleJobRunner.java
import io.opentelemetry.extension.annotations.WithSpan;
//省略

public class SampleJobRunner implements CommandLineRunner {

    @WithSpan
    public void run(String... args) throws Exception {
        final String jobName = System.getProperty("job.name");
        log.info("Job Start, JobName:{}.", jobName);
        apiCall();
        log.info("Job Finished, JobName:{}.", jobName);
    }

    @WithSpan
    private void apiCall() {
         //処理は省略
    }
}

上記設定後、「検証2：Batchアプリのトレーシング検証(1)」と同じ方法でBatchアプリを起動した結果、下図の通りBatchアプリのrunメソッドからトレーシングされていることが確認できた。

また、Batchアプリのログ、Webアプリのログでは同じTraceIdでログ出力されていることも確認できた。

batch
2021-06-19 21:28:24 trace:bc36ac3e733f5cc0f7875b08604fd005 span:e0748955ace7d29e thread:main level:INFO     logger:com.example.sample.runner.SampleJobRunner        message:Job Start, JobName:sample.
2021-06-19 21:28:24 trace:bc36ac3e733f5cc0f7875b08604fd005 span:f60deafc5f7d16a3 thread:main level:INFO     logger:com.example.sample.runner.SampleJobRunner        message:API Call, URL : http://localhost:8881/web01/sample.
2021-06-19 21:28:24 trace:bc36ac3e733f5cc0f7875b08604fd005 span:f60deafc5f7d16a3 thread:main level:INFO     logger:com.example.sample.runner.SampleJobRunner        message:StatusCode : 200 OK, Header : {Content-Type=application/json, Transfer-Encoding=chunked, Date=Sat, 19 Jun 2021 12:28:24 GMT, Keep-Alive=timeout=60, Connection=keep-alive}.
2021-06-19 21:28:24 trace:bc36ac3e733f5cc0f7875b08604fd005 span:f60deafc5f7d16a3 thread:main level:INFO     logger:com.example.sample.runner.SampleJobRunner        message:Response Message : web01-app-message.
2021-06-19 21:28:24 trace:bc36ac3e733f5cc0f7875b08604fd005 span:e0748955ace7d29e thread:main level:INFO     logger:com.example.sample.runner.SampleJobRunner        message:Job Finished, JobName:sample.
2021-06-19 21:28:24 trace:bc36ac3e733f5cc0f7875b08604fd005 span:fbb222846e9c58bd thread:main level:INFO     logger:com.example.sample.JobRunner                     message:Job Normally Finished, Execution time : 2152ms
web-app-01/web-app-02
date:2021-06-19 21:28:24    trace:bc36ac3e733f5cc0f7875b08604fd005  span:e98db147d1913074   thread:http-nio-8881-exec-9 X-Track:    level:INFO  logger:com.example.webapp01.Controller                  message:getSample is Called.
date:2021-06-19 21:28:24    trace:bc36ac3e733f5cc0f7875b08604fd005  span:e98db147d1913074   thread:http-nio-8881-exec-9 X-Track:    level:INFO  logger:com.example.webapp01.Controller                  message:Header : {traceparent=00-bc36ac3e733f5cc0f7875b08604fd005-528fff0462f17bbb-01, host=localhost:8881, connection=keep-alive, accept=application/json, application/*+json, user-agent=Java/11.0.2}.
date:2021-06-19 21:28:24    trace:bc36ac3e733f5cc0f7875b08604fd005  span:e98db147d1913074   thread:http-nio-8881-exec-9 X-Track:    level:INFO  logger:com.example.webapp01.Controller                  message:API Call, URL : http://localhost:8882/web02/sample.
date:2021-06-19 21:28:24    trace:bc36ac3e733f5cc0f7875b08604fd005  span:7fad792962413c9e   thread:http-nio-8882-exec-8 X-Track:    level:INFO  logger:com.example.webapp02.Controller                  message:getSample is Called.
date:2021-06-19 21:28:24    trace:bc36ac3e733f5cc0f7875b08604fd005  span:7fad792962413c9e   thread:http-nio-8882-exec-8 X-Track:    level:INFO  logger:com.example.webapp02.Controller                  message:Header : {traceparent=00-bc36ac3e733f5cc0f7875b08604fd005-1930db76decfbcb2-01, host=localhost:8882, connection=keep-alive, accept=application/json, application/*+json, user-agent=Java/11.0.2}.
date:2021-06-19 21:28:24    trace:bc36ac3e733f5cc0f7875b08604fd005  span:e98db147d1913074   thread:http-nio-8881-exec-9 X-Track:    level:INFO  logger:com.example.webapp01.Controller                  message:StatusCode : 200 OK, Header : {Content-Type=application/json, Transfer-Encoding=chunked, Date=Sat, 19 Jun 2021 12:28:24 GMT, Keep-Alive=timeout=60, Connection=keep-alive}.
date:2021-06-19 21:28:24    trace:bc36ac3e733f5cc0f7875b08604fd005  span:e98db147d1913074   thread:http-nio-8881-exec-9 X-Track:    level:INFO  logger:com.example.webapp01.Controller                  message:Response Message : web02-app-message.

参考