slog登場に伴うloggerの取り回し手法の見直し / kamakura.go #6

https://kamakurago.connpass.com/event/316438/

ほぼ同内容のBlogはこちら: https://blog.arthur1.dev/entry/2024/05/18/212731

Transcript

1. slog登場に伴う loggerの取り回し手法の見直し id:arthur-1 株式会社はてな 2024-05-17 kamakura.go #6 1
2. Arthurと申します 株式会社はてな アプリケーションエンジニア ポケカの練習仲間が欲しい 𝕏: @Arthur1__ 2
3. Mackerel作ってます 3
4. 前置き このトークは2024-06-08に開催されるGo Conference 2024にProposalを出していたものです（落選） 4
5. log/slog使ってますか？ 5
6. log/slog packageとは 6 log/slog Go 1.21〜追加されたビルトインのログパッケージ 構造化ログが扱えるなどの進化を遂げた Proposal: https://go.googlesource.com/proposal/+/master/design/5 6345-structured-logging.md
7. お品書き • slog登場以前のログ事情 ◦ loggerの引き回しと、なぜそれが必要なのか • slog登場後のログ ◦ loggerは共通でもある程度上手くやっていけるよと いう話 7
8. slog登場以前の ログ事情 8
9. Goの構造化ログ 9 slogが登場するまで、サードパーティの構造化ログラ イブラリを各々使っていた （例） • Logrus https://github.com/sirupsen/logrus • Zap https://github.com/uber-go/zap • Zerolog https://github.com/rs/zerolog • Apex Log https://github.com/apex/log
10. 構造化ログのフィールド 10 あるアプリケーション・モジュールのログについて、 常に特定のフィールドを付与したいというニーズ （例）Webアプリケーションなら • モジュール名 • リクエストID • ユーザID
11. なぜ？ 11 ログの出力命令ごとにいちいちフィールドを指定しま くるのは面倒で拡張も大変だから log.WithFields(log.Fields{“module”: “userService”, “user_id”: 1}).Info(“validation passed”) … log.WithFields(log.Fields{“module”: “userService”, “user_id”: 1}).Info(“succeeded”)
12. loggerの引き回し 12 アプリケーションやモジュールごとにloggerインスタンスを 作り、呼び出し先でも利用できるように引き回す logger := log.WithFields(log.Fields{“module”: “userService”, “user_id”: 1}) logger.Info(“validation passed”) … logger.Info(“succeeded”)
13. loggerの引き回し手法 13 loggerのインスタンスを作り、それを他の関数などから参照 できるようにする方法はいくつかある • グローバル変数にloggerを入れる • 関数の引数にloggerを入れる • 構造体のフィールドにloggerを入れる • contextにloggerを入れる
14. グローバル変数にloggerを入れる 14 Pros • 簡単最速 Cons • リクエストごとのloggerを作れない ◦ Webアプリケーションは並列でリクエストを処理する var Logger = log.WithFields(log.Fields{“module”: “userService”}) func Hoge() { Logger.Info(“Hello, world.”) }
15. 関数の引数にloggerを入れる 15 func A() { logger := log.WithFields(log.Fields{“user-id”: 1}) B(logger) } func B(logger Logger) { logger.Info(“Hello, world.”) }
16. 関数の引数にloggerを入れる 16 Pros • リクエストごと関数が呼ばれるならば、リクエストごとに作っ たloggerを引き回せる Cons • ログを出したい関数全てで引数が増える ◦ バケツリレーを頑張る必要あり ◦ 急にログを出したくなるといちいち関数のシグネチャが変 わってしまう
17. 構造体のフィールドにloggerを入れる 17 type UserService struct { logger Logger } func NewUserService() { logger := log.WithFields(log.Fields{“user-id”: 1}) return &UserService{logger: logger} } (u *UserService) Login() { u.logger.Info(“success”) }
18. 構造体のフィールドにloggerを入れる 18 Pros • その構造体がリクエストごと生成されるならば、リクエストご とのloggerを置く場所として利用できる Cons • その構造体のレシーバでなければloggerを利用できない • ジェネリクスを使いたい時など、どうしてもレシーバにできな いこともある • 超える際には明示的に別の方法で引き渡す必要がある ◦ 引数にloggerを入れるのと同じ苦しみが待っている
19. contextにloggerを入れる 19 package mylog import “context” type key struct{} // loggerをcontextに格納 func NewContext(ctx context.Context, logger Logger) context.Context { return context.WithValue(ctx, key{}, logger) } // contextからloggerを取り出す func FromContext(ctx context.Context) Logger { return ctx.Value(key{}).(Logger) }
20. contextにloggerを入れる 20 func A() { logger := log.WithFields(log.Fields{“user-id”: 1}) ctx := mylog.NewContext(context.Background(), logger) B(ctx) } func B(ctx context.Context) { logger := mylog.FromContext(ctx) logger.Info(“Hello, world.”) }
21. contextにloggerを入れる 21 Pros • contextを自然に引き渡して行けばloggerも引き回せる • リクエストスコープでloggerを作れる。オーバーライドや継 承も可能 Cons • ログを出したい関数の頭で、contextからloggerを取り出す コードが毎回書かれるのが煩雑
22. ここまでのまとめ 22 Go 1.21より前の時代では、 loggerインスタンスを contextに入れて引き回し、 ログを出力したいところで contextから取り出すのが良さそう
23. slogが やってきたぞ🐟 23
24. slogの新要素 24 フロントエンドのLoggerとバックエンドのHandlerと いう2つのインタフェースに分離された Handlerでは出力フォーマットを変えられるだけでな く、ログレコードに常に特定のフィールドを追加する といった処理も可能
25. slogの新要素 25 slog.InfoContext(ctx context.Context, msg string, args ...any) logger handlerは、ログ出力の際にcontextの値を利用すること ができる
26. デフォルトlogger 26 slog.SetDefault(l *Logger) デフォルトのloggerを登録しておける 大体グローバル変数に入れているのと一緒だが、複数のgoroutine から呼ばれるのを考慮してsync/atomicが内部で使われている slogだけでなくlogのデフォルト（log.Println()など）も変わ るので注意
27. 気づき 27 場所によって構造化ログに自動で入れたいフィールド を変えたいという理由だけで、 loggerインスタンスを個々に作って引きまわす必要は なくなったのでは？
28. 方針 28 • contextの値を読み取って、自動でフィールドを追加 するようなlogger handlerを作る • これを用いて生成したloggerをDefaultに登録する
29. 実装例 29 var keys = []string{“user_id”, “request_id”} type MyLogHandler struct { slog.Handler } func (h *MyLogHandler) Handle(ctx context.Context, r slog.Record) error { for _, key := range keys { if v := fromContext(ctx, key); v != nil { r.AddAttrs(slog.Attr{Key: string(key), Value: slog.AnyValue(v)}) } } return h.Handler.Handle(ctx, r) }
30. 実装例 30 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!") }
31. 実行結果 https://go.dev/play/p/pjs7A-WNptj 31
32. 任意のkeyを許したい 32 先ほどの例ではログに書きたいcontextのkeyのリストを用 意していた （ただのmapではなくgoroutine safeな）sync.Mapを contextに持ち、この中身を出力するlog handlerを用いる と、任意のkeyを許せて捗りそう https://github.com/PumpkinSeed/slog-context
33. Baggageの活用 33 OpenTelemetryのBaggageを出力するlog handlerを用い ても良い https://github.com/remychantenay/slog-otel trace idやspan idもログにシュッと出せて最高便利
34. Webアプリケーションでは 典型的なWebアプリケーションで「ここだけはJSONログにし たい」など、複数個のlog handlerを併用したいことは少ない やりたいのは高々フィールドを制御したいぐらいだろう とすると、これをリッチなhandlerに任せ、loggerはDefault に登録したものだけを利用するので十分実用に適う 34
35. まとめ • slog登場より以前、構造化ログに追加したいフィールド を制御するためだけにloggerインスタンスを個々に作っ て引きまわすことがあった • slogの仕組みに乗っかると、共通のloggerを利用するこ とが可能。DefaultだけでOK • 実用上便利なslog handlerをいくつか紹介した 35
36. おしまい 36