GOGEN Tech Blog
🐶

開発を加速させる、オブザーバビリティ(Go × ECS Fargate × Datadog)

に公開

こんにちは、GOGENでCTOをしている楠本(@zabio3)です。

GOGENでは、不動産売買取引というドメイン特有の複雑さを捉えるSaaS開発において、少人数での効率的な価値提供を支える開発環境づくりが非常に重要だと考えています。その中でも、障害の検知・原因追跡・修正を迅速に行える「オブザーバビリティ(可観測性)」の整備は、開発生産性とユーザー体験の双方を支える土台となっています。

本記事では、その設計思想と、日々の開発実務にどう落とし込んでいるかを紹介します。限られたリソースでも安定した価値提供を続けるために、メトリクス、トレーシング、ロギングという3つの観点から観測性を高める取り組みを行っています。

なぜオブザーバビリティが大事なのか

GOGENでは「開発者の時間を本質的価値に集中させる」という方針のもと、初期の開発フェーズから監視・可視化を徹底しています。

これにより、障害の早期発見・一次切り分けができ、エラー対応が 運用負荷 ではなく 開発体験の一部 として回る仕組みを実現しました。

導入に選んだのはDatadog。AWS ECS + Go + Next.jsという構成下で、最小のコストで最大の情報を得られるよう、独自ライブラリ群も整備しています。

メトリクス

基本的なメトリクスはECSを通してCloudWatchに集約されるのですが、我々のサービスではバックエンド開発にGo言語を利用しており、基本的なCloudWatchのメトリクスだけでは到底、障害対応に立ち向かう事ができません。
そこでDatadog Metricsにカスタムメトリクスを送信することで障害対応に備えることにしました。
Go言語でサービスを開発するときに我々が取得しているメトリクスの例を紹介します。

1. 実際のメモリ使用量
Go言語にはGCが存在するため、ECS経由で取得できるメモリ使用量は実際に利用されているメモリ利用量よりもはるかに大きい値であり、なかなか開放されません。そのため、実際にどれだけのメモリが必要とされているのかを測ることができません。これは長期的なメモリリークなどを調査するときに困ります。

2. goroutine の数
Go言語を用いてユーザーのリクエスト時間が長くなる傾向のあるチャットなどのリアルタイムなサービスを開発するときや、簡単な非同期処理を行う際などに、goroutineを活用する場合がありますが、その際、現在サーバー上で実行されているgoroutineの数を気にする必要があります。goroutineリークが起きないように気をつけないといけません。

3. MySQLへの接続数
Go言語ではMySQLへの接続にはコネクションプールが使われますが、それらが意図したとおりのコネクション数を保っているかを確認する必要があります。AuroraなどのAmazon RDSへの接続数はインスタンスサイズによりシビアに固定されており、サービスがまだ小さなフェーズだと、合わせて小さなインスタンスを利用するケースも多く、MaxConnectionsエラーに引っかかりがちです。これらもしっかり監視する必要があります。

どのようにメトリクスを取得しているか
アプリのコンテナからPrometheusのライブラリpromhttpを用いてOpenMetrics形式で出力し、Datadog AgentのOpenMetrics Integrationでその値を定期的にポーリングしてもらい、Datadog Metricsへ送信しています。
promhttpを利用すれば、デフォルトでメモリ利用量やgoroutine数など、Goのランタイムの必須メトリクスを取得することができます。
MySQLのコネクション数の取得にはdlmiddlecote/sqlstatsを利用しています。

トレーシング

トレーシングはリクエストあたりのログの量を少なくするのに非常に役立ちます。
処理の開始と終わりをスパンという単位で計測し、スパンの親子関係でサービスやリソースの依存関係を表現できます。
つまり、都度詳細なログを仕込まなくても、リクエストの内部でどのようなサービス・リソースを呼び出しており、それにどのくらいの時間がかかっているか、どのようなクエリが実行されたのかなどが詳細に記録されるのです。
エラーが起きたときにどこのスパンでエラーが起きているのかも一目瞭然です。1リクエストに必要な情報が1つのトレースに集約されるため、膨大なログの中から必要なログを探し出す作業はもう必要ありません。

OpenTelemetry

Datadog Traces向けにトレースを取得する方法にはdd-trace-goを利用するなどいくつかあるのですが、我々のチームではOpenTelemetryという共通規格の実装を用いることにし、今後Datadog以外の便利なツールが出てきたときにそこにもトレースログを送信できるようにしています。
OpenTelemetryはdd-trace-goとは違って、利用しているライブラリごとのライブラリを探して利用する必要があります。(もちろん独自のサービス・リソースのスパン用のライブラリを自作することもできます。)

我々が実際に利用しているOpenTelemetryライブラリをいくつか紹介します。

  1. connect-go: connectrpc.com/otelconnect
    • Connect RPC用のライブラリ
  2. chi: github.com/riandyrn/otelchi
    • http サーバー chi 用のライブラリ
  3. bun: github.com/uptrace/bun/extra/bunotel
    • bun ORM 用のライブラリ
  4. aws: go.opentelemetry.io/contrib/instrumentation/github.com/aws/aws-sdk-go-v2/otelaws
    • AWS SDK 用のライブラリ
  5. http: go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp
    • 外部サービスを実行するHTTP Client用のライブラリ
  6. gRPC exporter: go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc
    • Datadog Agent へのトレースログ出力用のライブラリ
  7. 標準出力 exporter: go.opentelemetry.io/otel/exporters/stdout/stdouttrace
    • ローカル環境でのトレースログデバッグ用

トレーシングを複数サービスに横展開するための取り組み

トレースログを出力するためにOpenTelemetry関連の処理を記述することをメンバーに押し付けることで認知負荷を高めてしまい、サービス開発に集中できなくなることがあっては開発速度を下げてしまうことに繋がります。
GOGEN ecosystem ライブラリを作ることでトレーシングに関連する処理を複数サービスに横展開する取り組みを行っています。
いくつかそのライブラリの内容をご紹介します。

1) connect-goのリクエスト毎のスパン作成をInterceptorにまとめた例

package ddotel

import (
	"context"
	"errors"

	"connectrpc.com/connect"
	"go.opentelemetry.io/otel/attribute"

	"github.com/GOGEN-Inc/release/backend/pkg/cerr"
	"github.com/GOGEN-Inc/release/backend/pkg/clog"
)

const (
	DDAttributeErrorStackKey   = attribute.Key("error.stack")
	DDAttributeErrorMessageKey = attribute.Key("error.message")
)

func NewConnectTraceLogUnaryInterceptor() connect.UnaryInterceptorFunc {
	return func(next connect.UnaryFunc) connect.UnaryFunc {
		return func(ctx context.Context, req connect.AnyRequest) (connect.AnyResponse, error) {
			span := injectTraceAttributes(ctx, "connect.server")
			resp, err := next(ctx, req)
			if err != nil {
				cErr := &cerr.Error{}
				if errors.As(err, &cErr) {
					if clog.ConnectCodeToLevel(cErr.ConnectError().Code()) == clog.LevelError {
						span.SetAttributes(DDAttributeErrorMessageKey.String(err.Error()))
						if cErr.Stack != "" {
							span.SetAttributes(DDAttributeErrorStackKey.String(cErr.Stack))
						}
					}
				} else {
					span.SetAttributes(DDAttributeErrorMessageKey.String(err.Error()))
				}
			}
			return resp, err
		}
	}
}

2) Auth0へのリクエストスパンをコンストラクタにまとめた例

package auth0

import (
	"net/http"

	"go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
	"go.opentelemetry.io/otel/attribute"
	semconv "go.opentelemetry.io/otel/semconv/v1.18.0"
	"go.opentelemetry.io/otel/trace"
)

func NewAuth0ClientWithTracer(cfg *Config) Client {
	auth0Http := &http.Client{
		Transport: otelhttp.NewTransport(
			http.DefaultTransport,
			otelhttp.WithSpanOptions(trace.WithAttributes(
				attribute.KeyValue{
					Key:   "operation.name",
					Value: attribute.StringValue("auth0.http"),
				},
				semconv.ServiceName(cfg.ServiceName),
			)),
		),
	}
	client, err := NewClient(cfg, auth0Http)
	if err != nil {
		panic(err)
	}
	return client
}

このようにInterceptorを差し込むだけ、またはコンストラクタをDIするだけで各所のスパンが生成されるような仕組みを提供し、機能開発時にOpenTelemetry関連ライブラリ群と他のエンジニアが格闘する必要がないようにしています。

エラーログが出たときにスタックトレースを取得する重要性

Go標準のエラーではエラーが出たときにスタックトレースが出力されないため、どこでエラーが起きたかが一見してわかりません。
エラーを返すときはfmt.Errorf()などを用いてWrapするルールを敷いているのですが、それでもエラー調査時の手間がかかります。

そこで我々は独自のエラー型をecosystemライブラリ内で定義することで対応しました。
エラーをNewするときにスタックトレースを取得する仕組みを作りました。

package cerr

import (
	"bytes"
	"context"
	"encoding/json"
	"errors"
	"fmt"
	"net"
	"net/http"
	"runtime"

	"connectrpc.com/connect"
	"google.golang.org/protobuf/proto"

	"github.com/GOGEN-Inc/release/backend/pkg/clog"
)

type Error struct {
	Code    Code
	Msg     string          // ユーザーへ Code とともに返却するメッセージ
	Err     error           // ログに残したいエラー
	Stack   string          // スタックトレース
	Details []proto.Message // ユーザーへ返却したい詳細なエラー
}

func NewError(code Code, msg string, wrap error) *Error {
	err := &Error{
		Code: code,
		Msg:  msg,
		Err:  wrap,
	}
	if clog.ConnectCodeToLevel(code.ConnectCode()) == clog.LevelError {
		stackTrace := make([]byte, 2048)
		n := runtime.Stack(stackTrace, false)
		err.Stack = string(stackTrace[0:n])
	}
	return err
}

このようにNewするときにログレベルがErrorだった場合にはスタックトレースを取得して含めるようにしています。
エラーをプロジェクト内で共通フォーマット化することにより、ログレベルの指定、ユーザーに返却するメッセージの作成、ログに出力するエラーのラップ、必要に応じたスタックトレースの作成などを一元管理することができます。
これらの情報を利用し、トレースログにエラーやスタックトレースを出力しています。 (先ほど示した「1) connect-goのリクエスト毎のスパン作成をInterceptorにまとめた例」を参考にしてください。)

スタックトレースを出力するとDatadogとGitHubのコードを連携できる

Datadog TracesにはGitHub連携機能というのがあり、トレースログにスタックトレースがアタッチされていた場合、スタックトレースの箇所のソースコードをDatadog Traces上で見ることができます。
つまりGitHubやIDEを開かなくても、エラーアラートが飛んできたときに、Datadogだけでエラーの原因に当たりをつけることができるのです。外出先でもスマホひとつで障害の一次対応ができたりします。これは少人数でサービスを運用するに当たり非常に強力な機能です。
この機能を利用するときはデプロイ時のタスク定義にGitのrepository_urlとcommitハッシュを含め、トレースログにそれらのデータを出力する必要があります。
これらはすべてのトレースログにおいて共通のattributeなのでExporter内で指定しておけば大丈夫です。

package ddotel

import (
	"context"
	"fmt"

	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc"
	"go.opentelemetry.io/otel/exporters/stdout/stdouttrace"
	"go.opentelemetry.io/otel/propagation"
	"go.opentelemetry.io/otel/sdk/resource"
	"go.opentelemetry.io/otel/sdk/trace"
	semconv "go.opentelemetry.io/otel/semconv/v1.18.0"
)

type InitGlobalTracerInput struct {
	Env          string
	DebugTracing bool
	ServiceName  string
	Version      string
	GitCommitSHA string
	GitRepo      string
}

func InitGlobalTracer(input *InitGlobalTracerInput) error {
	var exporter trace.SpanExporter
	if input.Env == "local" {
		// ローカルで DebugTracing が true の場合、 stdout にトレースを export する。
		if input.DebugTracing {
			var err error
			exporter, err = stdouttrace.New(stdouttrace.WithPrettyPrint())
			if err != nil {
				return fmt.Errorf("failed to initialize stdout exporter: %w", err)
			}
		}
	} else {
		// ローカル以外、 Datadog agent 向けにトレースを export する。
		var err error
		exporter, err = otlptracegrpc.New(
			context.Background(),
			otlptracegrpc.WithInsecure(),
		)
		if err != nil {
			return fmt.Errorf("failed to initialize otlptrace exporter: %w", err)
		}
	}
	res := resource.NewWithAttributes(
		semconv.SchemaURL,
		semconv.ServiceName(input.ServiceName),
		semconv.ServiceVersion(input.Version),
		attribute.KeyValue{
			Key:   "git.commit.sha",
			Value: attribute.StringValue(input.GitCommitSHA),
		},
		attribute.KeyValue{
			Key:   "git.repository_url",
			Value: attribute.StringValue(input.GitRepo),
		},
	)
	opts := []trace.TracerProviderOption{
		trace.WithSampler(trace.AlwaysSample()),
		trace.WithResource(res),
	}
	if exporter != nil {
		opts = append(opts, trace.WithBatcher(exporter))
	}
	tp := trace.NewTracerProvider(opts...)
	otel.SetTracerProvider(tp)
	otel.SetTextMapPropagator(propagation.NewCompositeTextMapPropagator(propagation.TraceContext{}, propagation.Baggage{}))
	return nil
}

ロギング

Go標準ロガーであるslogを利用して、構造化ログを出力するようにしています。基本的にリクエストのログは1リクエスト1ログに限定して、出力したいカスタム値がある場合はリクエストContext内のattributes mapに値を追加し、リクエストの最後にInterceptor内でまとめて1回だけ出力する仕組みを取っています。

カスタムロガーの作成

slogを直接利用するのではなく、gRPC ecosystemのロガーを参考にリクエストContext内にロガーとattributesを入れて持ち運ぶライブラリを作成して利用しています。

package clog

import (
	"context"
	"log/slog"
	"sync"
)

type ctxSlog struct {
	logger     *slog.Logger
	mu         sync.RWMutex
	attributes map[string]any
}

type ctxSlogKey struct{}

func ContextWithSlog(ctx context.Context, logger *slog.Logger) context.Context {
	ctxSlog := &ctxSlog{
		logger:     logger,
		attributes: make(map[string]any),
	}
	return context.WithValue(ctx, ctxSlogKey{}, ctxSlog)
}

func Extract(ctx context.Context) *slog.Logger {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return slog.Default()
	}
	logger := l.logger
	var attrs []any
	for k, v := range l.attributes {
		attrs = append(attrs, k, v)
	}
	logger = logger.With(attrs...)
	return logger
}

func AddAttributes(ctx context.Context, attributes map[string]any) {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return
	}
	l.mu.Lock()
	defer l.mu.Unlock()
	for k, v := range attributes {
		l.attributes[k] = v
	}
}

const (
	MessageAttributeKey = "msg"
	ErrorAttributeKey   = "error.message"
	StackAttributeKey   = "error.stack"
)

func AddError(ctx context.Context, err error) {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return
	}
	l.mu.Lock()
	defer l.mu.Unlock()
	l.attributes[ErrorAttributeKey] = err
}

func GetError(ctx context.Context) error {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return nil
	}
	l.mu.RLock()
	ierr, ok := l.attributes[ErrorAttributeKey]
	l.mu.RUnlock()
	if !ok {
		return nil
	}
	err, ok := ierr.(error)
	if !ok {
		return nil
	}
	return err
}

func AddMsg(ctx context.Context, msg string) {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return
	}
	l.mu.Lock()
	defer l.mu.Unlock()
	l.attributes[MessageAttributeKey] = msg
}

func GetMsg(ctx context.Context) string {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return ""
	}
	l.mu.RLock()
	msg, ok := l.attributes[MessageAttributeKey].(string)
	l.mu.RUnlock()
	if !ok {
		return ""
	}
	return msg
}

func delMsg(ctx context.Context) {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return
	}

	l.mu.Lock()
	defer l.mu.Unlock()
	if _, ok := l.attributes[MessageAttributeKey]; !ok {
		return
	}
	delete(l.attributes, MessageAttributeKey)
}

func AddStack(ctx context.Context, stack string) {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return
	}
	l.mu.Lock()
	defer l.mu.Unlock()
	l.attributes[StackAttributeKey] = stack
}

func GetStack(ctx context.Context) string {
	l, ok := ctx.Value(ctxSlogKey{}).(*ctxSlog)
	if !ok {
		return ""
	}
	l.mu.RLock()
	iStack, ok := l.attributes[StackAttributeKey]
	l.mu.RUnlock()
	if !ok {
		return ""
	}
	stack, ok := iStack.(string)
	if !ok {
		return ""
	}
	return stack
}

実際のロジック内では下記のコードを用いてロギングを行います。

package clog

import (
	"context"
	"fmt"
)

func Debug(ctx context.Context, msg string, args ...any) {
	Extract(ctx).DebugContext(ctx, msg, args...)
}

func Debugf(ctx context.Context, format string, args ...any) {
	Extract(ctx).DebugContext(ctx, fmt.Sprintf(format, args...))
}

func Info(ctx context.Context, msg string, args ...any) {
	Extract(ctx).InfoContext(ctx, msg, args...)
}

func Infof(ctx context.Context, format string, args ...any) {
	Extract(ctx).InfoContext(ctx, fmt.Sprintf(format, args...))
}

func Warn(ctx context.Context, msg string, args ...any) {
	Extract(ctx).WarnContext(ctx, msg, args...)
}

func Warnf(ctx context.Context, format string, args ...any) {
	Extract(ctx).WarnContext(ctx, fmt.Sprintf(format, args...))
}

func Error(ctx context.Context, msg string, args ...any) {
	Extract(ctx).ErrorContext(ctx, msg, args...)
}

func Errorf(ctx context.Context, format string, args ...any) {
	Extract(ctx).ErrorContext(ctx, fmt.Sprintf(format, args...))
}

Datadog Tracesとの連携

Datadog Tracesとログを連携させるために、dd.trace_idというattributeを構造化ログに含める必要があります。これを含めておくと、各トレース画面からリクエスト内のすべてログをリストアップできたり、ログからトレース画面へ飛ぶことができるようになります。

このようにトレースを作成するときにロガーのattributeにトレースIDを関連付けておくことで、すべてのログにトレースIDを含めることができます。

package ddotel

import (
	"context"
	"strconv"

	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/trace"

	"github.com/GOGEN-Inc/release/backend/pkg/clog"
)

func injectTraceAttributes(ctx context.Context, opsName string) trace.Span {
	spanCtx := trace.SpanContextFromContext(ctx)
	traceID := spanCtx.TraceID()
	spanID := spanCtx.SpanID()
	ddTraceID := OtelTraceIDToUint64(traceID)
	ddSpanID := OtelSpanIDToUint64(spanID)

	// Inject trace ID into log attributes
	clog.AddAttributes(ctx, map[string]any{
		"otel.trace_id": traceID.String(),
		"dd.trace_id":   strconv.FormatUint(ddTraceID, 10),
		"dd.span_id":    strconv.FormatUint(ddSpanID, 10),
	})

	// Inject operation name into span attributes for Datadog APM
	span := trace.SpanFromContext(ctx)
	span.SetAttributes(attribute.KeyValue{
		Key:   "operation.name",
		Value: attribute.StringValue(opsName),
	})
	return span
}

DatadogとOpenTelemetryでトレースIDの型が異なる問題

DatadogとOpenTelemetryでトレースIDの型が異なるため、適宜変換する必要があります。基本的にOpenTelemetry -> Datadogの方向でしか変換する必要はありません。

  • Datadog: uint64
  • OpenTelemetry: [16]byte
package ddotel

import "encoding/binary"

// OpenTelemetry と Datadog の TraceID と SpanID の変換
// dd-agent 準拠で変換する
// https://github.com/DataDog/datadog-agent/blob/47e3e537dae47ec704b2de7e06c20dbf3e166aee/pkg/trace/api/otlp.go#L676-L682

func OtelTraceIDToUint64(b [16]byte) uint64 {
	return binary.BigEndian.Uint64(b[len(b)-8:])
}

func OtelSpanIDToUint64(b [8]byte) uint64 {
	return binary.BigEndian.Uint64(b[:])
}

ここではDatadog Agentが内部で行っている変換ロジックを参考にしました。OpenTelemetryの16 bytes中、8 bytesのみを利用してuint64に変換しています。

ログをどのようにDatadogに送信しているか

ECSにはFirelensという機能があり、コンテナの標準出力をサイドカーに戻す機能があります。
サイドカーでfluentbitを起動しており、そこでJSONで出力された構造化ログをパースし、Datadogに送信するようにしています。
Datadogで送信すると同時にfirehose経由でS3にもログを保存しています。このため、Datadog Logsが障害のときもログを欠損させずにS3に保存することができます。

おわりに、GOGENではエンジニアを募集しています!

本記事ではGOGENプロダクト部で行っているオブザーバビリティの実践例を、メトリクス、トレーシング、ロギングの3つに分けてご紹介しました。
実際のコード例も示しておりますので、皆様のオブザーバビリティの向上のお役に立てれば嬉しいです。

他にも、Datadog RUM(Real User Monitoring)なども活用している為、運用を楽にしてくれる便利な機能も紹介していければと考えています。

少しでも興味を持たれた方は、ぜひお気軽にご連絡ください。ぜひ一度お話ししましょう。

採用情報の詳細は、下記リンクよりご覧いただけます👇

https://herp.careers/v1/gogen/vkCF0UKhKF-u

GOGEN Tech Blog
GOGEN Tech Blog

Discussion