Slide 1

Slide 1 text

slog登場に伴う loggerの取り回し手法の見直し id:arthur-1 株式会社はてな 2024-05-17 kamakura.go #6 1

Slide 2

Slide 2 text

Arthurと申します 株式会社はてな アプリケーションエンジニア ポケカの練習仲間が欲しい 𝕏: @Arthur1__ 2

Slide 3

Slide 3 text

Mackerel作ってます 3

Slide 4

Slide 4 text

前置き このトークは2024-06-08に開催されるGo Conference 2024にProposalを出していたものです(落選) 4

Slide 5

Slide 5 text

log/slog使ってますか? 5

Slide 6

Slide 6 text

log/slog packageとは 6 log/slog Go 1.21〜追加されたビルトインのログパッケージ 構造化ログが扱えるなどの進化を遂げた Proposal: https://go.googlesource.com/proposal/+/master/design/5 6345-structured-logging.md

Slide 7

Slide 7 text

お品書き ● slog登場以前のログ事情 ○ loggerの引き回しと、なぜそれが必要なのか ● slog登場後のログ ○ loggerは共通でもある程度上手くやっていけるよと いう話 7

Slide 8

Slide 8 text

slog登場以前の ログ事情 8

Slide 9

Slide 9 text

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

Slide 10

Slide 10 text

構造化ログのフィールド 10 あるアプリケーション・モジュールのログについて、 常に特定のフィールドを付与したいというニーズ (例)Webアプリケーションなら ● モジュール名 ● リクエストID ● ユーザID

Slide 11

Slide 11 text

なぜ? 11 ログの出力命令ごとにいちいちフィールドを指定しま くるのは面倒で拡張も大変だから log.WithFields(log.Fields{“module”: “userService”, “user_id”: 1}).Info(“validation passed”) … log.WithFields(log.Fields{“module”: “userService”, “user_id”: 1}).Info(“succeeded”)

Slide 12

Slide 12 text

loggerの引き回し 12 アプリケーションやモジュールごとにloggerインスタンスを 作り、呼び出し先でも利用できるように引き回す logger := log.WithFields(log.Fields{“module”: “userService”, “user_id”: 1}) logger.Info(“validation passed”) … logger.Info(“succeeded”)

Slide 13

Slide 13 text

loggerの引き回し手法 13 loggerのインスタンスを作り、それを他の関数などから参照 できるようにする方法はいくつかある ● グローバル変数にloggerを入れる ● 関数の引数にloggerを入れる ● 構造体のフィールドにloggerを入れる ● contextにloggerを入れる

Slide 14

Slide 14 text

グローバル変数にloggerを入れる 14 Pros ● 簡単最速 Cons ● リクエストごとのloggerを作れない ○ Webアプリケーションは並列でリクエストを処理する var Logger = log.WithFields(log.Fields{“module”: “userService”}) func Hoge() { Logger.Info(“Hello, world.”) }

Slide 15

Slide 15 text

関数の引数にloggerを入れる 15 func A() { logger := log.WithFields(log.Fields{“user-id”: 1}) B(logger) } func B(logger Logger) { logger.Info(“Hello, world.”) }

Slide 16

Slide 16 text

関数の引数にloggerを入れる 16 Pros ● リクエストごと関数が呼ばれるならば、リクエストごとに作っ たloggerを引き回せる Cons ● ログを出したい関数全てで引数が増える ○ バケツリレーを頑張る必要あり ○ 急にログを出したくなるといちいち関数のシグネチャが変 わってしまう

Slide 17

Slide 17 text

構造体のフィールドに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”) }

Slide 18

Slide 18 text

構造体のフィールドにloggerを入れる 18 Pros ● その構造体がリクエストごと生成されるならば、リクエストご とのloggerを置く場所として利用できる Cons ● その構造体のレシーバでなければloggerを利用できない ● ジェネリクスを使いたい時など、どうしてもレシーバにできな いこともある ● 超える際には明示的に別の方法で引き渡す必要がある ○ 引数にloggerを入れるのと同じ苦しみが待っている

Slide 19

Slide 19 text

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) }

Slide 20

Slide 20 text

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.”) }

Slide 21

Slide 21 text

contextにloggerを入れる 21 Pros ● contextを自然に引き渡して行けばloggerも引き回せる ● リクエストスコープでloggerを作れる。オーバーライドや継 承も可能 Cons ● ログを出したい関数の頭で、contextからloggerを取り出す コードが毎回書かれるのが煩雑

Slide 22

Slide 22 text

ここまでのまとめ 22 Go 1.21より前の時代では、 loggerインスタンスを contextに入れて引き回し、 ログを出力したいところで contextから取り出すのが良さそう

Slide 23

Slide 23 text

slogが やってきたぞ🐟 23

Slide 24

Slide 24 text

slogの新要素 24 フロントエンドのLoggerとバックエンドのHandlerと いう2つのインタフェースに分離された Handlerでは出力フォーマットを変えられるだけでな く、ログレコードに常に特定のフィールドを追加する といった処理も可能

Slide 25

Slide 25 text

slogの新要素 25 slog.InfoContext(ctx context.Context, msg string, args ...any) logger handlerは、ログ出力の際にcontextの値を利用すること ができる

Slide 26

Slide 26 text

デフォルトlogger 26 slog.SetDefault(l *Logger) デフォルトのloggerを登録しておける 大体グローバル変数に入れているのと一緒だが、複数のgoroutine から呼ばれるのを考慮してsync/atomicが内部で使われている slogだけでなくlogのデフォルト(log.Println()など)も変わ るので注意

Slide 27

Slide 27 text

気づき 27 場所によって構造化ログに自動で入れたいフィールド を変えたいという理由だけで、 loggerインスタンスを個々に作って引きまわす必要は なくなったのでは?

Slide 28

Slide 28 text

方針 28 ● contextの値を読み取って、自動でフィールドを追加 するようなlogger handlerを作る ● これを用いて生成したloggerをDefaultに登録する

Slide 29

Slide 29 text

実装例 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) }

Slide 30

Slide 30 text

実装例 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!") }

Slide 31

Slide 31 text

実行結果 https://go.dev/play/p/pjs7A-WNptj 31

Slide 32

Slide 32 text

任意のkeyを許したい 32 先ほどの例ではログに書きたいcontextのkeyのリストを用 意していた (ただのmapではなくgoroutine safeな)sync.Mapを contextに持ち、この中身を出力するlog handlerを用いる と、任意のkeyを許せて捗りそう https://github.com/PumpkinSeed/slog-context

Slide 33

Slide 33 text

Baggageの活用 33 OpenTelemetryのBaggageを出力するlog handlerを用い ても良い https://github.com/remychantenay/slog-otel trace idやspan idもログにシュッと出せて最高便利

Slide 34

Slide 34 text

Webアプリケーションでは 典型的なWebアプリケーションで「ここだけはJSONログにし たい」など、複数個のlog handlerを併用したいことは少ない やりたいのは高々フィールドを制御したいぐらいだろう とすると、これをリッチなhandlerに任せ、loggerはDefault に登録したものだけを利用するので十分実用に適う 34

Slide 35

Slide 35 text

まとめ ● slog登場より以前、構造化ログに追加したいフィールド を制御するためだけにloggerインスタンスを個々に作っ て引きまわすことがあった ● slogの仕組みに乗っかると、共通のloggerを利用するこ とが可能。DefaultだけでOK ● 実用上便利なslog handlerをいくつか紹介した 35

Slide 36

Slide 36 text

おしまい 36