💬

GoアプリケーションからDBにおけるSQLクエリの処理まで一気通貫で計装する(GORM+sqlcommenter)

に公開

はじめに

どうもこんにちは。間瀬です。
本記事はOpenTelemetry Advent Calendar 2025の1日目の記事です。
https://qiita.com/advent-calendar/2025/otel

私事ですが、今日から新たな?職場で働くことになりました。
これまで培った経験を活かして貢献できるよう努めていきます。

さて、今回はOpenTelemetryとGoogle Cloudのサービスを使って、Goで実装したアプリケーションからRDBMSにおけるSQLクエリの処理まで一気通貫で計装する方法を紹介したいと思います。

計装方法・システム構成

  • アプリからDBへのアクセスはORMであるGORMを使用します。
  • go-gorm/opentelemetryを使用してGORMにおける処理を計装します。
  • sqlcommenterでSQLにトレース&スパンをコメントとして埋め込みます。
  • インフラはGoogle Cloudで構築し、DBはCloud SQL for MySQL、トレースとログはそれぞれCloud TraceとCloud Loggingをバックエンドとして利用します。
  • Cloud SQLのパフォーマンス分析ツールとして無料で提供されているQuery Insightを利用します。

app_architecture

go-gorm/opentelemetry & sqlcommenter周りの仕組み解説

GORM

GORMはGoにおけるORM(SQLを直接書かずにコードからデータベースの操作ができるライブラリ)の一つです。
今回関連する特徴的な機能として、「Hooks」という機能があり、データベースにSELECTなどの特定の操作を行う前後で処理を挟むことが可能です。

go-gorm/opentelemetry

GORMにおける処理をOpenTelemetryで計装するためのプラグインになっており、上記のHooksを利用してデータベース操作の前後でスパンの生成やメトリクスの収集を行ってくれます。これらの処理はプラグインの初期化時にフックとして登録されています。

https://github.com/go-gorm/opentelemetry/blob/2ca45f9278a7d7ccfd3228c93295c20e0234e237/tracing/tracing.go#L70

func (p otelPlugin) Initialize(db *gorm.DB) (err error) {
	if !p.excludeMetrics {
		if sqlDB, err := db.DB(); err == nil {
			metrics.ReportDBStatsMetrics(sqlDB)
		}
	}
    
    # フックとして実行する処理の定義
	cb := db.Callback()
	hooks := []struct {
		callback gormRegister
		hook     gormHookFunc
		name     string
	}{
		{cb.Create().Before("gorm:create"), p.before("gorm.Create"), "before:create"},
		{cb.Create().After("gorm:create"), p.after(), "after:create"},

		{cb.Query().Before("gorm:query"), p.before("gorm.Query"), "before:select"},
		{cb.Query().After("gorm:query"), p.after(), "after:select"},

		{cb.Delete().Before("gorm:delete"), p.before("gorm.Delete"), "before:delete"},
		{cb.Delete().After("gorm:delete"), p.after(), "after:delete"},

		{cb.Update().Before("gorm:update"), p.before("gorm.Update"), "before:update"},
		{cb.Update().After("gorm:update"), p.after(), "after:update"},

		{cb.Row().Before("gorm:row"), p.before("gorm.Row"), "before:row"},
		{cb.Row().After("gorm:row"), p.after(), "after:row"},

		{cb.Raw().Before("gorm:raw"), p.before("gorm.Raw"), "before:raw"},
		{cb.Raw().After("gorm:raw"), p.after(), "after:raw"},
	}

	var firstErr error

    # フックの登録
	for _, h := range hooks {
		if err := h.callback.Register("otel:"+h.name, h.hook); err != nil && firstErr == nil {
			firstErr = fmt.Errorf("callback register %s failed: %w", h.name, err)
		}
	}

	return firstErr
}

本プラグインを使用すると例えば以下のような情報がトレースの属性として付与されます。

属性 説明
db.system.name データベースシステムの名前(例:mysql)
db.collection.name 操作対象のテーブル名
db.operation データベース操作の種類(例:select)
db.query.text 実行されたSQLクエリ

ログへのTrace、Span情報の埋め込みについて

本プラグインではログへTraceとSpanを埋め込むための機能が提供されていますが、GORMのデフォルトのロガーではコンテキスト情報の伝播ができていない?のか埋め込むことができませんでした。(特にissueで報告されているように見えなかったので、単純に私の使い方が良くないのかもしれない)

また、本プラグインで提供されているログへの埋め込み機能におけるトレースやスパンのキーが Google Cloud がトレースとログ情報をリンクするための構造化ロギングとして定義しているキーと異なってしまっているので、GORMのLoggerのカスタマイズに従い、今回は独自のロギング機能を実装していきます。

独自とはいうものの、GORMが提供しているデフォルトロガーや本プラグインが提供している機能をほぼ流用しています。

以下、ロガーの実装例です。

package log

import (
	"context"
	"errors"
	"fmt"
	"log/slog"
	"time"

	"gorm.io/gorm"
	"gorm.io/gorm/logger"
	"gorm.io/gorm/utils"
)

type slogGormLogger struct {
	slogger       *slog.Logger
	level         slog.Level
	slowThreshold time.Duration
}

func NewSlogGormLogger(slogger *slog.Logger, level slog.Level, slowThreshold time.Duration) logger.Interface {
	return &slogGormLogger{
		slogger:       slogger,
		level:         level,
		slowThreshold: slowThreshold,
	}
}

func (l *slogGormLogger) LogMode(level logger.LogLevel) logger.Interface {
	newlogger := *l
	return &newlogger
}

func (l *slogGormLogger) Info(ctx context.Context, msg string, data ...interface{}) {
	l.slogger.InfoContext(ctx, msg, data...)
}

func (l *slogGormLogger) Warn(ctx context.Context, msg string, data ...interface{}) {
	l.slogger.WarnContext(ctx, msg, data...)
}

func (l *slogGormLogger) Error(ctx context.Context, msg string, data ...interface{}) {
	l.slogger.ErrorContext(ctx, msg, data...)
}

func (l *slogGormLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) {
	if l.level > slog.LevelDebug {
		return
	}

	elapsed := time.Since(begin)
	sql, rows := fc()

	attrs := []slog.Attr{
		slog.String("file", utils.FileWithLineNum()),
		slog.String("latency", elapsed.String()),
		slog.String("sql", sql),
		slog.Int64("rows", rows),
	}

	switch {
	case err != nil && !errors.Is(err, gorm.ErrRecordNotFound):
		attrs = append(attrs, slog.String("err", err.Error()))
		l.slogger.LogAttrs(ctx, slog.LevelError, "gorm query error", attrs...)
	case elapsed > l.slowThreshold && l.slowThreshold != 0:
		slowLog := fmt.Sprintf("SLOW SQL >= %v", l.slowThreshold)
		attrs = append(attrs, slog.String("slow_log", slowLog))
		l.slogger.LogAttrs(ctx, slog.LevelWarn, "gorm slow query", attrs...)
	default:
		l.slogger.LogAttrs(ctx, slog.LevelDebug, "gorm query", attrs...)
	}
}

以下では、slogで実装したロガーで利用するためのハンドラーを実装しています。この処理の中でトレースやスパン情報を埋め込んでいきます。

package log

import (
	"context"
	"log/slog"

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

const (
	DefaultTraceIDKey      = "logging.googleapis.com/trace"
	DefaultSpanIDKey       = "logging.googleapis.com/spanId"
	DefaultTraceSampledKey = "logging.googleapis.com/trace_sampled"
)

type TraceHandlerConfig struct {
	TraceIDKey      string
	SpanIDKey       string
	TraceSampledKey string
}

type TraceHandler struct {
	slog.Handler
	config TraceHandlerConfig
}

func NewTraceHandler(h slog.Handler, config *TraceHandlerConfig) *TraceHandler {
	cfg := TraceHandlerConfig{
		TraceIDKey:      DefaultTraceIDKey,
		SpanIDKey:       DefaultSpanIDKey,
		TraceSampledKey: DefaultTraceSampledKey,
	}
	if config != nil {
		if config.TraceIDKey != "" {
			cfg.TraceIDKey = config.TraceIDKey
		}
		if config.SpanIDKey != "" {
			cfg.SpanIDKey = config.SpanIDKey
		}
		if config.TraceSampledKey != "" {
			cfg.TraceSampledKey = config.TraceSampledKey
		}
	}

	return &TraceHandler{
		Handler: h,
		config:  cfg,
	}
}

func (h *TraceHandler) Handle(ctx context.Context, r slog.Record) error {
	span := trace.SpanFromContext(ctx)
	if span.SpanContext().IsValid() {
		r.AddAttrs(
			slog.String(h.config.TraceIDKey, span.SpanContext().TraceID().String()),
			slog.String(h.config.SpanIDKey, span.SpanContext().SpanID().String()),
			slog.Bool(h.config.TraceSampledKey, span.SpanContext().TraceFlags().IsSampled()),
		)
	}
	return h.Handler.Handle(ctx, r)
}

func (h *TraceHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
	return &TraceHandler{
		Handler: h.Handler.WithAttrs(attrs),
		config:  h.config,
	}
}

func (h *TraceHandler) WithGroup(name string) slog.Handler {
	return &TraceHandler{
		Handler: h.Handler.WithGroup(name),
		config:  h.config,
	}
}

sqlcommenter

2021年頃にGoogleが発表したオープンソースのライブラリで、SQLにTraceやSpanをコメントとして埋め込むことができます。これによってアプリケーションとデータベースのデータを関連付けられるようになります。

仕組みとしては、Goの標準ライブラリである database/sql パッケージをラップすることで、SQLクエリをドライバーが処理する前にコメントを埋め込むことができるようになっています。
今回のようにGORMを利用しているときでも、初期化する際にラップされたドライバーを利用するように渡してあげることで利用することができます。

sqlcommenterでコメントに付与されるフィールド

コメントとして出力するフィールドはTraceやSpanの情報以外にもあるので、ドキュメントを参照してください。

Query Insightsとの連携

Google Cloud のCloud SQLのパフォーマンス分析ツールとして提供されているQuery InsightsはCloud Traceと連携しており、sqlcommenterでTraceやSpanをSQLに埋め込むことで、コンソール上でアプリケーション内の処理からDBにおけるクエリの処理まで一つのトレースとして紐づけた状態でデータを確認することができるようになります。

各種機能の初期化

上記で紹介した各種機能の初期化処理を行います。

package main

import (
    	"gorm.io/driver/mysql"
	"gorm.io/gorm"
	"gorm.io/plugin/opentelemetry/tracing"
	"sqlcommentercore "github.com/google/sqlcommenter/go/core"
	gosql "github.com/google/sqlcommenter/go/database/sql"
)

func initDB() (*gorm.DB, error) {

	dsn := fmt.Sprintf("%s:%s@tcp(%s:%s)/%s?charset=utf8mb4&parseTime=True&loc=Local",
		os.Getenv("DB_USER"),
		os.Getenv("DB_PASSWORD"),
		os.Getenv("DB_HOST"),
		os.Getenv("DB_PORT"),
		os.Getenv("DB_NAME"),
	)
    
        // sqlcommenterによってラップされたドライバーを利用
	dbConnPool, err := gosql.Open("mysql", dsn, sqlcommentercore.CommenterOptions{
		Config: sqlcommentercore.CommenterConfig{
			EnableDBDriver:    true,
			EnableRoute:       true,
			EnableFramework:   true,
			EnableAction:      true,
			EnableTraceparent: true,
			EnableApplication: true,
		},
	})
	if err != nil {
		panic(err)
	}

	// GORM用のlogger設定
	baseHandler := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
		Level: slog.LevelDebug,
	})
	traceHandler := otellog.NewTraceHandler(baseHandler, &otellog.TraceHandlerConfig{
		TraceIDKey:      "logging.googleapis.com/trace",
		SpanIDKey:       "logging.googleapis.com/spanId",
		TraceSampledKey: "logging.googleapis.com/trace_sampled",
	})
	slogger := slog.New(traceHandler)
	customGormLogger := otellog.NewSlogGormLogger(slogger, slog.LevelDebug, 200*time.Millisecond)

        // GORMの初期化(上記のSqlcommenterでラップされたドライバーとロガーを設定)
	db, err := gorm.Open(mysql.New(mysql.Config{
		Conn: dbConnPool,
	}), &gorm.Config{Logger: customGormLogger})
	if err != nil {
		return nil, fmt.Errorf("failed to connect to database: %w", err)
	}

	// OpenTelemetryプラグインの有効化
	if err := db.Use(tracing.NewPlugin()); err != nil {
		return nil, fmt.Errorf("failed to use tracing plugin: %w", err)
	}

	return db, nil
}

計装してみる

これまでに説明した構成で処理を実行し、Cloud Traceのコンソールから確認した結果は以下の通りです。
※説明していませんでしたが、Goアプリケーション(図中緑色の箇所)にもOpenTelemetryを導入しています。

cloud_trace_console

Cloud SQLで計装された情報(図中赤色の箇所)はクエリのスキャンにかかった時間だけでなく、実行計画も確認できるようになっています。
Query Insightsだけでも処理時間や実行計画を確認することは可能ですが、sqlcommenterを使用することでアプリケーション情報(図中緑色の箇所)との紐付けができるようになっています。

GORMのOpenTelemetryプラグインで出力したスパンにはSQLクエリが設定されているので、実行計画と合わせてどのようなクエリが実行されたか確認することができます。

gorm_span

また、以下のようにGORMが出力しているログもトレースにリンクすることができています。

log_link

留意点

  • アプリケーションとDBで同期的なサンプリングができない。

仕方のないことだと思いますが、Query Insightsが取得するデータは1分間あたりの最大サンプル数として個別に設定する必要があります。そのため、アプリケーションが計装したトレースはあるが、Cloud SQLで計装したトレースが存在しない、逆も然りという状況が発生する可能性があります。サンプル数として設定できるパラメータはCloud SQLのエディションによって異なります。詳しくはドキュメントを参照してください。

  • Query Insightsにおけるデータ保持期間とCloud Traceのデータ保持期間が異なる

Cloud SQLのエディションによってデータの保持期間が異なりますが、Enterpriseエディションの場合は7日間でEnterprise Plusエディションでは30日間になります。
Cloud Traceのデータ保持期間は30日間になるので、Enterpriseエディションを利用している場合は注意してください。

さいごに

今回はGoアプリケーションがGoogle CloudのQuery Insightsを活用することで、アプリケーションからDBでのスキャン処理まで一つのトレースとして紐づける方法について紹介しました。
いずれの手段も簡単に導入することができ、Query InsightsもCloud SQLを利用していれば無料で利用することができるので活用してみてください。

また、次回は今回計装したトレース情報をAIエージェントに取り込んで、アプリケーションからDBまで一気通貫でボトルネックの特定から原因調査、改善策の提案を行うことができるか検証した内容を紹介したいと思います。
記事を閲覧いただきありがとうございました。

Discussion