🔍

OpenTelemetry Go Deep Dive

2023/12/08に公開

はじめに

この記事はGo 言語 Advent Calendar 2023及びOpenTelemetry Advent Calendar 2023 8 日目の記事です。

今まで OpenTelemetry に関する記事をいくつか書いてきました(App Runner にデプロイしたアプリからトレースを X-Ray や Jaeger で可視化する記事コンテナでデプロイした Lambda から X-Ray に OpenTelemetry でトレースを送る記事など)。今までの記事はどちらかというとインフラ観点のものが多く、アプリのサイドカーで OpenTelemetry Collector を動かしてマネージドサービスや OSS のツールにトレースを送る設定だったり、コンテナで動かして docker compose でローカルでも動かせるようにするだったりにフォーカスした内容が多かったです。一方でアプリの計装部分はドキュメントの Getting Started をコピペして少し改造して使う程度で全体の計装の流れやそれぞれの関数の処理の内容を深く理解していませんでした。これではいけないと思ったので OpenTelemetry-Go のリポジトリを見ながら処理の流れを追ってみました。

作ったアプリ

リポジトリはこちらです。HTTP リクエストを送る client, HTTP レスポンスを返す backend, client からのリクエストを backend にプロキシする api-gateway の三つのコンポーネントからなります。現実世界のシステムだと client <-> backend がやり取りするだけのものよりも、後段のマイクロサービスに色々リクエストを送って最終的にレスポンスを返すことが多いと考えて、複数のアプリケーションでトレースを伝播させるサンプルとなるようにしました。

OpenTelemetry におけるトレース

コンセプト

ドキュメントのリンクはこちらです。分散システムにおいて一連の処理の流れを記録し、マイクロサービスやサーバーレスアプリケーションのように複数のサービスが協調するアーキテクチャにおいてそれぞれのサービスが一連の処理の一部であることを伝播させ最終的に可視化します。

上の図で言うとクライアントが API Gateway にリクエストを送ってレスポンスが返ってくるまでが一連のトレース(青色の部分)です。このトレースの一部として API Gateway が後段のバックエンドにリクエストを送ってからレスポンスが返ってくるまで(赤色の部分)と、バックエンドがリクエストを処理するもの(黄色の部分)があります。

そしてこの青赤黄で可視化するのは Observability Backend(クライアント、API Gateway、バックエンドのバックエンドではなく SaaS やマネージドサービスや OSS で提供される Observability ツールのこと) で行います。クライアントや API Gateway などの個々のコンポーネントは OpenTelemetry Collector にテレメトリデータを送信し、Collector が Observability Backend にテレメトリデータを送信し、Observability Backend が可視化を行う、という棲み分けになっています。

今回の記事は OpenTelemetry SDK Deep Dive というタイトルなので一番最初の個々のコンポーネントが OpenTelemetry Collector にテレメトリを送信する部分を深掘りしていきます。

Span

個々のコンポーネントが送信するテレメトリは何でどのような形式なのかをまずみていきます。ドキュメントはこちらです。

一連の処理の流れがトレースなわけですがひとつひとつの処理の記録が Span です。これは Span Context や Attributes などいろいろな情報を含みますが、まずはトレースの全体感を掴むために上の図のように Span の一部の情報だけを取り出して見ていきます。

Span はトレースを構成する一要素であり複数の Span を紐づけて可視化することでトレースの分析が可能になります。アプリ側でひとつの処理を行うと Span が生成されて、この Span を共通の Trace ID で繋げることで一連のトレースとみなして紐づけることができます。つまりトレースを可視化して分析するのは Observability Backend でやることであって、アプリから見るとその構成要素の Span を処理を行うたびに生成しているわけです。構造が決まっているログを処理を行うたびに出力していると考えるとイメージしやすいです。ただログを出力するだけだとそのログがどの一連の流れの一部なのかわかりませんが、 Span Context のなかの Trace ID を見れば一連の流れ(Trace ID によって識別される)の一部であることが Observability Backend 側でわかります。Span には開始時刻と終了時刻、Attribute (Span に付与される key-value 形式の補足情報)などの情報も含まれるので Observability Backend 側で詳細に分析できます。

上の図だと Client から生成された Span では Span Context に trace_id (0x5b...) と span_id (0x05...)が含まれています。Span はネストすることができ、今回の例だと API Gateway での処理は Client から送られてきたリクエストの一部なので API Gateway から生成された Span の parent_id は Client から生成されたスパンの span_id である 0x05... になっています。一方で Client から送る Span の方は親側になるため parent_id は null です。

Context Propagation

Span のところで書いたように共通の Trace ID を持つ Span を生成することで同じ Trace ID を持つ Span と紐づけることができますし、parent_id に Span ID を指定することでネストを表現することができます。これらは Span の中の context に含まれているわけですが分散システムの場合はこの context を複数のコンポーネントに渡していかないといけません。例えば Client が HTTP リクエストを API Gateway に送る時に Client が Span を生成すれば何かしらの方法で生成された Span の context を API Gateway に渡す必要があります。そして API Gateway の方では受け取った context の情報をもとに Span を生成する(API Gateway で生成した Span の Trace ID は受け取った context.trace_id と同じものにし、parent_id は context.span_id と同じものにする)必要があります。

分散システムにおいてトレーシングを可能にするのがこの context を伝播させていくこと、つまり Context Propagation です。ドキュメントはここです。

まず Context の方は Span でも出てきたように Span 同士やトレースと関連づけるために必要な情報を含んだオブジェクトのことです。OpenTelemetry でのデフォルトのフォーマットは W3C TraceContextです。この場合
Traceparent ヘッダーに 00-5ee15c77c665af9cf3e1296e8bcac3be-951cf5b24854df69-01 といった形式で値がセットされます。こちらにあるように version, trace-id, parent-id(要は span-id ), trace-flags がそれぞれ - で区切られて格納されています。

次に Propagation の方は複数のアプリケーション間でやり取りされるメッセージから Context を挿入する・抽出することです。Propagators API を使って Context を取り出すことができます。Propagator は Inject/Extract メソッドを実装していて、Carrier に対して Context の挿入・抽出を行います。その名のとおり Carrier は Context を運ぶ入れ物で Propagator はこの入れ物に Context を入れたり取り出したりするものというイメージです。

import (
    "net/http"
    "go.opentelemetry.io/otel"
    "go.opentelemetry.io/otel/propagation"
)
otel.SetTextMapPropagator(propagation.TraceContext{})
propagator := otel.GetTextMapPropagator()
// Carrier から取り出した Context を context.Context に入れる
ctx := propagator.Extract(*http.Request.Context(), propagation.HeaderCarrier(*http.Request.Header))

HTTP リクエストを受ける側では http.Request.Context() で context.Context を取り出すことができます(つまり Context を抽出できる)。ただ context.Context を指定するところはともかく毎回 Carrier を指定するのは手間です。Propagators API のドキュメントにも書いているように多くの場合はライブラリが助けてくれます。

Propagation is usually implemented via a cooperation of library-specific request interceptors and Propagators, where the interceptors detect incoming and outgoing requests and use the Propagator’s extract and inject operations respectively.

propagator.Inject をラップ

例えば HTTP リクエストを送る場合( HTTP リクエストを送るときに Context を挿入する)は以下のように otelhttp.Get などが使えます。これを使うとユーザーが書くコードでは Carrier を指定しなくて良くなります。コードを読むと裏では &http.Client{Transport: NewTransport(http.DefaultTransport)}.Do(req) が呼ばれています。NewTransporthttp.DefaultTransport をラップしています。最終的に HTTP リクエストを送るときに RoundTrip が呼ばれ、この中で propagators.Inject が呼ばれています

import (
    "net/http"
    "context"
    "go.opentelemetry.io/otel"
    "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
)

tracer := otel.Tracer("api-gateway")
url := "http://localhost:8080/"

ctx, span := tracer.Start(context.Background(), "proxy request")
defer span.End()
// otelhttp でラップされた Get メソッドを実行する
resp, err := otelhttp.Get(ctx, url)

propagator.Extract をラップ

例えば HTTP リクエストを受けてそのリクエストから Context を取り出す場合( Context を抽出する)は otelhttp.NewHandler でハンドラー関数をラップすることが有用です。フレームワークによっては計装するミドルウェアがあるものもあります(例えば Echo の場合は otelecho があります)。otelhttp.NewHandler内部的には otelhttp.NewMiddleware を呼んでいて、最終的にmiddleware.serveHTTPを実行しています。この中で propagator.Extract を呼んでいて propagation.HeaderCarrier(*http.Request.Header) という Carrier が指定されています。ここで HTTP ヘッダーという Carrier から Context を取り出していてこの Context を HTTP リクエストに埋め込んでハンドラーが実行されます。そうするとハンドラーの中では *http.Requext.Context() で Context を取り出すと Carrier から取り出した Context を得ることができます。

import (
    "net/http"
    "io"
    "go.opentelemetry.io/otel"
    "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
)

func handler(w http.ResponseWriter, req *http.Request) {
    tracer := otel.Tracer("api-gateway")
    ctx, span := tracer.Start(req.Context(), "proxy request")
    defer span.End()
    // some operation using ctx and span
    response := "Response from backend"
    _, _ = io.WriteString(w, response)
}

func registerHandlers() {
    wrappedHandler := otelhttp.NewHandler(http.HandlerFunc(handler), "proxy request to backend")
    http.Handle("/", wrappedHandler)
}

アプリケーションコード

全体の流れ

最初に大まかな流れをまとめておきます。公式のガイドだとこちらが参考になります。

tp := TracerProvider(*go.opentelemetry.io/otel/sdk/trace.TracerProvider)を作成する
↓
go.opentelemetry.io/otel.SetTracerProvider(tp) で TracerProvider を登録する
↓
go.opentelemetry.io/otel.SetTextMapPropagator(TextMapPropagator interface) で Propagator を登録する
↓
計装する箇所で go.opentelemetry.io/otel.Tracer を作成する
↓
計装する箇所で ctx,span := Tracer.Start(ctx, "span name") で context と span を生成する
↓
span に attribute を追加したり、net/http.NewRequestWithContext() に ctx を渡して HTTP リクエストに trace id が付与されたヘッダーをつけるようにして計装する
↓
defer span.End() として span が終了するようにしておく
↓
span が span processor のキューに積まれ、span processor はキューに積まれた span を非同期で処理(exporter 経由でバックエンドに送る)していく 

ここで出てきた Tracer や Tracer Provider、Span Exporter を次に見ていきます。

Tracer

アプリにおいて Span はどのように生成されるのかというと Tracer によって生成されます。Span を生成するところでは以下のようなコードが出てきます。

ctx, span := tracer.Start(ctx, "span name")
defer span.End()

Tracer.Start() を実行すると Context の情報をもとに Context と Span を生成します。Tracer は Span 製造機のようなイメージです。

Tracer Provider

ドキュメントはこちらです。先ほど出てきた Tracer を返却するグローバルなリソースです。Tracer Provider を登録しておくと otel.Tracer() で Tracer を取得できます。Tracer Provider は NewTracerProvider で作成でき、引数に WithSampler (サンプリングの設定を指定)や WithBatcher (後述するように Span Exporter を引数にとって Span Processor として登録する)などの関数を取ります。

import (
    "go.opentelemetry.io/otel/exporters/otlp/otlptrace"
    "go.opentelemetry.io/otel/sdk/resource"
    sdktrace "go.opentelemetry.io/otel/sdk/trace"
)

tracerProvider := sdktrace.NewTracerProvider(
    sdktrace.WithSampler(sdktrace.AlwaysSample()),
    sdktrace.WithResource(*resource.Resource),
    sdktrace.WithBatcher(*otlptrace.Exporter),
)

Span Exporter

生成した Span は必ず終了する必要があります。Tracer の SDK ドキュメントにも書かれています。

Any Span that is created MUST also be ended. This is the responsibility of the user.

結論を先に言うと span.End() を実行すると最終的に Span はバックエンドに送信され、この送信者が Span Exporter です。例えば gRPC で OpenTelemetry Collector と通信する場合には otlptracegrpc.New で Span Exporter を作成すると、この Exporter を通して Span は Collector に送られます。

span.End() の処理の中で何が行われるかと思って実装を見ていくと、ざっくり言えばここで Span Processor をとってきて、ここでその OnEnd を呼んでいます。

sdktrace.WithBatcher() で Span Exporter を登録した場合で考えます。この場合 WithBatcher のコードにあるように BatchSpanProcessor が Tracer Provider に登録されます。span.End() が実行されると spanProcessor.OnEnd() が呼ばれるので BatchSpanProcessor の OnEnd を見てみるとここで内部的なキューに Span をエンキューするメソッドが呼ばれています。つまり span.End() を実行すると SpanProcessor のキューに Span が積まれる(そしてキューに積まれるということはその後おそらく非同期で処理される)わけです。

キューを処理する関数を読むとここで BatchSpanProcessor のキューに Span が積まれています。BatchSpanProcessor は作成された時に並行処理でキューの中身を処理していて(コードはこの辺り)、具体的にはここでキューの中身をどのように処理するか定義されています。ここで BatchSpanProcessor の exportSpans が呼ばれます。 この関数は BatchSpanProcessor に登録された Exporter のExportSpans 呼びますExporter は interface で ExportSpans を実装している必要があります

長々と書きましたが結論を言うと span.End() を実行すると Span Exporter が Span をバックエンドに送信します。

テスト

ここでは client から backend server に HTTP リクエストを送った時 Context Propagation がうまく動いたかをテストする場合を考えます。

client 側で tracer.Start() を使って Context を生成し、これの Trace ID と backend 側で HTTP ヘッダーから取り出した Context の Trace ID が一致するかテストすればいいです。前者はともかく後者をどのように実現するかが課題です( Context Propagation はライブラリ側で勝手にやってくれるケースが多いため。ライブラリを使わなければテストはしやすくなるかもしれませんが同じようなコードが増えそう)。

Go の場合 tracetest パッケージがありこの中の InMemoryExporter を使うとテストしやすいです。この Exporter はその名の通り Span をメモリに保存するため、GetSpans() で Span を取り出すことができます。

おわりに

コードを読むことで生成された Span がどのような流れで最終的に Observability Backend に送られるのかイメージがついてきました。今回調べたのは Go SDK ですが、 Rust だと Span 送信は Drop トレイトを使って実装されていそうなので今度は Rust のコードも調べてみようと思います。

Discussion