コンテンツにスキップ

Go言語のloggerをDefault1つで済ませる方法:slog Handlerがcontextの中身を見てよしなにするパターン - Diary of a Perpetual Student

チェック

  • [ ] 本文を確認した
  • [ ] 概要を確認した
  • [ ] タグを確認した
  • [ ] inbox/ 直下へ移行した

概要

Go言語のloggerをDefault1つで済ませる方法:slog Handlerがcontextの中身を見てよしなにするパターン - Diary of a Perpetual Student のWebクリップ。本文からGo、AWS、Observability、設計、キャリア評価などの学習材料として使えそうな内容を保存した。関連タグ: go, go/context, observability, opentelemetry, web-clip。

本文

Diary of a Perpetual Student

Perpetual Student: A person who remains at university far beyond the normal period

Go言語のloggerをDefault1つで済ませる方法:slog Handlerがcontextの中身を見てよしなにするパターン

先日、kamakura.go #6にて、「slog登場に伴うloggerの取り回し手法の見直し」という題で登壇しました。Go Conference 2024にこの内容でproposalを出していて落選してしまったのですが、kamakura.go #6のテーマ「昔のGo、今のGo」とピッタリだったので応募して発表の機会を頂いたという経緯です。

speakerdeck.com

この発表は以下のエントリのrefinement版となる内容です。今度は机上論ではなく実践経験をもとに話を組み立てています。

blog.arthur1.dev

  • loggerの引き回しと、なぜそれが必要だったのか

  • Logger/Handler

  • Loggerのインタフェースとして、contextを引数に持つ関数が用意される

  • デフォルトLogger

  • contextの中身を見て自動でフィールドを追加するHandlerがあれば……

  • contextにsync.Mapを持ち、その中身をログに書くHandler

  • OpenTelemetry Baggageの中身をログに書くHandler

  • まとめ

loggerの引き回しと、なぜそれが必要だったのか

あるアプリケーション・モジュールの構造化ログについて、常に特定のフィールドを付与したいというニーズがあります。例えばWebアプリケーションなら、ソースコードの関数・モジュール名、リクエストID、ユーザIDといったログの検索に有益な情報をログに付与したいでしょう。

その時に、ログの出力命令ごとにいちいちフィールドを指定しまくるのは大変です。単純にコード量が多いし、仮に付与したいフィールドが増えたときに一行一行変更して回らないといけません。ログに出したい変数を持って回る必要もあります。

log.WithFields(log.Fields{"module": "userService", "user_id": 1}).Info("validation passed") ... log.WithFields(log.Fields{"module": "userService", "user_id": 1}).Info("succeeded")

(このあたりのサンプルコードは構造化ログのライブラリとしてhttps://github.com/sirupsen/logrusを使用したケースです。)

そこで、必要に応じてloggerインスタンスを作り、呼び出し先でも利用できるように引き回す手法があります。例えば、ユーザIDが確定した時点でユーザIDを常にログに含むようなloggerを作って、それ以降の処理ではこのloggerを利用してログを書くといったやり方です。

logger := log.WithFields(log.Fields{"module": "userService", "user_id": 1}) logger.Info("validation passed") ... // loggerを作った命令とは別の関数の場合、loggerをここでも使えるように引き回す必要がある logger.Info("succeeded")

loggerの引き回し手法はいくつかありますが、私個人としては以下の記事で推奨されている手法の1つである「contextにloggerを入れる」パターンが好みです。

zenn.dev

package mylog import "context" type key struct{} func ContextWithLogger(ctx context.Context, logger Logger) context.Context { return context.WithValue(ctx, key{}, logger) } func FromContext(ctx context.Context) Logger { return ctx.Value(key{}).(Logger) }
func A() { logger := log.WithFields(log.Fields{"user_id", 1}) ctx := mylog.ContextWithLogger(context.Background(), logger) B(ctx) } func B(ctx context.Context) { logger := mylog.FromContext(ctx) logger.Info("Hello, world!") }

ただし、この手法はloggerを利用したい関数でcontextからloggerを取り出す命令を書かなければいけないので、そこだけ若干煩雑でコードの美しさが損なわれると感じていました。

slogの特徴

さて、Go 1.21からはGoビルトインのlog/slogパッケージが登場しました。https://go.googlesource.com/proposal/+/master/design/56345-structured-logging.mdがプロポーザルの内容で、こちらを読むとどのような思想で設計されたのかを知ることができます。

Logger/Handler

LoggerとHandlerという2つのインタフェースに概念が分離されました。

Info(msg string, args ...any)

Handlerは実際にログのレコードを作って書き込むという処理を担います。text、jsonといった出力フォーマットを変えることができるのはもちろん、ログレコードに特定のフィールドを追加するといった処理も可能です。

Loggerのインタフェースとして、contextを引数に持つ関数が用意される

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

デフォルトLogger

slog.SetDefault(l *Logger)

slog.Info()

実装としてはグローバル変数にloggerが格納されているのと大差ないのですが、複数のgoroutineから呼ばれことを考慮してsync/atomicが利用されています*1。

contextの中身を見て自動でフィールドを追加するHandlerがあれば……

これらの特徴を見て私は「場所によって構造化ログに自動で入れたいフィールドを制御したいという理由だけで、リクエストごとloggerを作って引き回す必要はなくなったのでは」と思いました。具体的には、contextの値を読み取って自動でフィールドを追加するようなHandlerを作り、これを用いて作ったloggerをデフォルトとして登録してしまえば、リクエストごと作ったloggerを引き回す必要がなくなるという見立てです。

こういった方針で作ってみたのが以下のコードです。contextに含まれる特定のキーの値をHandlerがログレコードのフィールドに追加するようなHandlerができました。

package main import ( "context" "log/slog" "os" ) var keys = []string{"user_id", "request_id"} type MyLogHandler struct { slog.Handler } var _ slog.Handler = &MyLogHandler{} func (h *MyLogHandler) Handle(ctx context.Context, r slog.Record) error { for _, key := range keys { if v := ctx.Value(key); v != nil { r.AddAttrs(slog.Attr{Key: string(key), Value: slog.AnyValue(v)}) } } return h.Handler.Handle(ctx, r) } func main() { logger := slog.New(&MyLogHandler{slog.NewJSONHandler(os.Stderr, nil)}) slog.SetDefault(logger) A() } func A() { ctx := context.WithValue(context.Background(), "user_id", 1) ctx = context.WithValue(ctx, "request_id", "000") B(ctx) } func B(ctx context.Context) { slog.InfoContext(ctx, "Hello, world!") }

https://go.dev/play/p/pjs7A-WNptj

slog.InfoContext(ctx, "Hello, world!")
{"time":"2009-11-10T23:00:00Z","level":"INFO","msg":"Hello, world!","user_id":1,"request_id":"000"}

というログが書き出されます。

任意のkeyでもログに書けるようなHandler

先ほどの手法では、ログに書き出したいcontextのフィールドのリストを定義しておく必要があります。しかし、ログに書き出したいものが増えるたびにリストを編集するのは大変だし、そもそもloggerという存在がアプリケーションの内部のことを知っている(たとえばrequest_idというログに書き出したい存在がいること)ように見えて微妙な感じがします。

contextにsync.Mapを持ち、その中身をログに書くHandler

ログに書き出したいcontextのkeyを1つ1つ管理しなくても良い手法として、contextにmapを持ってしまい、handlerとしてはmapの中身を全部書き出してしまうやり方があります。mapのキーだけ決めてしまえば良いです。

  • user_id <- このキーをログに出すと管理

  • request_id <- このキーをログに出すと管理

という構造だったのが、

  • user_id

  • request_id

  • その他なんでも

という構造になるイメージです。

ただし、goroutine safeになるようにただのmapではなくsync.Mapを使うと良いでしょう。実際にこの指針で実装されたslog HandlerがGitHubで公開されています。

github.com

2024-05-22 追記:上記slog-contextの実装は、親のcontextに入っているmapを子から破壊する実装になっていました。issueとPRが出ていたのでそのうち直されるかも WithValue on contex with existing fields affects the parent context · Issue #5 · PumpkinSeed/slog-context

OpenTelemetry Baggageの中身をログに書くHandler

また、ログに書き出したいものの置き場としてOpenTelemetryのBaggageを利用するのも手です。

opentelemetry.io

Baggageはテレメトリのためのコンテキスト情報をspan(service)をまたいでも伝達するためのキーバリューストアです。Baggageの基本的な使い方として挙げられるのは、下流のサービスに上流のサービスのコンテキスト情報(何らかのIDとか)を受け渡し、下流のサービスではBaggageから値を取り出してspanのattributeに追加する、といった流れです。Baggageに入れるのはテレメトリに付与したい情報なので、その中身をログに書きだしても大抵は不都合がないでしょう。

OpenTelemetry Baggageをcontextから取り出してログに書くslog handlerについても、すでにサードパーティの実装があります。Baggageの中身だけでなくトレースIDもログレコードに付与してくれるので、ログとトレースを紐づけたいときにとても便利です。

まとめ

典型的なWebアプリケーションにおいて、「ここだけはJSONログにしたい」など複数のslog handlerを併用したいことは少ないと感じています。やりたいのは高々ログに付与する属性を制御したい程度でしょう。その役割はcontextの中身を見てよしなにするリッチなhandlerに任せることで、リクエストごとにloggerインスタンスを作る必要がなくなります。リクエストごとloggerが作られないのなら、頑張って引き回す必要もなくなり、デフォルトのloggerに登録しておけばどこでもslog packageから呼び出してシンプルにログを書き出すことができます。Webアプリケーションのloggerとしてはこの考え方で十分実用に適うと思います。

*1:https://github.com/golang/go/blob/66d34c7d08d7c536c3165dc49ed318e73ea5acc2/src/log/slog/logger.go#L61-L74

Software Engineer, Audio Engineer & PTCG Player. Tech Lead & Product Owner, Mackerel Dev, Hatena Co., Ltd.

  • Website

  • GitHub: @Arthur1

  • Presentations

  • PHPerKaigi 2026で「PHP 7.4でもOpenTelemetryゼロコード計装がしたい!」という発表をしました

  • 【2026年最新改良版】Google SlideからSpeakerDeckに上げるPDFを品質良く文字化けさせず作る方法

  • GitHub ActionsのDockerのバージョンアップにより、ビルドしたコンテナをLambdaにデプロイするときに失敗するようになったかもしれない

  • OpenTelemetryコレクターのOTLP Exporterをotlpではなくotlp_grpcとして呼ぶように変わる話(そしてそのうち他のコンポーネントでも……)

  • Recap 2025

  • 男女5名のコミュニティリーダーが語る、エンジニア×ネイルアートの魅力──キラキラエンジニアへの道は輝く指先から!|CodeZine(コードジン)

  • 新卒研修として開発した「はてなピアスター」がSlack活用アワードで優勝しました | Hatena Developer Blog

  • MackerelはOpenTelemetry対応のための開発を進めています - Mackerel Meetup復活記念連載 #1 | Mackerel お知らせ #mackerelio

  • AWS JumpStart for NewGradsで、はてな新卒エンジニアがクラウドアーキテクチャ設計に取り組んできた | Hatena Developer Blog

  • 2026 / 3

  • 2026 / 2

  • 2026 / 1

  • 2025 / 12

  • 2025 / 11

  • 2025 / 10

  • 2025 / 9

  • 2025 / 8

  • 2025 / 7

  • 2025 / 6

  • 2025 / 5

  • 2025 / 4

  • 2025 / 3

  • 2025 / 2

  • 2025 / 1

  • 2024 / 12

  • 2024 / 11

  • 2024 / 10

  • 2024 / 9

  • 2024 / 8

  • 2024 / 7

  • 2024 / 6

  • 2024 / 5

  • 2024 / 4

  • 2024 / 3

  • 2024 / 2

  • 2024 / 1

  • 2023 / 12

  • 2023 / 11

  • 2023 / 10

  • 2023 / 9

  • 2023 / 8

  • 2023 / 7

  • 2023 / 6

  • 2023 / 5

  • 2023 / 4

  • 2023 / 3

  • 2023 / 2

  • 2023 / 1

  • 2022 / 12

  • 2022 / 11

  • 2022 / 10

  • 2022 / 9

  • 2022 / 8

  • 2022 / 7

  • 2022 / 6

  • 2022 / 5

  • 2022 / 4

引用をストックしました

引用するにはまずログインしてください

引用をストックできませんでした。再度お試しください

限定公開記事のため引用できません。

要点

  • Goの実装・設計・標準的な書き方を面接や実務の深掘り材料にする。
  • トレーシング、メトリクス、可観測性の説明材料として使う。
  • 元URL: https://blog.arthur1.dev/entry/2024/05/18/212731

タグ

go #go/context #observability #opentelemetry #web-clip