Zenn
⛳

Golang ✖️ GraphQL ✖️ OpenTelemetryで実現するアプリのトレース

2023/09/19に公開
Go
GraphQL
xray
OpenTelemetry
tech

はじめに

Golangで書いているGraphQLアプリをECSにデプロイしてトレースしてみました。今回はAWS X-Rayにトレース結果を送信しますが、Datadogなどに送信する場合でも似たような手順になると思うのでよかったら参考にして下さい。
GraphQLライブラリにはgqlgenを使用しています。
https://github.com/99designs/gqlgen

完成したリポジトリは以下のようになっているのでよかったら参照して下さい。
https://github.com/ryohei1216/graphql-trace

環境構築

まずはgqlgenのドキュメントに沿って環境構築を行います。初期のTodoアプリをリゾルバ分割した物を私のリポジトリにアップしていますので面倒な方はこちらをforkして使って下さい。
https://github.com/ryohei1216/graphql-trace/tree/base
今回はこの初期状態のままOpenTelemetryに関するコードをmiddlewareに実装していきます。

OpenTelemetryの実装

基本的にこちらのドキュメントに沿ってOpenTelemetryに関する実装を行なっていきます。

用語の解説

  • Tracer Provider
    Tracerを提供する。またトレース情報のExport先を管理したり、トレースに共通で付けたい属性データを管理する
  • Tracer
    Spanを生成する
  • Span
    各操作におけるトレース情報。
  • Trace Provider
    トレース情報の出力先。標準出力だったり、Jaegerのような分散トレース可視化ツールなど。今回はAWS X-Rayになる。
  • Trace Context
    Spanの関連付け（Child of, Follows from）をする上で伝播させる必要のあるデータ
  • OTLP Exporter
    OpenTelemetry Protocol Exporterの略。
  • OTEL Collector
    -データの収集、変換、ルーティング、および送信のための中央集約ポイントを提供するコンポーネント.

グローバルトレーサーの実装

まずはドキュメント通り、必要なライブラリをインストールします。

go get go.opentelemetry.io/otel
go get go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc
go get go.opentelemetry.io/otel/sdk/resource
go get go.opentelemetry.io/otel/sdk/trace
go get go.opentelemetry.io/otel/sdk/metric
go get go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetricgrpc

ドキュメントにSetting up the Global Tracerと書かれているように、トレーサーはグローバル変数として宣言して良いみたいです。基本的に各アプリにつきトレーサーは１つしか使用しないためなのかなと考えています。
graphディレクトリ配下にopentelemetry.goを作成して以下のようにします。

graph/opentelemetry.go
package graph

import (
	"context"

	"go.opentelemetry.io/contrib/detectors/aws/ecs"
	"go.opentelemetry.io/contrib/propagators/aws/xray"
	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc"
	"go.opentelemetry.io/otel/sdk/resource"
	sdkTrace "go.opentelemetry.io/otel/sdk/trace"
)

var Tracer = otel.Tracer("github.com/ryohei1216/graphql-trace")

func New(ctx context.Context) (func(context.Context) error, error) {
	// OTLP Exporterを作成する
	traceExporter, err := otlptracegrpc.New(ctx, otlptracegrpc.WithInsecure())
	if err != nil {
		return nil, err
	}

	// ECSのデータを検出する
	ecsResourceDetector := ecs.NewResourceDetector()

	resource, err := resource.New(
		ctx,
		resource.WithDetectors(ecsResourceDetector),
	)
	if err != nil {
		return nil, err
	}

	tp := sdkTrace.NewTracerProvider(
		sdkTrace.WithSampler(sdkTrace.AlwaysSample()),
		sdkTrace.WithBatcher(traceExporter),
		sdkTrace.WithIDGenerator(xray.NewIDGenerator()),
		sdkTrace.WithResource(resource),
	)

	otel.SetTracerProvider(tp)
	otel.SetTextMapPropagator(xray.Propagator{})

	return func(context.Context) error {
		err = tp.Shutdown(ctx)
		if err != nil {
			return err
		}
		return nil
	}, nil
}

トレーサーをグローバルに宣言する

ドキュメント通り、トレーサーはグローバルに宣言しています。

var Tracer = otel.Tracer("github.com/ryohei1216/gqlgen-resolver")

ここで、トレーサーを作成する際の名前ですがアプリ内で一意になるためライブラリ名が推奨されています。

// The passed name needs to uniquely identify instrumentation code.
// Therefore, it is recommended that name is the Go package name of the
// library providing instrumentation

OTLP Exporterを作成する

	// OTLP Exporterを作成する
	traceExporter, err := otlptracegrpc.New(ctx, otlptracegrpc.WithInsecure())
	if err != nil {
		return nil, err
	}

ここでは、OTLP Exporterを作成しています。OTLP Exporterは、トレースした情報をCollectorへ送信するために必要となります。CollectorとはExporterによって送信されたトレース情報を受け取り、データの収集、変換、ルーティング、および送信のための中央集約ポイントを提供するコンポーネントです。簡単に言うと、X-RayやDatadogなどのサービスにトレース情報が送信される前にCollectorを通過することでデータがフォーマットされ、各サービスに最適化されたトレース情報を送信してくれるようになります。
ここではオプションでWithInsecure()のみを渡していますが、AWSのサイドカーにCollectorをデフォルト設定で用意するときはこれだけで動くはずです。もし他のオプションが気になる方はご自身で必要なオプションを設定して下さい。
https://pkg.go.dev/go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc@v1.18.0

(Collectorを通過しなくてもトレース情報を各サービスに直接送信できることもありますが、多くの場合はCollectorを通過させることが推奨されているようです。https://opentelemetry.io/docs/collector/#when-to-use-a-collector)

ECSのデータを検出する

こちらのドキュメントに従ってECSのデータを検出し、トレース情報のメタデータに追加します。

	// ECSのデータを検出する
	ecsResourceDetector := ecs.NewResourceDetector()

	resource, err := resource.New(
		ctx,
		resource.WithDetectors(ecsResourceDetector),
	)
	if err != nil {
		return nil, err
	}

ドキュメントと少し書き方が異なりますが、こちらの書き方の方が今後他の情報をメタデータに追加したい時など拡張しやすいです。他の情報はオプションで環境変数やホストなどを選択できるのでプロジェクトに必要なメタデータを任意に追加して下さい。
https://pkg.go.dev/go.opentelemetry.io/otel/sdk@v1.18.0/resource

Tracer Providerの作成

	tp := sdkTrace.NewTracerProvider(
		sdkTrace.WithSampler(sdkTrace.AlwaysSample()),
		sdkTrace.WithBatcher(traceExporter),
		sdkTrace.WithIDGenerator(xray.NewIDGenerator()),
		sdkTrace.WithResource(resource),
	)

ドキュメントの続きに従ってTracer Providerを作成します。Tracer Providerは、その名の通りトレーサーを提供します。先ほどグローバルに宣言されていたトレーサーもこのTracer Providerによって提供されています。WithSampler()によってアプリの処理をトレースする割合を決めることができます。WithBatcher()では先ほど作成したtraceExporterを設定します。WithResource()にも先ほど設定したresourceを設定します。WithIDGenerator()ではトレース情報を一意に定めるためのIDを生成する方法を設定します。今回はAWS X-Rayのフォーマットに合わせてトレーサーIDを作成したいのでxray.NewIDGenerator()を使用しています。

トレーサーをグローバルに設定する

	otel.SetTracerProvider(tp)
	otel.SetTextMapPropagator(xray.Propagator{})

OpenTelemetryの最後の設定です。これまでの過程で作成したTracer Providerをグローバルに設定します。トレーサーを取得する時には、ここで設定されたTracer Providerから生成されたトレーサーを取得することになります。otel.Tracer()でどこからでも設定されたトレーサーにアクセスできます。
また、propagationの設定も行います。propagationとは、分散トレーシングやコンテキスト伝播の概念です。
https://opentelemetry.io/docs/concepts/signals/traces/#context-propagation
こちらを設定することで分散トレーシングが可能になります。
今回は、xray.Propagatorを設定しています。
xray.Propagatorは
X-Amzn-Trace-Id: Root={traceId};Parent={parentId};Sampled={samplingFlag}
の形式でheaderにトレースIDを付与してくれます。

終了する前にShutdown()でTracerProviderをリソースリークしないように終了させます。

これでトレーサーの設定は完了です。
もし、より詳細にトレーサーの設定を行いたい場合はこちらの方の記事がとても詳しく書かれているので参考にして下さい。
https://zenn.dev/vaxila_labs/articles/a91f3a2af2f365

次はこのトレーサーを使ってGraphQLのmiddlewareを実装していきます。

middlewareの実装

OpenTelemetryに関する実装はgqlgenのmiddlewareに実装していきます。
gqlgenのmiddlewareについてはこちらの記事がとても分かりやすかったです。
https://zenn.dev/hsaki/books/golang-graphql/viewer/middleware

特に理由がなければ、リクエストの開始からレスポンスまでの処理をトレースしたいと考えるかと思います。上記の記事によるとResponseMiddlewareはリクエストを受けて前処理を行い、後処理(deferでの処理など)はレスポンスを返す最後の処理で実行されるようです。これはアプリの開始から終了までをトレースするには都合の良い挙動になっています。また、FieldMiddlewareでは分割したリゾルバやフィールドの処理に関するミドルウェアになっているようです。FieldMiddlewareを利用することでリゾルバ分割した処理もトレースできるようになります。後で説明しますが、トレースデータには親子関係を持たせることができます。

上図の一番上の長い帯が親トレースで、その下にたくさんある短い帯が子トレースです。この帯が用語の説明で紹介したSpanになります。
例えば、GraphQLではメインのリゾルバの処理が親トレースになって、フィールドごとの処理が子トレースになって表示されるとGraphQLアプリとしては見やすいトレースになるかと思います。今回もそこを目指していきます。

graohディレクトリ配下にmiddleware.goを以下のように実装します。

graph/middleware.go
package graph

import (
	"context"
	"fmt"
	"strings"

	"github.com/99designs/gqlgen/graphql"
	"github.com/vektah/gqlparser/v2/gqlerror"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/codes"
	"go.opentelemetry.io/otel/trace"
)

type gqlError struct {
	errList gqlerror.List
}

func (e *gqlError) Error() string {
	return e.errList.Error()
}

func newGqlError(errList gqlerror.List) error {
	return &gqlError{
		errList: errList,
	}
}

type graphqlTracer struct {
	tracer trace.Tracer
}

var _ interface {
	graphql.HandlerExtension
	graphql.ResponseInterceptor
	graphql.FieldInterceptor
} = &graphqlTracer{}

func NewGraphQLTracer(tracer trace.Tracer) graphql.HandlerExtension {
	return &graphqlTracer{
		tracer: tracer,
	}
}

func (t graphqlTracer) ExtensionName() string {
	return "GraphQLTracer"
}

func (t graphqlTracer) Validate(_ graphql.ExecutableSchema) error {
	return nil
}

func (t graphqlTracer) InterceptResponse(ctx context.Context, next graphql.ResponseHandler) *graphql.Response {
	oc := graphql.GetOperationContext(ctx)
	if oc.Operation.Name == "IntrospectionQuery" {
		return next(ctx)
	}

	query := strings.Split(oc.RawQuery, " ")[0]

	ctx, span := t.tracer.Start(ctx, query+":"+oc.OperationName, trace.WithSpanKind(trace.SpanKindServer))
	defer span.End()

	if !span.IsRecording() {
		return next(ctx)
	}

	res := next(ctx)

	if len(res.Errors) > 0 {
		span.SetStatus(codes.Error, res.Errors.Error())
		span.RecordError(newGqlError(res.Errors))
		span.SetAttributes(attribute.Key("error.message").String(res.Errors.Error()))

	}
	return res
}

func (t graphqlTracer) InterceptField(ctx context.Context, next graphql.Resolver) (interface{}, error) {
	oc := graphql.GetOperationContext(ctx)
	if oc.Operation.Name == "IntrospectionQuery" {
		return next(ctx)
	}

	fc := graphql.GetFieldContext(ctx)

	ctx, span := t.tracer.Start(ctx, fc.Field.ObjectDefinition.Name+"/"+fc.Field.Name, trace.WithSpanKind(trace.SpanKindServer))
	defer span.End()

	if !span.IsRecording() {
		return next(ctx)
	}

	span.SetAttributes(
		attribute.Key("resolver.path").String(fc.Path().String()),
		attribute.Key("resolver.object").String(fc.Field.ObjectDefinition.Name),
		attribute.Key("resolver.field").String(fc.Field.Name),
		attribute.Key("resolver.alias").String(fc.Field.Alias),
	)

	argKV := []attribute.KeyValue{}
	for _, arg := range fc.Field.Arguments {
		if arg.Value != nil {
			argKV = append(argKV, attribute.Key(fmt.Sprintf("resolver.args.%s", arg.Name)).String(arg.Value.String()))
		}
	}

	if len(argKV) > 0 {
		span.SetAttributes(argKV...)
	}

	res, err := next(ctx)

	if err != nil {
		span.SetStatus(codes.Error, err.Error())
		span.RecordError(err)
		span.SetAttributes(attribute.Key("error.message").String(err.Error()))
	}

	errList := graphql.GetFieldErrors(ctx, fc)
	if len(errList) != 0 {
		span.SetStatus(codes.Error, errList.Error())
		span.RecordError(newGqlError(errList))
		span.SetAttributes(attribute.Key("error.message").String(errList.Error()))
	}

	return res, err
}

ResponseMiddleware

先ほど説明したResponseMiddlewareに関する処理が以下のようになっています。

func (t graphqlTracer) InterceptResponse(ctx context.Context, next graphql.ResponseHandler) *graphql.Response {
	oc := graphql.GetOperationContext(ctx)
	if oc.Operation.Name == "IntrospectionQuery" {
		return next(ctx)
	}

	query := strings.Split(oc.RawQuery, " ")[0]

	ctx, span := t.tracer.Start(ctx, query+":"+oc.OperationName, trace.WithSpanKind(trace.SpanKindServer))
	defer span.End()

	if !span.IsRecording() {
		return next(ctx)
	}

	res := next(ctx)

	if len(res.Errors) > 0 {
		span.SetStatus(codes.Error, res.Errors.Error())
		span.RecordError(newGqlError(res.Errors))
		span.SetAttributes(attribute.Key("error.message").String(res.Errors.Error()))
	}
	return res
}

処理の初めにtracer.Start()してSpanを生成し、終わりにspan.End()します。

	if len(res.Errors) > 0 {
		span.SetStatus(codes.Error, res.Errors.Error())
		span.RecordError(newGqlError(res.Errors))
		span.SetAttributes(attribute.Key("error.message").String(res.Errors.Error()))
	}

こちらではリゾルバの処理でエラーが発生した際のトレース情報を設定しています。span.SetStatusでエラーメッセージとともにstatusをエラーに設定しています。また、span.RecordErrorでエラーを記録するようにしています。ここで気を付けてほしいのは、span.RecordErrorをしてもステータスはエラーにならないということです。span.RecordErrorを設定してもspan.SetStatusでエラーを設定しないとステータスはエラーにならないのでご注意ください。

FieldMiddleware

FieldMiddlewareに関する処理は以下のようになっています。

func (t graphqlTracer) InterceptField(ctx context.Context, next graphql.Resolver) (interface{}, error) {
	oc := graphql.GetOperationContext(ctx)
	if oc.Operation.Name == "IntrospectionQuery" {
		return next(ctx)
	}

	fc := graphql.GetFieldContext(ctx)

	ctx, span := t.tracer.Start(ctx, fc.Field.ObjectDefinition.Name+"/"+fc.Field.Name, trace.WithSpanKind(trace.SpanKindServer))
	defer span.End()

	if !span.IsRecording() {
		return next(ctx)
	}

	span.SetAttributes(
		attribute.Key("resolver.path").String(fc.Path().String()),
		attribute.Key("resolver.object").String(fc.Field.ObjectDefinition.Name),
		attribute.Key("resolver.field").String(fc.Field.Name),
		attribute.Key("resolver.alias").String(fc.Field.Alias),
	)

	argKV := []attribute.KeyValue{}
	for _, arg := range fc.Field.Arguments {
		if arg.Value != nil {
			argKV = append(argKV, attribute.Key(fmt.Sprintf("resolver.args.%s", arg.Name)).String(arg.Value.String()))
		}
	}

	if len(argKV) > 0 {
		span.SetAttributes(argKV...)
	}

	res, err := next(ctx)

	if err != nil {
		span.SetStatus(codes.Error, err.Error())
		span.RecordError(err)
		span.SetAttributes(attribute.Key("error.message").String(err.Error()))
	}

	errList := graphql.GetFieldErrors(ctx, fc)
	if len(errList) != 0 {
		span.SetStatus(codes.Error, errList.Error())
		span.RecordError(newGqlError(errList))
		span.SetAttributes(attribute.Key("error.message").String(errList.Error()))
	}

	return res, err
}

ResponseMiddlewareとやっていることはあまり変わりません。ですが挙動が異なるのでご紹介した記事で各ミドルウェアのアクションや処理の順番についてはしっかり理解しておいて下さい。
ResponseMiddlewaerと異なるのは、ここで引数から渡されるコンテキストはResponseMiddlewareから伝搬されたものになることです。つまり、ここで生成したSpanは子Spanになり、ResponseMiddlewareで生成されたSpanは親Spanになります。

最後にserver.goを以下のように書き換えます。

server.go
package main

import (
	"context"
	"log"
	"net/http"
	"os"

	"github.com/99designs/gqlgen/graphql/handler"
	"github.com/99designs/gqlgen/graphql/playground"
	"github.com/ryohei1216/graphql-trace/graph"
)

const defaultPort = "80"

func main() {
	port := os.Getenv("PORT")
	if port == "" {
		port = defaultPort
	}

	ctx := context.Background()
	shutdown, err := graph.New(ctx)
	if err != nil {
		log.Fatal(err)
	}
	defer shutdown(ctx)

	srv := handler.NewDefaultServer(graph.NewExecutableSchema(graph.Config{Resolvers: &graph.Resolver{}}))

	srv.Use(graph.NewGraphQLTracer(graph.Tracer))

	http.Handle("/", playground.Handler("GraphQL playground", "/query"))
	http.Handle("/query", srv)

	log.Printf("connect to http://localhost:%s/ for GraphQL playground", port)
	log.Fatal(http.ListenAndServe(":"+port, nil))
}

以上で、メインのリゾルバを親Span、フィールドごとの処理を子Spanとしてトレースができるようになりました。

実際にトレースしてみる

実際にmutationでcreateTodoを実行してからqueryでtodosを実行してみると以下のような結果が得られました。ちゃんとメインのリゾルバで親Spanを生成して、フィールドごとに子Spanが生成されています。

まとめ

以上、GraphQLとOpenTelemetryでアプリのトレースを行ってみました。アプリの監視はプロジェクトをスケールさせる上で重要となってくるのでよければ参考にして下さい。

完成したリポジトリは以下のようになっているのでよかったら参照して下さい。
https://github.com/ryohei1216/graphql-trace

Discussion