Zenn
🔍

【OpenTelemetry】トレーサビリティを高めるLoggerを考えてみた【Go, Slog】

2023/12/08に公開
Go
OpenTelemetry
tech

はじめに

最近携わらせて頂いている開発案件では、Goを使用してMicroserviceを開発しているのですが、ログからエラー内容を把握するのが困難という課題がありました。
これを解決するために、OpenTelemetryを活用してトレーサビリティを高めるLoggerを設計しました。本記事では、OpenTelemetryの計装例とLoggerの実装例を汎用的な形にしてご紹介します。

前提

この記事ではOpenTelemetryそのものの説明は割愛します。以下のトピックは理解しているものとして進めます。

環境

本記事では、以下の環境を前提としています。

  • 言語: Go 1.21
  • Cloud: GCP(GKE, Cloud Logging等)
  • 通信: gRPC Gateway

課題と解決策

ログからエラー箇所を特定する上での主な課題は以下の2点でした。

  1. 単一Microserviceのログをリクエスト単位で抽出できない
  2. 複数のMicroservice間でログをリクエスト単位で抽出できない

これらの課題に対処するため、OpenTelemetryの利用を決定しました。

  • MicroserviceごとにリクエストごとにSpanIDを発行し、ログに表示することで、リクエスト単位のログ抽出を可能にする → ①への解決策
  • Microserviceの最上流でリクエストごとにTraceIDを発行し、ログに表示することで、下流のMicroserviceに伝播させ、リクエスト単位のログ抽出を可能にする → ②への解決策

さらに、Baggageを活用して特定のオブジェクトIDをセットし、特定のユースケースのログの絞り込みを容易にしました。

OpenTelemetryの計装例

ここでは、OpenTelemetryの具体的な計装例をご紹介します。

説明の前に

計装をするにあたり、OpenTelemetryのDemoのドキュメントとリポジトリが非常に参考になるため、一度目を通しておくことを推奨します。

Trace Providerのセット

Trace Providerの設定は、mainゴルーチン内で行います。複数のスレッドから同時に呼び出されないように気をつけてください。

import (
	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/propagation"
	"go.opentelemetry.io/otel/sdk/trace"
)

tp := trace.NewTracerProvider(
  trace.WithSampler(trace.AlwaysSample()),
)
otel.SetTracerProvider(tp)
otel.SetTextMapPropagator(propagation.NewCompositeTextMapPropagator(propagation.TraceContext{}, propagation.Baggage{}))

自動計装の実装例(gRPC Server, gRPC Client)

gRPC Serverの実装例

gRPC Server側の計装例は次のようになります。

var srv = grpc.NewServer(
    grpc.StatsHandler(otelgrpc.NewServerHandler()),
)

gRPC Clientの実装例

gRPC Client側では、grpc.DialContext()を使用してcontextを渡します。これは、上位レイヤーからcontextを引き回す必要があります。

func createClient(ctx context.Context, svcAddr string) (*grpc.ClientConn, error) {
    return grpc.DialContext(ctx, svcAddr,
        grpc.WithTransportCredentials(insecure.NewCredentials()),
        grpc.WithStatsHandler(otelgrpc.NewClientHandler()),
    )
}

注意点： 執筆時点での最新版otelgrpc(v0.46.1)では、Interceptorの関数が非推奨になっています。以下に非推奨の例を示します。

// 非推奨の例
var srv = grpc.NewServer(
  grpc.UnaryInterceptor(otelgrpc.UnaryServerInterceptor()),
  grpc.StreamInterceptor(otelgrpc.StreamServerInterceptor()),
)

// 非推奨の例
func createClient(ctx context.Context, svcAddr string) (*grpc.ClientConn, error) {
	return grpc.DialContext(ctx, svcAddr,
		grpc.WithTransportCredentials(insecure.NewCredentials()),
		grpc.WithUnaryInterceptor(otelgrpc.UnaryClientInterceptor()),
		grpc.WithStreamInterceptor(otelgrpc.StreamClientInterceptor()),
	)
}

Blog記事等での実装例ではInterceptorが一般的ですが、公式ドキュメントに記載されているメソッドを使用することを推奨します。また、私は先述のDemoサイトでInterceptorが使用されていたため、PRを作成し修正を行いました。

Baggageの使用例

Baggageを使用すると、Context Propagationを利用して特定のSpanで得られた情報を他のサービスへ伝播できます。

以下はBaggageへの値の追加の実装例です。Baggageからの値の取り出しはLoggerの実装例で合わせて紹介します。

import (
	"context"
  "log/slog"
  grpc_auth "github.com/grpc-ecosystem/go-grpc-middleware/auth"
	"go.opentelemetry.io/otel/baggage"
)

func SetBaggage(ctx context.Context, key, value string) (context.Context, error) {
	bg := baggage.FromContext(ctx)
	member, err := baggage.NewMember(key, value)
	if err != nil {
		return ctx, err
	}
	bg, err = bg.SetMember(member)
	if err != nil {
		return ctx, err
	}
	return baggage.ContextWithBaggage(ctx, bg), nil
}

func TraceInterceptor(ctx context.Context) (context.Context, error) {
    key, err := grpc_auth.AuthFromMD(ctx, "bearer")
    if err != nil {
        return nil, err
    }
    ctx, err = SetBaggage("key", key)
	if err != nil {
		slog.Error("failed to set baggage", err)
      return ctx, nil
	}
}

Loggerの実装例

Contextを介して伝播されるTrace ID, Span ID, Baggageのkeyとvalueをログに出力するよう実装します。

// internal/logger/logger.go
package logger

import (
	"context"
	"log/slog"
	"os"
	"go.opentelemetry.io/otel/baggage"
	"go.opentelemetry.io/otel/trace"
)

type LogHandler struct {
	slog.Handler
}

func NewLogHandler() LogHandler {
	return LogHandler{
		Handler: slog.NewJSONHandler(os.Stdout),
	}
}

func (h LogHandler) Handle(ctx context.Context, r slog.Record) error {
	sc := trace.Span

ContextFromContext(ctx)
	if sc.IsValid() {
		r.AddAttrs(
			slog.String("trace", sc.TraceID().String()),
			slog.String("span_id", sc.SpanID().String()),
		)
	}
	bg := baggage.FromContext(ctx)
	members := bg.Members()
	for _, member := range members {
		r.AddAttrs(slog.String(member.Key(), member.Value()))
	}
	return h.Handler.Handle(ctx, r)
}

このloggerを呼び出し元で初期化し、InfoContextやErrorContextメソッドを介することで、Trace IDやBaggageの値をログに追加できます。

logger := newLogHandler()
logger.InfoContext(ctx, "success to do something")
logger.ErrorContext(ctx, "success to do something")

slogとcontext.Contextについては、以下のリソースが参考になります。

OpenTelemetryロガーとしてslogを使用する場合、otelslogも選択肢になります。まだv0.0.3ですが、今後の発展次第で導入を検討する価値はありそうです。

今後に向けて

OpenTelemetryを用いたトレーサビリティの高いLoggerの実装例を紹介しました。当初の課題は解決しましたが、ログに多くの情報を詰め込んでしまうという問題も生じています。将来的には、必要な時だけTrace IDやSpan IDを出力するなどの対策が必要かもしれません。

皆様の参考になれば幸いです。

Discussion