Go 1.21 で追加された log/slog を本番環境に実戦投入しました

この記事は Go Advent Calendar 2023 7 日目の記事です。

こんにちは。ARIGATOBANK バックエンドエンジニアの富樫です。

私たちのチームでは、バックエンドシステムのすべてを Go 言語で構築しています。これまでロギングライブラリとして主に zap を利用してきましたが、最近 Go 1.21 で追加された log/slog を本番環境の一部サービスで利用し始めました。

この記事では、log/slog を開発や本番環境へ投入するにあたってカスタマイズした実装の詳細について共有します。

log/slog とは

Go 1.21 で標準ライブラリに加わった log/slog は、構造化ロギングをサポートするログパッケージです。

slog package — log/slog — Go Packages

基本的な使い方はこんな感じです。

package main

import (
  "log/slog"
  "os"
)

func main() {
  slog.SetDefault(slog.New(slog.NewJSONHandler(os.Stdout, nil)))
  slog.Info("hello, world!", slog.String("user", "gopher"))
}

実行すると以下のように出力されます。

{"time":"2023-12-03T16:56:12.194852+09:00","level":"INFO","msg":"hello, world!","user":"gopher"}

これまで構造化ロギングには logrus 、zap、zerolog などのサードパーティライブラリが利用されてきました。Go の標準ライブラリには初期から log パッケージがありますが、基本的な機能の提供に留まります。構造化ロギングの重要性の高まりや、大規模なプログラムにおいて複数ログパッケージの混在による一貫したログ出力の難しさなどの課題を受けて、今回新たに標準ライブラリとして追加されました。
（参考: Structured Logging with slog）

log/slog の API は、フロントエンドの Logger とバックエンドの Handler に分かれています。共通のバックエンドである Handler を標準ライブラリとして提供することで、既存のログパッケージを含めて相互運用可能になっています。また、context.Context 型を標準でサポートし、Handler でコンテキスト情報を抽出できるなど、後発パッケージならではの設計がなされています。

log/slog を利用したログ出力実装の詳細

開発および本番環境への投入に向けて、Google Cloud や OpenTelemetry との統合を実現する必要がありました。そこで、log/slog を利用して以下の 3 つを実装しました。

• Cloud Logging と既存の zap 構成との互換性を保つ ReplaceAttr 関数
• OpenTelemetry の TraceID と SpanID を Cloud Logging の指定フィールドに埋め込む Handler
• 既存ログモジュールと互換性のある独自ログ出力関数

最終的には以下のコードに対して次のような出力が得られる実装になりました。

// ハンドラの設定
slog.SetDefault(slog.New(NewHandler("foobar")))

// ログ出力
Info(ctx, "Hello, ARIGATOBANK Tech Blog!", slog.String("user", "gopher"))

{
  "time": "2023-12-04T08:48:47.220523+09:00",
  "severity": "INFO",
  "caller": "sample/main.go:25",
  "message": "Hello, ARIGATOBANK Tech Blog!",
  "user": "gopher",
  "logging.googleapis.com/trace": "projects/foobar/traces/8416afb165e7189003dce7f8617c17ba",
  "logging.googleapis.com/spanId": "9620652c5aabf556",
  "logging.googleapis.com/trace_sampled": false
}

以下で各実装について詳しく説明します。

slog.HandlerOptions.ReplaceAttr の実装

ReplaceAttr はログ出力の直前に呼び出される関数で、フィールドの変換や削除に利用します。

ここで実装したのは 2 つです。1 つは Cloud Logging の構造化ロギングにおける 特別な JSON フィールド への対応、もう 1 つは既存のログモジュールで利用していた zap の構成との互換性を維持する対応です。

具体的には以下のように実装しています。

func NewHandler(projectId string) *Handler {
  opt := slog.HandlerOptions{
    AddSource:   true,
    ReplaceAttr: replaceAttr,
  }
  return &Handler{
    Handler:      slog.NewJSONHandler(os.Stderr, &opt),
    GcpProjectId: projectId,
  }
}

func replaceAttr(groups []string, a slog.Attr) slog.Attr {
  switch a.Key {
  case slog.LevelKey:
    // Cloud Logging 対応: level -> severity
    return slog.String("severity", getSeverity(a.Value.Any().(slog.Level)))
  case slog.MessageKey:
    // Cloud Logging 対応: msg -> message
    return slog.Attr{Key: "message", Value: a.Value}
  case slog.SourceKey:
    // zapcore.ShortCallerEncoder 相当
    return slog.Any("caller", getCaller(a.Value.Any().(*slog.Source)))
  }
  switch a.Value.Kind() {
  case slog.KindDuration:
    // zapcore.StringDurationEncoder 相当
    return slog.String(a.Key, a.Value.Duration().String())
  }
  return a
}

slog.Handler.Handle の実装

Handler はログ出力の実体を担うインターフェースです。カスタマイズとしては、標準ライブラリが提供する slog.JSONHandler などに出力を任せつつ、出力したいフィールドを追加する機能などをここに実装していくことになるでしょう。

特に slog.Handler.Handle は context.Context 型が引数に入ってきます。私たちのチームでは OpenTelemetry を利用しているので、SpanContext から TraceID や SpanID などを取り出してログに埋め込む機能を実装しました。ここでも Cloud Logging の特別な JSON フィールドに出力し、Cloud Trace の Trace や Span と紐づくようにしています。

type Handler struct {
  slog.Handler
  GcpProjectId string
}

const (
  keyGcpTrace        = "logging.googleapis.com/trace"
  keyGcpSpanId       = "logging.googleapis.com/spanId"
  keyGcpTraceSampled = "logging.googleapis.com/trace_sampled"
)

func (h *Handler) Handle(ctx context.Context, r slog.Record) error {
  if h.GcpProjectId != "" {
    spanCtx := trace.SpanContextFromContext(ctx)
    if spanCtx.IsValid() {
      r.AddAttrs(
        slog.String(keyGcpTrace, fmt.Sprintf("projects/%s/traces/%s", h.GcpProjectId, spanCtx.TraceID().String())),
        slog.Bool(keyGcpTraceSampled, spanCtx.IsSampled()),
        slog.String(keyGcpSpanId, spanCtx.SpanID().String()),
      )
    }
  }

  return h.Handler.Handle(ctx, r)
}

独自のログ出力関数を定義する

log/slog では、各ログレベルごとに context.Context 型の引数を取る関数と取らない関数が用意されています。例えば Info レベルのログ出力関数として以下の 2 つがあります。

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

しかし、開発者にとってはどちらを使うべきか迷いが生じたり、誤って Context を引数にとらないメソッドを利用し TraceID が出力されないといった不具合に繋がる可能性があります。 私たちのチームでは以前から Logger ライブラリを社内で独自に整備していたこともあり、log/slog の利用においても以下のようなログ出力関数を独自に定義することにしました。

func Info(ctx context.Context, msg string, args ...any)
func Infof(ctx context.Context, format string, args ...any)
// 他のログレベルの関数も同様

ここで問題になるのが、出力に含まれるファイル名や行番号の取得です。これらの独自関数から単純に slog.InfoContext などの関数を呼び出すと、ログ出力元のファイル名や行番号として独自関数の定義位置が出力されてしまいます。

この問題については log/slog のパッケージドキュメントにも言及があり、解決策が Example に示されています。ドキュメントに沿って以下のように実装しました。

func Info(ctx context.Context, msg string, args ...any) {
  log(ctx, slog.LevelInfo, msg, args...)
}

func log(ctx context.Context, level slog.Level, msg string, args ...any) {
  logger := slog.Default()
  if !logger.Enabled(ctx, level) {
    return
  }

  var pcs [1]uintptr
  runtime.Callers(3, pcs[:]) // Skip(3): Callers, log, Debug[f]/Info[f]/Warn[f]/Error[f]/Fatal[f]

  r := slog.NewRecord(time.Now(), level, msg, pcs[0])
  r.Add(args...)

  _ = logger.Handler().Handle(ctx, r)
}

独自関数の導入には多少の迷いがあり、Go らしく Linter を実装して利用する関数を強制することも検討しました。最終的には slog.InfoContext などの名前がほんのちょっとだけ長いと感じたことや、既存の使い勝手を維持したいという考えから導入を決めました。

また、これらの関数は、実質的には slog の Handler を呼び出す実装でしかありません。いざとなれば slog.InfoContext などの標準ライブラリの関数を使えますし、それにより出力内容に影響を与えることはありません。この柔軟性に気付いたとき、log/slog の設計の巧妙さに改めて感心しました。

今後の log/slog に期待すること

log/slog が標準ライブラリに追加されたことにより、ログ出力の共通バックエンドとしてのインターフェースが標準化されました。

今後は各 Observability バックエンドが Handler や ReplaceAttr 関数の実装を提供し、開発者にとって適切なログ出力の実装が容易になることを期待しています。OpenTelemetry における instrumentation のようにエコシステムが充実すると良いですね。

例えば Cloud Logging のフィールドに対応する Handler や ReplaceAttr 関数が Google Cloud 自身のメンテナンスによって公開されることを期待したいです。

まとめ

この記事では Go 1.21 で新しく標準ライブラリに加わった log/slog の本番環境投入にあたって実装した内容について紹介しました。これから log/slog の利用を検討している方にとって、参考になる情報があれば幸いです。他にもこういう実装を slog でやってみたよ、という話があればぜひ教えてください。

参考資料

• log/slog パッケージドキュメント
• Structured Logging with slog
• A Guide to Writing slog Handlers
• A consistent logging format for Go
• Structured logging | Cloud Logging
• Cloud Logging 構造化ログの特別な JSON フィールドまとめ

We are Hiring!

ARIGATOBANK の提供するモバイルアプリ “arigatobank” は、バックエンドシステムをすべて Go で開発しています。今後も「お金で困っている人をゼロにする」世界を実現するために Go をフル活用して様々な機能やサービスを創出していきたいと考えています。

新しいお金の流れをつくるプロダクト開発に一緒に取り組む仲間を探しています。興味をもっていただけましたら、まずはカジュアルにお話できればと思います。お気軽に 採用ページ からご連絡ください！

ARIGATOBANK Culture Deck