Apollo Server に OpenTracing を導入してみたいけど・・・?
今回は OpenTracing の一例として、Apollo Server の GraphQL API のトレースログを出してみたいと思います。
Apollo にはありがたいことに OpenTracing 対応のモジュール "Apollo Opentracing" というモジュールがあるので、OpenTracing 仕様のログを出力するのは非常に簡単です。
先日の記事(【2019年10月版】TypeGraphQL なら ORM は TypeORM でしょう。)で作成いたしました Apollo Server とテスト用の docker-compose を改造して、Jeager, Zipkin でトレースログを出力してみたいと思います!
Jaeger でのトレースログ出力
それではまず、Jaeger へのログ出力を行ってみましょう。
以下の記事が非常に参考になるので(ほぼそのまま)、こちらの記事を参考に、Jaegerへの出力を行ってみたいと思います。
1. モジュールの追加
以下のコマンドにてモジュールを追加します。
$ npm i apollo-opentracing jaeger-client @types/jaeger-client
apollo-opentracing
と、今回は Jaegerを使うので、 jaeger-client
を使用します。また、jaeger-client
の型定義、@types/jaeger-client
を追加しました。
2. Tracer の作成
先ほどの記事を丸パクリして tracer を作成します。
import { initTracer } from 'jaeger-client';
const config = {
serviceName: 'apollo-typeorm-opentracing',
sampler: {
type: 'const',
param: 1,
},
reporter: {
logSpans: true,
collectorEndpoint: 'http://localhost:14268/api/traces',
},
}
const options = {
logger: {
info(msg: string) {
console.log('INFO ', msg)
},
error(msg: string) {
console.log('ERROR', msg)
},
},
}
export const tracer = initTracer(config, options)
今回は Jaeger は docker-composeでサクッと起動しますので、接続先は localhost:14268
とします。
3. プラグインの投入
続いて Apollo Server のプラグインとして上記で作った tracer
を登録します。apollo-opentracing
本家リポジトリの README にあるようにとりあえずシンプルなOpentracing 用 Extension を作成し、ApolloServer のコンストラクタで組み込みます。
...
import { default as OpentracingExtension } from "apollo-opentracing";
...
const server = new ApolloServer({
schema, playground: true, introspection: true,
extensions: [
() => new OpentracingExtension({
server: tracer,
local: tracer
})
]
});
...
コードの対応は…なんとこれだけです!
4. Jaeger コンテナの追加
テスト用のコンテナ群に、Jaeger のコンテナを追加します。
今回は Jaeger のイメージは以下の AllInOneイメージを使用してしまいます。
...(前回の続き)
jaeger:
image: jaegertracing/all-in-one
environment:
- COLLECTOR_ZIPKIN_HTTP_PORT=9411
ports:
- 5775:5775/udp
- 6831:6831/udp
- 6832:6832/udp
- 5778:5778
- 16686:16686
- 14268:14268
- 9411:9411
はい、以上です!
5. 動作確認
まず、例によって docker-compose でテスト用の関連サーバー群を立ち上げます。
$ cd test
$ docker-compose up
ログを垂れ流して、MySQL がちゃんと3306ポートを待ち受け開始したか確認してくださいね!
MySQL ポートが開かれたら、新しいターミナルから、以下のコマンドでApollo Serverを起動します。
$ npm start
ブラウザから Http://localhost:4000
を開き、立ちあがった PlayGrooundからGRaphQLのクエリをいくつか発行してみましょう。
そして、ブラウザから http://localhost:16686
にアクセスしてください。
Services
に上記の Tracer作成で指定した、apollo-typeorm-opentracing
を選択し、"Find Traces" をクリックしてください。
以下のようにいくつかのアクセストレースログが表示されるかと思います。
なかなかグラフィカルでいいですね!そして何より簡単!
ただし TypeORMの対応がまだ なので MySQL へ投げるクエリのOpentracing対応のログなどは自力でガリガリ実装する必要があるようです。。。
Zipkin 対応
TypeORM は OpenTracing 対応していませんが、Zipkin には SQL のログなどが出せるようなので Zipkin でもトレースログの出力を試してみます。
対象のソースコードは上記の Jaeger の続き…ではなく、前回の記事の続きからとなります。
1. モジュールのインストール
今回は以下のモジュールを追加いたしました。
- apollo-opentracing
- opentracing
- zipkin-javascript-opentracing
- zipkin
- zipkin-transport-http
以下のコマンドでごっそりと投入いたします。
$ npm i apollo-opentracing opentracing zipkin-javascript-opentracing zipkin zipkin-transport-http
2. Tracer の作成
続いて Zipkin 用の tracer
を作成いたします。
非常に簡易な Tracer ですが、以下の zipkin-javascript-opentracing
本家リポジトリのサンプルをそのまま拝借いたします。
import { BatchRecorder } from "zipkin";
import { HttpLogger } from "zipkin-transport-http";
const ZipkinJavascriptOpentracing = require("zipkin-javascript-opentracing");
const recorder = new BatchRecorder({
logger: new HttpLogger({
endpoint: "http://localhost:9411/api/v1/spans"
})
});
// Setup the tracer to use http and implicit trace context
export const tracer = new ZipkinJavascriptOpentracing({
serviceName: "TypeGraphQL TypeORM Sample",
recorder,
kind: "client"
});
zipkin-javascript-opentracing
は TypeScript の対応が出来ていないようなので require
してしまいます。
エンドポイントは後ほど docker-compose.yml
で作成いたしますが、localhost:9411
といたします。
3. TypeORM への仕込み
Zipking の TypeORM 用トレースログ流し込みプラグインとして zipkin-instrumentation-typeorm
がありますが、今回はこれを使用したいと・・・思ったのですがバージョンが古くて現在の Zipkin には対応できていませんでした。
ちょっとした修正を行いましたので本家ではなく私のリポジトリを参照します。
以下のように dependencies に git のパスを直指定しておきます。
...
"dependencies": {
...
"zipkin": "^0.19.1",
"zipkin-instrumentation-typeorm": "git:https://github.com/Yoshinori-Koide-PRO/zipkin-instrumentation-typeorm.git",
"zipkin-javascript-opentracing": "^2.0.1",
...
}
...
で、 npm i
を実行してください。
続いて以下のように TypeORM のコネクションをハイジャックいたします。
import { createConnection } from "typeorm";
import { TypeOrmInstrumentation } from "zipkin-instrumentation-typeorm";
import { tracer } from "./tracer"
export const connection = createConnection("local").then(con => TypeOrmInstrumentation.proxyConnection(con, { tracer: tracer._zipkinTracer, serviceName: "TypeGraphQL TypeORM Sample" }))
tracer
は import したままだと Opentracing 用の Tracer なので内部オブジェクトの_zipkinTracer
を使用します。
これで Zipkin に SQL のログが流れます。
4. Opentracing 用 Extension の作成
続いて、Jeagerの場合と同様に Extension を作成し、ApolloServer に組み込みます。
import { tracer } from "./tracer";
import { default as OpentracingExtension } from "apollo-opentracing";
...
const server = new ApolloServer({
schema, playground: true, introspection: true,
extensions: [
() => new OpentracingExtension({
server: tracer,
local: tracer
})
]
});
...
OpentracingExtension
でいろいろやってくれるようですね~。
5. Zipkin サーバーの準備
テスト環境用の docker-compose.yml
に zipkin を追加します。以下の docker-compose-slim.yml
を使ってみました。
...(前回の続き)
zipkin:
image: openzipkin/zipkin-slim
container_name: zipkin
# Environment settings are defined here https://github.com/openzipkin/zipkin/blob/master/zipkin-server/README.md#environment-variables
environment:
- STORAGE_TYPE=mem
# Uncomment to enable self-tracing
# - SELF_TRACING_ENABLED=true
# Uncomment to enable debug logging
- JAVA_OPTS=-Dorg.slf4j.simpleLogger.log.zipkin2=debug
ports:
# Port used for the Zipkin UI and HTTP Api
- 9411:9411
depends_on:
- storage
# Fake services allow us to compose with docker-compose-elasticsearch.yml
# BusyBox is pinned to prevent repetitive image pulls for no-op services
storage:
image: busybox:1.31.0
container_name: fake_storage
dependencies:
image: busybox:1.31.0
container_name: fake_dependencies
6.実行と動作確認
例によって以下のコマンドで docker-compose を立ち上げます。
$ cd test
$ docker-compose up
ログを垂れ流して、MySQL がちゃんと3306ポートを待ち受け開始したか確認してくださいね!
MySQL ポートが開かれたら、新しいターミナルから、以下のコマンドでApollo Serverを起動します。
$ npm start
ブラウザから Http://localhost:4000
を開き、立ちあがった PlayGrooundからGRaphQLのクエリをいくつか発行してみましょう。
そして、ブラウザから http://localhost:9441
にアクセスしてください。検索ボタンをクリックしてデータのロードをすると、以下のようにアクセスログが表示されいると思います。
一つをクリックしてみると、内容が展開されて詳細が見れます。
こちらはAPIのインタフェース = Resolve のメソッドが呼び出されたログですね。
Zipkin はドリルダウンでどこにどれだけ時間がかかっているかがわかるのが魅力ですが、Apollo 用の Tracer と TypeORM用の Tracer がうまく連携できていないので別々のトレーサーとしてログが表示されています。う~ん、ちゃんと連携させるにはもう一工夫必要なようです。。。
とはいえAPIのアクセスログとSQLのトレースログが簡単に取れるので、これまでよりはボトルネックの割り出しが簡単にできそうです。
開発作業が収束してから重めの性能問題が発覚するのはキツイので、実装フェーズから積極的に Jaeger or Zipkin でのAPI性能チェックを開発作業に組み込めるようにしていきたいとおもいました。
Githubに上げました。
上記のサンプルですが、github に上げました!
- Jaeger 版: https://github.com/Yoshinori-Koide-PRO/apollo-typeorm-functions/tree/jaeger
- Zipkin 版: https://github.com/Yoshinori-Koide-PRO/apollo-typeorm-functions
ご参考にどうぞ~。