サイドカーライブラリ Dapr の分散トレーシングを試す
ちょっと前にこんなニュースがありました。
公式はこの辺かな?
Microsoft が OSS で、しかも golang で作ったという異色のライブラリです。
また最近は envoy を使ったサービスメッシュについて色々と調べていたこともあり、似たような問題を解決するものであるといこともあり、興味を持ちました。
サンプルやコンセプトページを見ているとなんとなく雰囲気がつかめてきます。
- Isito のように、各サービスにサイドカーとして起動するDapr インスタンスとサイドカーインスタンスを管理するDaprサーバーから構成されている。
- RedisやKafkaなどのストレージと連携して、サービス間でステートをやり取りする機能(WebAPIや言語別のSDK)がある
- そんな大したものではなく、Daprサーバーに向けてオブジェクトを登録・取得する簡単なAPIがあるという感じ
- セキュリティ、秘密管理、分散トレーシングなどの非機能要件に関する部分をある程度Dapr側でやってくれる
envoy, Istio などと比較して違いがあるのは最初にあげたBindingsでしょう。 とりあえずWebAPIとして作っておいて、DaprがよしなにgRPCとかイベント連携にしてくれるとか、自前で実行方法に合わせた連携処理を書かなくて済むというのは便利です。
と色々と気になる機能はありますが、今回はの主題は分散トレーシングについてです。
サイドカーで分散トレーシング
どうして分散トレーシングが気になるかと言えば、 envoy などのサイドカーパターンで分散トレーシングを行うには Context Propagation というトレース情報の伝播が必要だからです。
サービスを跨ぐ複数の通信をトレーシングで一連の処理だと認識するには、 各通信で一位となるID(トレースIDとか呼ばれる)を受け渡していく必要があります。
分散トレーシングライブラリはサーバー側(通信の入り口)でヘッダなどを見てトレースIDがあるかを調べ、あるならそれを使い、無いなら新しくトレースIDを作ります。
同一処理内で外部API通信などを行うクライアント側(通信の出口)でも通信のヘッダにサーバー側で取得したトレースIDを乗せることで、一連のトレースであることを認識させていきます。
これが伝播と呼ばれるもので、実装するのがとても面倒です。
Zipkin Brave, OpenTelemetry, Spring Cloud Sleuth など様々なライブラリやフレームワークがあり、現状はOpenTelemetryにまとまるかもしれないという希望もありつつ、まだまだ群雄割拠な状態です。
envoy のようなサイドカーの分散トレーシングがやってくれるのは、トレースサーバーへの情報送信だったり、ZipkinやJaeger,StackDriverなど複数トレースサーバーへの差異の吸収だったりします。
トレースIDの伝播は、そもそもサービス内から実行するクライアント実行の通信が一連のトレースかどうかを判断する術をサイドカーが持たないので、サービス側の責務になります。
ということは伝播のための仕組みやライブラリをサービス側から完全に消し、透過的な分散トレーシングを実現することは困難というのが現時点での私の結論でした。
となると、Daprのトレーシングは果たしてどうかというのが気になってしまいます。
Dapr で分散トレーシングに言及しているのはこの辺り。
まだサンプル集には実装例はありませんでしたが、ドキュメントを見ていると、
- OpenTelemetry使うから、Dapr側で ZipkinとかJargerとかにトレース情報送る
- X-Correlation-ID というのがトレースID的なもの
- X-Correlation-ID がヘッダにあればそのまま使うし、無いなら新しく作るとある
最後の文面が出てきた時点であまり期待はできなくなったのですけど、折角ですし試してみました。
Dapr で分散トレーシング
試したコードはこちらです。
Daprはk8sでもオンプレミスでも動くようです。(オンプレミスで分散で動かすガイドはまだ見当りませんが)
またローカルなどでテスト用途で動かすための standalone モードがありますので、今回はそちらで試します。
に従い、Daprを導入すると dapr cli が手に入り、Docker上 で daprサーバーと ステート管理のための redis が動くようになります。
55bf9b9c9e52 daprio/dapr "./placement" 4 days ago Up 4 days 0.0.0.0:50005->50005/tcp dapr_placement ad75cf783790 redis "docker-entrypoint.s…" 4 days ago Up 4 days 0.0.0.0:6379->6379/tcp dapr_redis
あとは、サービスのコードを作成したら、 dapr run コマンドでサービスとサイドカーを一緒に起動するという感じです。
まずは適当にservice2 という名前でアプリを作ってみます。
// app.js const express = require('express'); const bodyParser = require('body-parser'); const app = express(); app.use(bodyParser.json()); const port = 3001; app.post('/apply', (req, res) => { console.log(req.headers) res.send({message:"hello! " + req.body.name}) }); app.listen(port, () => console.log(`Node App service2 listening on port ${port}!`));
JSONを受け取り、リクエストヘッダをプリントして、返すというだけの簡単なものです。
また準備としてzipkinを起動し、Daprに zipkinにトレースを送るように設定します。
zipkin起動
docker run -d -p 9411:9411 openzipkin/zipkin
dapr サイドカーに trace と zipkin の設定を行います。
設定は CRD形式というk8sでの設定ファイルの書式です。
tracing.yml、これはトレースの送信方法など汎用的な設定です
apiVersion: dapr.io/v1alpha1 kind: Configuration metadata: name: tracing spec: tracing: enabled: true expandParams: true includeBody: true
zipkin.yaml , zipkinにトレースを送るための設定。トレース送信先の実装に応じて変更するものです。
apiVersion: dapr.io/v1alpha1
kind: Component
metadata:
name: zipkin
spec:
type: exporters.zipkin
metadata:
- name: enabled
value: "true"
- name: exporterAddress
value: "http://10.200.10.1:9411/api/v2/spans"
これらを サービスごとに components というディレクトリを作って置いておきます。
(components ディレクトリは、 dapr run コマンド実行時に自動で作れらる場合もあり、デフォルトでいくつかのファイルが勝手にできます。サイドカーの設定などを規定する場所となっています)
では、サイドカーと一緒にサービスを dapr run コマンドで起動します。
$ dapr run --app-id service2 --app-port 3001 --port 3501 --config ./components/tracing.yaml node app.js ℹ️ Starting Dapr with id service2. HTTP Port: 3501. gRPC Port: 55788 == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="starting Dapr Runtime -- version 0.2.0 -- commit c75b111" == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="log level set to: info" == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="standalone mode configured" == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="dapr id: service2" == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="loaded component statestore (state.redis)" == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="loaded component zipkin (exporters.zipkin)" == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="loaded component messagebus (pubsub.redis)" == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="loaded component tracing ()" == DAPR == time="2019-11-26T01:41:06+09:00" level=info msg="application protocol: http. waiting on port 3001" ✅ You're up and running! Both Dapr and your app logs will appear here. == APP == Node App service2 listening on port 3001! == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="application discovered on port 3001" == DAPR == 2019-11-26 01:41:07.169239 I | redis: connecting to localhost:6379 == DAPR == 2019-11-26 01:41:07.216321 I | redis: connected to localhost:6379 (localAddr: [::1]:55814, remAddr: [::1]:6379) == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="actor runtime started. actor idle timeout: 1h0m0s. actor scan interval: 30s" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="actors: starting connection attempt to placement service at localhost:50005" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="http server is running on port 3501" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="gRPC server is running on port 55788" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="local service entry announced" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="dapr initialized. Status: Running. Init Elapsed 651.0255980000001ms" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="actors: established connection to placement service at localhost:50005" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="actors: placement order received: lock" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="actors: placement order received: update" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="actors: placement tables updated" == DAPR == time="2019-11-26T01:41:07+09:00" level=info msg="actors: placement order received: unlock"
3501 ポートで dapr インスタンスが起動し、 3001 ポートで起動したservice2 に接続しているようです。
docker 上の dapr インスタンスと、ホスト上の node アプリケーションが合わさり、ログも混ざって出てる(== APP == の行)のが、なかなか面白いですね。
service2 は、 localhost:3001/apply で待ち受けしていますが、 これをdapr サイドカーは、localhost:3501/v1.0/invoke/service2/method/apply と、 /
最初は面食らいますが、URLを全体でユニークにするためなのかな?
では呼び出してみます。
$ curl -X POST http://localhost:3501/v1.0/invoke/service2/method/apply -d '{"name":"test"}'
{"message":"hello! test"}
ログは次のような感じ。
== APP == {
== APP == 'user-agent': 'curl/7.54.0',
== APP == host: '127.0.0.1:3001',
== APP == 'content-type': 'application/json',
== APP == 'content-length': '15',
== APP == accept: '*/*',
== APP == 'x-correlation-id': '86d482e659eea6f4;fcc76f86bce3a9614b9a372a36ab242f;1'
== APP == }
x-correlation-id が出ているので、zipkinを確認してみます。
ちなみに、x-correlation-id の ;より前は spanIDで、後ろがトレースIDです。
トレースが出ています。dapr サイドカーがいい感じにzipkinにトレースを送ってくれたようです。
2サービス間のトレーシング
では本題となる、2サービス間のトレーシングを試してみます。
前述のService2 を呼び出すService1 を別のサービスとして作成し、こちらも dapr サイドカーと一緒に起動します。
ポイントは Service2 のURLです。ソースにもある通り、Service1(自分)のサイドカーのURL(localhost:3500) + /v1.0/invoke/service2 としていて、 Serivce2のサイドカーに直接向けていません。Service2のアドレス解決は、Daprがやってくれます。
// app.js const express = require('express'); const bodyParser = require('body-parser'); const fetch = require("node-fetch") const app = express(); app.use(bodyParser.json()); const port = 3000; // dapr サイドカー経由のURL const service2URL = "http://localhost:3500/v1.0/invoke/service2/method/apply" app.get('/hello', (req, res) => { console.log(req.headers) fetch(service2URL, { method: "POST", body: JSON.stringify({name:"service1"}), headers: { "content-type":"application/json" // リクエストヘッダのトレースIDをクライアントのリクエストヘッダに伝播する // , "x-correlation-id" : req.headers["x-correlation-id"] } }).then(r => r.json()) .then(data => res.send(data)) }); app.listen(port, () => console.log(`Node App service1 listening on port ${port}!`));
ある程度答えは見えていたので恣意的ですが、とりあえずは x-correlation-id ヘッダの連携は今はしないようにコメントアウトしています。
dapr サイドカーを3500ポートで起動します。
dapr run --app-id service1 --app-port 3000 --port 3500 --config ./components/tracing.yaml node app.js
余談ですが、 dapr list で起動している dapr インスタンスも見れます。
$ dapr list APP ID HTTP PORT GRPC PORT APP PORT COMMAND AGE CREATED PID service2 3501 56104 3001 node app.js 12m 2019-11-26 01:51.24 53879 service1 3500 56938 3000 node app.js 11s 2019-11-26 02:03.23 55314
さて、service1 を呼び出してみます。
$ curl http://localhost:3500/v1.0/invoke/service1/method/hello
{"message":"hello! service1"}
service1 のログ
== APP == {
== APP == 'user-agent': 'curl/7.54.0',
== APP == host: '127.0.0.1:3000',
== APP == 'content-type': 'application/json',
== APP == accept: '*/*',
== APP == 'x-correlation-id': 'e757cdd5120e5471;a8ef06433d0fbf475e9d4e71e6caddd2;1'
== APP == }
service2 のログ
== APP == {
== APP == 'user-agent': 'node-fetch/1.0 (+https://github.com/bitinn/node-fetch)',
== APP == host: '127.0.0.1:3001',
== APP == 'content-type': 'application/json',
== APP == 'content-length': '19',
== APP == accept: '*/*',
== APP == 'accept-encoding': 'gzip,deflate',
== APP == 'x-correlation-id': 'ad8782c8425119f8;c49be5e2c42af227a984a36677c246d3;1',
== APP == connection: 'close'
== APP == }
見事に x-correlation-id が一致してないです。zipkinもおかしい。
ぱっと見、service1,service2 のスパンのあるトレースがあるので、成功? とも思ったけど中身がおかしい 。
gRPCの内部の通信のようなもの? を拾っているようだ。
で、service1 の app.js の コメントアウトしてある x-correlation-id の伝播を設定して、service1 を再起動します。 この場合は次のように、同一のトレースIDになりました。
$ curl http://localhost:3500/v1.0/invoke/service1/method/hello
{"message":"hello! service1"}
service1
== APP == {
== APP == 'user-agent': 'curl/7.54.0',
== APP == host: '127.0.0.1:3000',
== APP == 'content-type': 'application/json',
== APP == accept: '*/*',
== APP == 'x-correlation-id': '327d36a56fb4f0b7;fe6ad7b82c9e24156d73da4f24646a81;1'
== APP == }
service2
== APP == {
== APP == 'user-agent': 'node-fetch/1.0 (+https://github.com/bitinn/node-fetch)',
== APP == host: '127.0.0.1:3001',
== APP == 'content-type': 'application/json',
== APP == 'content-length': '19',
== APP == 'x-correlation-id': '3c614f073b853834;fe6ad7b82c9e24156d73da4f24646a81;1',
== APP == accept: '*/*',
== APP == 'accept-encoding': 'gzip,deflate',
== APP == connection: 'close'
== APP == }
zipkin も次の通り。
前述の分断されたトレースが１つにまとまったように見える。
なんでservice1のspanが4つ(自分のサイドカーに向けた通信だから?) とか、service2 の gRPC 呼び出しは何だ(サイドカー内部の通信はgRPC?)? とか疑問は残りますが、 dapr でも トレース情報の伝播は必須だということがわかりました。
まとめ
Dapr でもサービス内でヘッダ情報の伝播は必須だということがわかりました。
伝播に必須なのは x-correlation-id だけなので、楽といえば楽なんですけど。
実際、伝播や instrumentation のライブラリを作るのもそこまで難しくないでしょうし、OpenTelemetry でも用意されるのかな?
とはいえ、透過的な分散トレーシングは夢ではあるので、もしお前の呼び出し方はおかしいとか、こうすれば行けるとか、こんなAPIがあるよとかご指摘があれば是非ともお願いところです。
分散トレーシング以外でDapr に感じることは、 envoy 直接使うよりも設定は楽だし、dapr 前提でマイクロサービスを設計すると色々楽ができる部分がありそうなので将来性を感じました。
今後も注視していきたいと思います。
