谷本 心 in せろ部屋

はてなダイアリーから引っ越してきました

Dapr Advent Calendar 8日目 - DaprとZipkinで分散トレーシング

こんにちは、Dapr Advent Calendar 8日目です。今週は会社で全エンジニアとの1 on 1などやっており、なかなかの忙しさなのですが、何とかブログを続けられています!

DaprとZipkinで分散トレーシングをしてみよう

今回はDaprとZipkinを使って分散トレーシングをしてみます。最近色々なサービスやミドルウェアが分散トレーシングに対応するようになったので、だいぶ世の中に認知される技術になりましたよね。使ってるかどうかは別として😏

分散トレーシングやZipkinについての解説をすると長くなるので、あまりご存じないという方は先に調べておいてくださいね。

今回作成するアプリケーションのソースコードgithubに置いてあります。

https://github.com/cero-t/dapr-advent-2021/

今回は、過去に作成した「hello」「publish」と「subscribe」モジュールを使い、また「tracing」モジュールを作成します。

Daprで分散トレーシングを使ってみる

いきなり分散トレーシング

まずはアクセスしてみる

いきなりですが、Advent Calendar 2日目で作ったHello Worldのアプリケーションを起動させます。

cd hello
dapr run --app-id hello-app --app-port 8080 --dapr-http-port 18080 ../mvnw spring-boot:run

起動したら、Dapr経由でアプリケーションにアクセスしてみます。

curl localhost:18080/v1.0/invoke/hello-app/method/hello

メッセージが表示されるはずです。

{"message":"Hello, world!"}

特に問題なくアクセスができたでしょう。

f:id:cero-t:20211202051328p:plain
いま呼び出したアプリケーション

Zipkinにアクセス

そしたら、ブラウザで次のURLにアクセスしてみます。

http://localhost:9411/

そうするとZipkinの画面が表示されるので、右上の方にある「RUN QUERY」ボタンを押すと、何やら一覧が出てきます。

f:id:cero-t:20211208062840j:plain
Zipkinのトレース一覧画面

3つ並んでいるうちの一番上の「SHOW」ボタンを押してみます。

f:id:cero-t:20211208062934p:plain
Zipkinのトレース詳細画面

何やら結果が表示され、いま行ったリクエストが記録されていることが分かりました。

Daprを起動しただけなのに、Zipkinにアクセスできるし、トレーシングも行われている様子が分かります。まずはこの環境から説明します。

Zipkinと分散トレーシングは最初から設定されている

Dapr Advent Calendar 1日目に、Dapr CLIを使って dapr init をすると設定ファイルとDockerコンテナがいくつかできるという説明をしました。

上でアクセスした localhost:9411 は、ここで作成されたzipkinのDockerコンテナです。Daprのローカル環境では、最初から分散トレーシングを行えるようZipkinがインストールされるのです。

また、dapr init で同じように作成された ~/.dapr/config.yaml も見てみましょう。

~/.dapr/config.yaml

apiVersion: dapr.io/v1alpha1
kind: Configuration
metadata:
  name: daprConfig
spec:
  tracing:
    samplingRate: "1"
    zipkin:
      endpointAddress: http://localhost:9411/api/v2/spans

設定ファイルの詳細はあとで説明しますが、ひとまず spec.tracing という設定が行われていることが分かります。

dapr run コマンドでアプリケーションを起動する際に、--config オプションでこの設定ファイルを指定することができますが、指定しない場合には ~/.dapr/config.yaml が参照されるようになっています。

つまりローカル環境で dapr init を行うと、zipkinと ~/.dapr/config.yaml が作成されて、分散トレーシングが行われるように設定されるのです。これまで作ってきたアプリケーションたちも、気づかないうちに裏でzipkinにリクエストが記録されていたのです。

もう少し分散トレーシングらしいアプリケーションを作る

Hello Worldを呼ぶコントローラークラスの作成

Hello Worldを直接呼ぶだけでは分散トレーシングをしている感じがしないため、せめてHello Worldを呼び出すアプリケーションを別に作って、まとめて分散トレーシングをしてみましょう。

(tracing) TracingController.java

@RestController
public class TracingController {
    private RestTemplate restTemplate;

    @Value("http://localhost:${DAPR_HTTP_PORT}/v1.0/invoke/hello-app/method")
    private String helloUrl;

    public TracingController(RestTemplate restTemplate) {
        this.restTemplate = restTemplate;
    }

    @GetMapping("/invokeHello")
    public Map<String, ?> invokeHello() {
        Map<?, ?> result = restTemplate.getForObject(helloUrl + "/hello", Map.class);
        return Map.of("baseUrl", helloUrl, "remoteMessage", result);
    }
}

呼び出す処理のエンドポイントを /invokeHello としました。Advent Calendar 3日目に作成したものと同じですね。

ポート番号をアプリケーション設定ファイルで指定

続いて、設定ファイルでアプリケーションの起動ポートを指定します。

(tracing) application.properties

server.port=8087

このアプリケーションは8087番ポートを利用します。

Daprを使ったアプリケーションの起動

それではDaprを使ってアプリケーションを起動します。

dapr run --app-id tracing-app --app-port 8087 --dapr-http-port 18087 ../mvnw spring-boot:run

アプリケーションが起動したら次のコマンドでアクセスしてみます。

curl localhost:18087/v1.0/invoke/tracing-app/method/invokeHello

次のような結果が表示されるはずです。

{"remoteMessage":{"message":"Hello, world!"},"baseUrl":"http://localhost:18087/v1.0/invoke/hello-app/method"}

問題なくアクセスができました。

f:id:cero-t:20211208064331p:plain
いま呼び出したアプリケーション

Zipkinで確認する

いま行ったアクセスを確認するために、ブラウザでZipkinにアクセスします。

http://localhost:9411/

表示結果を時系列にするために「Start Time」をクリックして時間の降順に並べるようにしました。

f:id:cero-t:20211208064849j:plain
Zipkinのトレース一覧画面

結果を見ると、/v1.0/metadata へのアクセス以外に、ほぼ同じ時刻に tracing-app calllocal/hello-app/hellotracing-app calllocal/tracing-app/invokehello の2つが並んでいます。前者は「tracing-appからhello-appの/helloを呼んだ」という記録で、後者が「tracing-appの/invokeHelloが呼ばれた」という記録です。

分散トレーシングは、こういうものを1つにまとめる仕組みなのに、分かれているのはおかしいですね。なぜでしょうか。

トレースIDの伝播

複数のプロセスにまたがった分散トレーシングを行うためには「どのリクエストに紐付く処理なのか」を示すためのIDをリクエスト間で伝播させる必要があります。このIDはトレースIDとか、相関ID(correlation-id)と呼ばれています。

分散トレーシングを経験した人ほど、このトレースIDをどう伝播させるかに悩まされていると思うのですが、Daprの公式ドキュメントでもその辺りはきちんと触れられておらず、意外と話題にならないのが不思議です。

このトレースIDは様々な仕様や流派があるのですが、Daprでは W3C Trace-Context に準拠した traceparent が使われています。ちなみにDapr 0.6あたりまでは x-correlation-id という独自のトレースIDを利用しました。

traceparentを伝播させるようコントローラークラスを修正

それでは、この traceparent を伝播させるようなメソッドをコントローラークラスに追加しましょう。

(tracing) TracingController.java(抜粋)

    @GetMapping("/invokeHello2")
    public Map<String, ?> invokeHello(@RequestHeader("traceparent") String traceparent) {
        HttpHeaders httpHeaders = new HttpHeaders();
        httpHeaders.set("traceparent", traceparent);
        HttpEntity<?> request = new HttpEntity<>(httpHeaders);

        Map<?, ?> result = restTemplate.exchange(helloUrl + "/hello", HttpMethod.GET, request, Map.class).getBody();
        return Map.of("baseUrl", helloUrl, "remoteMessage", result);
    }

Daprからリクエストヘッダで受け取った traceparent を取り出して、次のリクエストを呼ぶ際にリクエストヘッダに追加しています。RestTemplateの利用するメソッドが getForObject から exchange に変わりましたが、getForObject メソッドにはリクエストヘッダを渡す機能がないので、exchange メソッドを使っています。

このメソッドは /invokeHello2 というエンドポイントにしました。

Daprを再起動して、Zipkinで確認

それでは一度アプリケーションを停止させ、Daprを使ってアプリケーションを再起動します。

dapr run --app-id tracing-app --app-port 8087 --dapr-http-port 18087 ../mvnw spring-boot:run

アプリケーションが起動したら次のコマンドでアクセスしてみます。

curl localhost:18087/v1.0/invoke/tracing-app/method/invokeHello2

次のような結果が表示されるはずです。

{"remoteMessage":{"message":"Hello, world!"},"baseUrl":"http://localhost:18087/v1.0/invoke/hello-app/method"}

いま行ったアクセスを確認するために、ブラウザでZipkinにアクセスします。

http://localhost:9411/

今度はリクエストが1つにまとめられるようになりました。

f:id:cero-t:20211208065241j:plain
Zipkinのトレース一覧画面

詳細を見ると、3つのリクエストが1つにまとまっていることが分かります。

f:id:cero-t:20211208065329p:plain
Zipkinのトレース詳細画面

上から順に「tracing-appの/invokeHello2が呼ばれた」「tracing-appからhello-appの/helloを呼んだ」「hello-appの/helloが呼ばれた」という処理になっています。この3つの記録は、ちょうどDaprを通過した場所とも一致しますね。

f:id:cero-t:20211208065611p:plain
Daprを通過するリクエス

Daprを通過するところで分散トレーシングを行っているということが分かりました。

pubsubでも分散トレーシング

ここまではInvoke APIを利用した処理で分散トレーシングを行いましたが、キューを経由するような処理でも分散トレーシングができるかどうかを試してみましょう。いったんキューを経由するため、Daprで保持していたような情報が失われるかも知れませんよね。

publishのコントローラークラスを修正

まずは以前のエントリーで作成したpublishモジュールの PublishController に、トレースIDを伝播するようなメソッドを追加します。

(publish) PublishController(抜粋)

    @PostMapping("/publish2")
    public void publish(@RequestBody Object message, @RequestHeader("traceparent") String traceparent) {
        System.out.println(traceparent);

        HttpHeaders httpHeaders = new HttpHeaders();
        httpHeaders.set("traceparent", traceparent);
        HttpEntity<?> request = new HttpEntity<>(message, httpHeaders);

        restTemplate.exchange(pubsubUrl, HttpMethod.POST, request, Void.class);
    }

上で作成した invokeHello2 と同様の方法で、トレースIDである traceparent を伝播させています。また確認するためにトレースIDを標準出力に出力しています。このメソッドは /publish2 というエンドポイントにしました。

続いて、tracingモジュール側に、これを呼び出すためのメソッドを追加します。

(tracing) TracingController.java(抜粋)

    @Value("http://localhost:${DAPR_HTTP_PORT}/v1.0/invoke/publish-app/method")
    private String publishUrl;

    @PostMapping("/invokePublish")
    public void invokePublish(@RequestBody Object message, @RequestHeader("traceparent") String traceparent) {
        System.out.println(traceparent);

        HttpHeaders httpHeaders = new HttpHeaders();
        httpHeaders.set("traceparent", traceparent);
        HttpEntity<?> request = new HttpEntity<>(message, httpHeaders);

        restTemplate.exchange(publishUrl + "/publish2", HttpMethod.POST, request, Void.class);
    }

上で作成した /publish2traceparent を伝播させながら呼び出しています。こちらでもトレースIDを標準出力に出力しています。こちらは /invokePublish というエンドポイントにしました。

Daprを使ったアプリケーションの起動

それでは作成したアプリケーションをDaprを使って起動させましょう。

まずはtracingアプリケーションをいったん停止させ、再起動します。

dapr run --app-id tracing-app --app-port 8087 --dapr-http-port 18087 ../mvnw spring-boot:run

続いて、publishアプリケーションを起動します。

cd publish
dapr run --app-id publish-app --app-port 8083 ../mvnw spring-boot:run

さらに、subscribeアプリケーションを起動します。

cd subscribe
dapr run --app-id subscribe-app --app-port 8084 ../mvnw spring-boot:run

pubsubは今回は標準で用意されたRedisを使うため、特に components の指定などはしていません。

f:id:cero-t:20211208070016p:plain
ここで起動したアプリケーション

アクセスして分散トレーシングの結果を見てみる

それでは起動したアプリケーションにアクセスしてみましょう。

curl -XPOST "localhost:18087/v1.0/invoke/tracing-app/method/invokePublish" -H "Content-type:application/json" -d '{
  "name": "Shin Tanimoto",
  "twitter": "@cero_t"
}'

そしてzipkinにアクセスしてみます。

http://localhost:9411/

いま送ったリクエストが一つにまとまって出力されているはずです。

f:id:cero-t:20211208070451p:plain
invokePublishのトレース詳細

tracing-appからpublish-appを経由してsubscribe-appまで一連の処理が流れたことがよく分かります。

また、tracingアプリケーション、publishアプリケーションそれぞれのコンソールには、トレースIDが出力されているはずです。

== APP == 00-8c991c3d443d34906f76f86a1b55fc03-205e7c2adf46ae1b-01

そして、subscribeアプリケーションのコンソールには、次のようなメッセージが出力されるはずです。

== APP == {"specversion":"1.0","source":"publish-app","type":"com.dapr.event.sent","traceid":"00-8c991c3d443d34906f76f86a1b55fc03-6d547142bb715869-01","data":{"name":"Shin Tanimoto","twitter":"@cero_t"},"id":"8318fa00-c587-46fc-aba6-53513feac2c6","datacontenttype":"application/json","topic":"my-message","pubsubname":"pubsub"}

このうち traceid のところに、同じトレースIDが出力されているはずです。どうやらpubsubではこの traceid という項目で traceparent を伝播させるということが分かりましたね。

同期処理だけではなく、非同期のpubsubでも問題なく分散トレーシングができることが分かりました。

今回やったことの解説

それでは、Daprがどのように分散トレーシングを行うかの仕組みについて説明します。

Daprの分散トレーシングに関するドキュメントはここにあります。

docs.dapr.io

Daprによる分散トレーシングの概要

f:id:cero-t:20211208070753p:plain
Tracing Overview

公式ドキュメントの図に示されているようにDaprの中でTracing Middlewareが動いており、Daprをリクエストが経由するたびに、Tracing Backend(今回はzipkin)にその情報が蓄積されるようになっています。逆に言えば、Daprを経由しないアクセスでは情報は蓄積されません。

上では、Daprを経由する形でアクセスしたため、Zipkinに情報が記録されました。

curl localhost:18080/v1.0/invoke/hello-app/method/hello

ここで、Daprを経由せずに直接アプリケーションにアクセスすると

curl localhost:8080/hello

何度アクセスしても、Zipkinには情報が記録されません。あくまでもDaprを経由したリクエストのみがZipkinに記録されるのです。

DaprのMiddleware機能

上で「Tracing Middleware」と簡単に言いましたが、このMiddlewareについてもう少し詳しく説明します。

Middlewareのドキュメントはここにあります。

docs.dapr.io

f:id:cero-t:20211208070856p:plain
Middleware Overview

上の画像はMiddlewareのドキュメントのものです。Daprは外部からリクエストを受け、アプリケーションを呼び出す際に、Middlewareをいくつか通過するというパイプライン処理を行っていることが分かります。

Middlewareは共通的な処理を行うフィルタのようなもので、Javaの開発者であれば、ServletFilterやInterceptorのようなものだと捉えれば分かりやすいと思います。このMiddlewareのひとつがTracing Middlewareです。

Middlewareには他にも認証認可を行うものやレートリミット(アクセス数の制限)を行うものなどがあります。Middlewareの一覧はここにあります。

https://docs.dapr.io/reference/components-reference/supported-middleware/

この一覧には掲載されていませんが、Daprでは「Tracing Middleware」と「CORS Middleware」が最初から組み込まれています。

Daprのパイプライン設定ファイル

このパイプライン設定をするのが config.yaml です。今回は dapr init で作成されたものをそのまま使いました。

~/.dapr/config.yaml

apiVersion: dapr.io/v1alpha1
kind: Configuration
metadata:
  name: daprConfig
spec:
  tracing:
    samplingRate: "1"
    zipkin:
      endpointAddress: http://localhost:9411/api/v2/spans

spec.tracing が分散トレーシングの設定です。

samplingRate はDaprを経由するリクエストのうち何割をTracing Backend(zipkin)に送るかを指定するものです。分散トレーシングはたいていパフォーマンス測定に使われるため、わざわざ全リクエストを送る必要はなく、たとえば 0.010.1 などを指定して一部のリクエストだけ記録することで、分散トレーシングそのものがアプリケーションに負荷を掛けないようにします。

ただし、分散トレーシング機能そのものを確認したい場合や、登壇でデモをする場合などは、常に記録されていたほうが嬉しいので 1 を指定したほうが良いでしょう。また、分散トレーシングをパフォーマンス計測ではなく、たまに発生する障害の分析などに使いたい場合も 1 を指定すると良いと思います。その辺りは目的や負荷とのバランスで決定します。

zipkin.endpointAddress はZipkinサーバのアドレスを指定します。Zipkinだけでなく、ZipkinとAPI互換のあるJaegerやNew Relicなどのアドレスを指定することもできます。

パイプライン設定ファイルは、これまで使ってきたコンポーネント設定ファイル(/components に置くファイル)とは異なり、1つしかありません。Daprにどのようなパイプライン処理をさせるかをまとめてここに記載するため、1つしか指定できないのです。

このパイプラインの設定をすることで、分散トレーシングが有効になりました。

まとめ

  • Daprは最初からzipkinを使った分散トレーシングが有効になっている
  • 複数のアプリケーション間での分散トレーシングをするためには、traceparent というヘッダを伝播させる必要がある
  • Invoke APIでもPub/sub APIでも分散トレーシングが使える
  • DaprにはMiddlewareというパイプライン処理を行うための仕組みがある
  • 分散トレーシングはTracing Middlewareという機能で提供されている
  • ローカル環境で dapr init するとZipkinのDockerコンテナが起動し、分散トレーシングを有効にするためのパイプライン設定ファイルが作成されるため、最初から分散トレーシングが有効になる

ところで、今回は分かりやすさのため、トレースIDを伝播させる実装をそれぞれのメソッドに追加しました。実際にはこんなものを全メソッドに入れるのは無理筋ですよね。このような処理は共通的に実装するべきで、たとえばSpring BootであればRestTemplateのInterceptor機能や、WebClientのFilter機能を使って実装ができます。その辺りについてはDaprの範疇ではなくSpring Bootの範疇となるため、今回の説明からは割愛しました。

また機会があれば、この辺りの実装についても紹介したいと思います。

それでは、また明日!