はじめに こんにちは。 アドベントカレンダー 8日目担当、 サーバーサイドエンジニアの miyauchi です。 昨年は「 Goとクリーンアーキテクチャとトランザクションと 」と「 Vim初心者から中級者の入り口くらいまで 」を書きました。 早いものでもう一年経つのですね。 さて、弊社ではバックエンドシステムを従来のモノリス型のサービスから、徐々にマイクロサービスへ移行中です。 そんな中で分散トレーシング(とりわけOpenTracing)について調査する機会がありました。 よって、今年はGoのアプリケーションで、OpenTracingを使うときのコード集を、解説ありで書いていきたいと思います。 「OpenTracingとは!」や、「分散トレーシングとは!」のような概念部分は書きません。 また、OpenTracingのTracer実装である jaeger についても詳細は書きません。 OpenTracingを使ったサンプルコード中心で、 チュートリアルに毛が生えたくらいの入門記事となります。 OpenTracingの具体的な使い方については、案外まとまった記事がないのかなと思ったので書こうと思ったわけですが、 一方で、少し今更感もあります、、、が、張り切っていきましょう! 分散トレーシングについて 「概念部分は書かない!」とは言ったものの、いきなりコードはやっぱりしんどいかもしれません。 なので、分散トレーシングとOpenTracingについて少しだけ説明します。 サービスを細かく分割していくと、 一回のリクエスト(HTTPリクエストなど)で複数のサービスやミドルウェアをコールすることになります。 そうすると困ってくることの一つが、一つの処理を追跡することが難しくなることが挙げられます。 例えば 「このリクエストすごく重いんだけど、いっぱいサービスコールしていてどこがボトルネックなのかわからない!」 といったものですね。 分散トレーシングは分散システムにおいてのサービス間呼び出しの追跡を助けます。 そして、OpenTracingは分散トレーシングのための、仕様、ライブラリ、ドキュメントなどから構成される開発キットのようなものです。 詳細は公式Webサイトより。 https://opentracing.io/ それでは、早速ですがコードを見ていきます。 今回紹介するソースコードは全て aptpodのGithubリポジトリ にあります。 手元でコードを見たい方はクローンをしておきましょう。 以降、コマンドなどの実行は全て、同リポジトリルートがカレントディレクトリである前提で進めます。 ミニマムアプリケーションを実装する 実装アプリケーションについて 最初にクライアントからHTTPコールするだけの、すごく簡単なミニマムアプリケーションを実装していきます。 こんな感じです。 +--------+ | client | +---+----+ | ^ | | client | | side | +--------+--------- | server | | side | v | v +--------------+ | hoge-service | +---+----------+ はい、簡単ですね。 OpenTracingの実装の流れ 流れの説明をする前に、 OpenTracingのAPIを使っていると、 Tracer 、 Span 、 SpanContext という用語が頻出します。これらについて少しだけ補足します。 要所で簡単に解説はしますが、ちゃんと理解するために The OpenTracing Data Model 、 及び The OpenTracing API を読むことをおすすめします。 ここでは、 Span と Tracer についてだけ簡単に図と合わせて説明します。 -----------------------------------------------------> time | parentspan | +----------------------------------------------+ | child span | | child span | +------------+ +-----------------------+ | grand child span | +------------------+ 任意の時間に特定の期間である Span Span は入れ子にすることができる 一番最初に Span を開始するのが Tracer 概念だけふんわりイメージできればOKです。 繰り返しになりますが、正確な理解は本家ドキュメントを読むことをおすすめします。 では実際の実装の流れについて説明します。 OpenTracingを使うときは基本的には次のような流れになります。 Tracer の初期化(原則アプリケーション起動時に一回) Tracer の取得 Span の開始 親の Span から新しい Span の開始 親の Span から新しい Span の開始 Span の終了 ...(任意の Span の開始と終了) Span の終了 ...(任意の Span の開始と終了) Span の終了 Tracer から Span を開始して、 Span から Span を入れ子にしていくイメージです。 実装する Tracerを初期化する Span は Tracer が開始します。 まずはアプリケーションのどこからでも参照できる、 GlobalTracer に Tracer をセットしましょう。 Tracer はインターフェースとなっていて実装は様々です。 今回は、jaegerを使うので こちら のコードを参考にして、 Tracer を初期化します。 jaeger独自の設定部分の解説は割愛します。 詳細は 公式 や Githubのリポジトリ を参照してください。 下記のコードのいずれかをコールすると jaeger版の Tracer の初期化が完了し、 GlobalTracer にセットされます。 // ./lib/tracer.go package lib import ( "io" "github.com/opentracing/opentracing-go" "github.com/uber/jaeger-client-go" "github.com/uber/jaeger-client-go/config" "github.com/uber/jaeger-client-go/log" "github.com/uber/jaeger-lib/metrics" ) func InitGlobalTracer(serviceName string) (io.Closer, error) { return initGlobalTracer(config.Configuration{ Sampler: &config.SamplerConfig{ Type: jaeger.SamplerTypeConst, Param: 1, }, Reporter: &config.ReporterConfig{ LogSpans: true, }, }, serviceName) } func InitGlobalTracerProduction(serviceName string) (io.Closer, error) { return initGlobalTracer(config.Configuration{}, serviceName) } func initGlobalTracer(cfg config.Configuration, serviceName string) (io.Closer, error) { jLogger := log.StdLogger jMetricsFactory := metrics.NullFactory return cfg.InitGlobalTracer( serviceName, config.Logger(jLogger), config.Metrics(jMetricsFactory), ) } GlobalTracer にセットするコードを紹介しましたが、そうではなく、オブジェクトとして生成し使い回すことも可能です。 // ./lib/tracer.go func CreateTracer(serviceName string) (opentracing.Tracer, io.Closer, error) { var cfg config.Configuration jLogger := log.StdLogger jMetricsFactory := metrics.NullFactory cfg.ServiceName = serviceName return cfg.NewTracer( config.Logger(jLogger), config.Metrics(jMetricsFactory), ) } クライアントを実装する 次にクライアント側の実装コードを見ていきます。 // ./minclient/main.go package main import ( "errors" "io/ioutil" "log" "net/http" "github.com/aptpod/opentracing-sandbox/lib" "github.com/opentracing/opentracing-go" ) func main() { // Tracerの初期化 closer, err := lib.InitGlobalTracer("client") if err != nil { panic(err) } defer closer.Close() // Tracerの取得 tracer := opentracing.GlobalTracer() // Spanの開始 // このSpanを引き回す span := tracer.StartSpan("get_hoge") // Spanの終了 defer span.Finish() // Hogeの呼び出し! res, err := getHoge(span) if err != nil { panic(err) } log.Println(res) } このコード断片については難しいことはないと思います。「OpenTracingの実装の流れ」 でも述べた通り、 Tracer を初期化して... Tracer を取得して... Span を開始して... 処理(Hogeサービスの呼び出し)をして... Span を終了する。 という流れが読み取れると思います。 一点、 HTTPコールは単純にHTTPを呼び出せばよいというわけではありません。 サービス間の流れを追跡するOpenTracingですから、 Span の情報を引き継ぐ必要があります。 コード中でのHTTPコールの実装箇所は getHoge() 関数内にあたるので、 掘り下げて見ていきましょう。 // ./minclient/main.go ... omitted func getHoge(span opentracing.Span) (string, error) { // リクエストの生成 // 今回はHogeのPath url := "http://localhost:18080" req, err := http.NewRequest(http.MethodGet, url, nil) if err != nil { return "", err } // ※ Tracerを使ってSpanの情報をInject if err := span.Tracer().Inject( span.Context(), opentracing.HTTPHeaders, opentracing.HTTPHeadersCarrier(req.Header), ); err != nil { return "", err } // 通常のHTTPアクセス resp, err := Do(req) if err != nil { return "", err } return string(resp), nil } サービス間で情報を引き継ぐには、HTTPリクエストに何かしらの方法で Span の情報を埋め込む必要があります。 引き継ぐ Span の情報( 情報 だと少し語弊があるかもしれませんが。。。) を SpanContext と言います。 OpenTracingでは Tracer が SpanContext をリクエストに埋め込む責務を追います。送信側でリクエストに SpanContext を入れることを Inject 、逆に受信側で SpanContext を取り出すことを Extract と言います。 また、 Inject して、 SpanContext を運ぶものを Career と言います。 今回はHTTPヘッダを Career として、 SpanContext を Inject しています。 さて、この Career ですが、HTTP以外のRPCコール時ももちろん考慮されていて、HTTPヘッダ以外にも種類があります。 気になる方はOpenTracingの実装を読んでみましょう。 // SpanContext伝播のイメージ +----------+ | service1 | `Inject` `SpanContext` to `Career` +---+------+ | | Carry using `Career` | v +----------+ | service2 | `Extract` `SpanContext` from `Career` +---+------+ さて、 Inject をしたら、あとは通常通りにHTTPコールすればOKです。 コード中では resp, err := Do(req) の部分ですが、この部分はそのままHTTPコールしているだけなので割愛します。 hogeサービスを実装する 今度は受信側の実装です。 package main import ( "log" "net/http" "time" "github.com/aptpod/opentracing-sandbox/lib" "github.com/opentracing/opentracing-go" "github.com/opentracing/opentracing-go/ext" ) func main() { // tracer の初期化 tracer, closer, err := lib.CreateTracer("hoge-service") if err != nil { panic(err) } defer closer.Close() log.Println("start hoge") http.ListenAndServe(":18080", http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { log.Println("hoge") // SpanのExtract spanCtx, _ := tracer.Extract(opentracing.HTTPHeaders, opentracing.HTTPHeadersCarrier(r.Header)) // リクエストからのSpanContextを引き継いで新しいSpanの開始 span := tracer.StartSpan("get_hoge", ext.RPCServerOption(spanCtx)) defer span.Finish() // ダミー処理 <-time.After(time.Second) w.WriteHeader(http.StatusOK) w.Write([]byte(`{ "name": "hoge!" }`)) })) } まずはTracerの初期化部分です。 サービス側の実装は GlobalTracer へセットするのではなく、新たに Tracer を生成してみます。 GlobalTracer でも良いのですが、サンプルなので。。。 1アプリケーションで複数の Tracer が必要な場合はそれぞれで生成するとよいでしょう。 次はリクエストハンドラ( http.HandlerFunc )の実装です。 リクエストハンドラ内で、まず伝播された SpanContext を Extract します。 そして、その SpanContext を利用して、新しく Span を開始しています。 ext.RPCServerOption(spanCtx) は SpanContext から適切な StartSpanOption を返す関数です。 そういうものだと思って指定します。 内容が気になる方は全然難しくない実装なのでぜひ追って見てください。 さて、ここまででミニマムコードができました。 動作確認 準備 Dockerで jaeger を起動しておきます。下記に示すコマンドで、UIも含めアプリケーションが起動します。 docker run --rm -p 6831:6831/udp -p 6832:6832/udp -p 16686:16686 jaegertracing/all-in-one:1.7 --log-level=debug ブラウザでUIを開いておきます。アドレスは http://localhost:16686/search です。 実行 hogeサービスを起動します。 go run ./minserver/*.go クライアントを実行します。 go run ./minclient/*.go ブラウザを確認すると、Spanなどが確認できるかと思います。 jaegerのUI めでたく、トレースできました。。。。。 しかしながら、 Span の情報が少なかったり、実装も少し冗長だったり、まだまだ実アプリケーションへの導入は難しそうです。 以降のセクションで少しずつ洗練していきましょう。 その他の実装リファレンス Tags/Logs/Baggage Span には Tag 、 Log 、 Baggage という付加情報をつけることができます。詳細は Tags, logs and baggage を参照してください。 このセクションではそれぞれの情報をどうやって付与するか、コード断片を紹介します。 SpanにTagをつける Span にはkey-value形式で任意の Tag をつけることが可能です。 tagValue := ... span.SetTag("tag.key", tagValue) また、 github.com/opentracing/opentracing-go/ext に Tag の変数があるので、適宜利用すると良いでしょう。 // Tagをつける例 ext.SpanKindRPCClient.Set(span) ext.SpanKindRPCServer.Set(span) ext.HTTPUrl.Set(span, "http://localhost:8080") ext.HTTPMethod.Set(span, http.MethodGet) ext.HTTPStatusCode.Set(span, http.StatusOK) SpanにLogを記録する github.com/opentracing/opentracing-go/log を使い、 Span 内で Log をつけます。 // Key-Value形式で簡易指定 span.LogKV( "hoge.log.key1", "hoge-log", "hoge.log.key2", "hoge-log2", ) // 型情報ありの指定 span.LogFields( tracelog.String("hoge.logfields.string", "hoge-log"), tracelog.Bool("hoge.logfields.bool", true), ) Log はこの関数を呼び出したタイミングで、 Span に印をつけるイメージです。 Baggageを使って情報を任意の情報を伝播する OpenTracingには(APIのI/Fを変更せずに)任意のオブジェクトを伝播する手段があります。 運ぶ情報を Baggage と呼びます。 強力な機能ですが、使い方には注意しましょう。 送信(client)側 baggage := ... span.SetBaggageItem("baggage", baggage) 受信(server)側 spanCtx, _ := tracer.Extract(opentracing.HTTPHeaders, opentracing.HTTPHeadersCarrier(r.Header)) span := tracer.StartSpan("format", ext.RPCServerOption(spanCtx)) defer span.Finish() // Baggageの取得 baggage := span.BaggageItem("baggage") context.Contextを利用する アプリケーションをモジュール化して実装すると Span オブジェクトを引き回すのが辛いケースがあると思います。 そこで、OpenTracingのライブラリには context.Context 内に Span を含めるユーティリティが用意されています。 利用できるのであれば、コードがシンプルになるので context.Context 使う方が良いと思います。 Contextに Span をセット span := ... ctx := ... ctx = opentracing.ContextWithSpan(ctx, span) Contextから Span を取得 ctx := ... span := opentracing.SpanFromContext(ctx) Contextにある Span を親として、新しく Span を開始 ctx := ... // もし、ctxにSpanがない場合はGlobalTracerからSpanを開始する span := opentracing.StartSpanFromContext(ctx, "new-operation-name") サンプルアプリケーションを実装する これまでは、ミニマムな実装とコード断片で解説してきました。 前提となるコード知識はついてきたので、サービスの依存関係がすこしだけ複雑なアプリケーションのソースコードも見ていきます。 ソースコードを細かく解説すると長くなるので、解説はミニマムアプリケーションとの差分だけにします。 実装アプリケーションについて まずはアプリケーションの全体像です。 矢印の番号は呼び出し順序を表しています。 +--------+ | client | +---+----+ 1| ^ | | client | | side | +--------+------------------------------------------------- | server | | side | v | v +--------------+ 3 +--------------+ | hoge-service |---->| fuga-service | +---+----------+ +---+------+---+ 2| 4| 5| | | +---------+ | | | v v v +--------------+ +-------------+ +-------------+ | foo-service | | bar-service | | baz-service | +--------------+ +-------------+ +-------------+ この呼出関係をjaegerで見ることができればOKです。 サービスの実装 各サービスのHttpハンドラに Tag を付けていきます。 Tag については説明したとおりです。 http.HandlerFunc 実装のみの抜粋です。 // ./server/baz.go http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { log.Println("baz") // SpanのExtract spanCtx, _ := tracer.Extract(opentracing.HTTPHeaders, opentracing.HTTPHeadersCarrier(r.Header)) // リクエストからのSpanContextを引き継いで新しいSpanの開始 span := tracer.StartSpan("get_baz", ext.RPCServerOption(spanCtx)) defer span.Finish() // タグ付け ext.HTTPMethod.Set(span, r.Method) ext.HTTPUrl.Set(span, r.URL.String()) <-time.After(time.Second) w.WriteHeader(http.StatusOK) w.Write([]byte(`{ "name" : "baz!" }`)) // タグ付け ext.HTTPStatusCode.Set(span, http.StatusOK) }) ポイントは // タグ付け ext.HTTPMethod.Set(span, r.Method) ext.HTTPUrl.Set(span, r.URL.String()) ... omitted // タグ付け ext.HTTPStatusCode.Set(span, http.StatusOK) です。全ハンドラにこのコードを実装しておけば、 UIから見たときにフィルタしやすくなります。 サービス間のAPIコールの実装 クライアントの実装と同じことをすれば良いのですが、 今回の実装は Span を context.Context に入れて伝播します。 まずは、 context.Context にセットするコードです。 // ./server/hoge.go ... omitted // リクエストからのSpanContextを引き継いで新しいSpanの開始 span := tracer.StartSpan("get_hoge", ext.RPCServerOption(spanCtx)) defer span.Finish() ... omitted // ctxにセット ctx := r.Context() ctx = opentracing.ContextWithSpan(ctx, span) // APIコール _, _ = cli.Call(ctx, "foo") _, _ = cli.Call(ctx, "fuga") あまり難しくはないですね。 次はAPIコール部分の cli.Call の実装です。 context.Context から Span を開始する点がポイントです。 // ./server/client.go type ServiceClient struct { tracer opentracing.Tracer } func (s *ServiceClient) Call(ctx context.Context, serviceName string) (int, map[string]interface{}) { // ctxにセットされているSpanから新しく子のSpanを開始する span, _ := opentracing.StartSpanFromContextWithTracer(ctx, s.tracer, fmt.Sprintf("call_%s_%s", http.MethodGet, serviceName)) defer span.Finish() serviceURL, _ := url.Parse(fmt.Sprintf("http://localhost:%d", portMapping[serviceName])) req, _ := http.NewRequest(http.MethodGet, serviceURL.String(), nil) // Tag付け ext.SpanKindRPCClient.Set(span) ext.HTTPUrl.Set(span, serviceURL.String()) ext.HTTPMethod.Set(span, "GET") // Tracerを使ってSpanの情報をInject _ = span.Tracer().Inject( span.Context(), opentracing.HTTPHeaders, opentracing.HTTPHeadersCarrier(req.Header), ) resp, _ := http.DefaultClient.Do(req) defer resp.Body.Close() var responseJson map[string]interface{} json.NewDecoder(resp.Body).Decode(&responseJson) return resp.StatusCode, responseJson } context.Context から Span を開始するのはこの部分です。 // ctxにセットされているSpanから新しく子のSpanを開始する span, _ := opentracing.StartSpanFromContextWithTracer(ctx, s.tracer, fmt.Sprintf("call_%s_%s", http.MethodGet, serviceName)) defer span.Finish() 簡単ですね。 さて、これで準備はできました。 動作確認 Jaegerを起動した状態で サービス群を起動します。 go run ./server/*.go クライアントを実行します。 go run ./client/*.go そして、 localhost:16686 にアクセスしてみましょう。あえて、スクショははりません。ぜひ動かしてみてください! サービス間の呼び出しがこんな感じで見ることができたらシステムの運用ちょっと楽になりそうですよね。 実装をもっと楽したい サーバー側、クライアント側のコードを見ていただくと分かると思いますが、 まだ少し冗長です。 Tag をつける部分とか。。。 go-stdlib のライブラリを使うと、 もう少し処理を共通化することができます。 リポジトリを覗いてみると、サーバー側はミドルウェアの実装、クライアント側はトランスポートの実装があるので、 適宜利用すると良いでしょう。 但し、まだ実験段階のようなので、使うときには注意しましょう。 最後に 少し長い記事となってしまいました。 OpenTracing x Go の理解の一助となれば幸いです。 ここまでくれば、もっと実践的なアプリケーションサンプル Hot R.O.D. - Rides on Demand も読み解きやすいと思います。 また、導入する際は Best Practices もあるので、 このページも必読です。 話は変わりますが、弊社では サーバーサイドエンジニアを随時募集中です! 私達の取り組みに興味があればぜひ気軽に遊びに来てください。 以上、アドベントカレンダー8日目担当の miyauchi でした! 明日は弊社のエンベデッドチームの要、 ochiai さんです! 参考リンク集 記事中のコード -> https://github.com/aptpod/opentracing-go-sandbox OpenTracing オフィシャルサイト -> https://opentracing.io/ OpenTracing ユーティリティライブラリ(実験段階) -> https://github.com/opentracing-contrib/go-stdlib jaeger オフィシャルサイト -> https://www.jaegertracing.io/ jaeger Github -> https://github.com/jaegertracing/jaeger jaeger client Github -> https://github.com/jaegertracing/jaeger-client-go