こちらはラクス Advent Calendar 2023の17日目の記事になります。
はじめに
Go 1.21より、標準パッケージとしてlog/slogパッケージが追加されました。
自己学習も兼ねて、このlog/slogパッケージの使い方について簡単にまとめたいと思います。
この記事はGo 1.21.4時点でのコードを元に記述しています。
slogの概要
log/slogパッケージは、構造化されたロギングを実行するロガーを提供するパッケージで、
Go1.21より標準パッケージに追加されました。
ログレコードは時間、メッセージ、ログレベルに加え、任意のキー/値のペアによって構成されます。
シンプルなログ出力
log/slogにはログレベルを指定してシンプルにログを出力する関数が定義されています。
例として、INFOレベルのログを出力してみます。
package main
import "log/slog"
func main() {
slog.Info("Hello, World!", "foo", "bar", "hoge", "fuga")
}
実行結果として、以下のような形式のログが標準出力されます。
実行日時 ログレベル ログメッセージ キー/値ペアのリスト
$ go run main.go
2023/12/16 23:09:04 INFO Hello, World! foo=bar hoge=fuga
ログレベルを指定する関数は以下4種類です。
Debug(msg string, args ...any)Info(msg string, args ...any)Warn(msg string, args ...any)Error(msg string, args ...any)
これらの関数はslogパッケージで宣言されているデフォルトのロガーから作成されたslog.Logger型の変数のメソッドを呼び出しています。
例えば、Info(msg string, args ...any)は内部的には*Loggerのレシーバメソッドであるfunc (l *Logger) Info(msg string, args ...any)を呼び出しています。
ログ出力形式を変更する
デフォルトの出力形式から変更する場合、slog.Loggerが内部的に保持しているハンドラを置き換える必要があります。
slogパッケージで提供されているハンドラはTextHandlerとJSONHandlerの2種類になります。
ハンドラはslog.New(h Handler)関数でLoggerを生成することで置き換え可能です。
TextHandler
TextHandlerはtime, level, msgキーを付与したログを出力します。
また、timeはRFC3339形式でミリ秒までの出力となります。
package main
import (
"log/slog"
"os"
)
func main() {
logger := slog.New(slog.NewTextHandler(os.Stdout, nil))
logger.Info("Hello, World!", "foo", "bar", "hoge", "fuga")
}
$ go run main.go
time=2023-12-16T23:31:56.723+09:00 level=INFO msg="Hello, World!" foo=bar hoge=fuga
JSONHandler
JSONHandlerはTextHandlerと同じくtime, level, msgキーを付与した上で、JSON形式でログを出力します。
また、timeの値の出力形式がRFC3339形式でナノ秒までの出力となります。
package main
import (
"log/slog"
"os"
)
func main() {
logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
logger.Info("Hello, World!", "foo", "bar", "hoge", "fuga")
}
$ go run main.go
{"time":"2023-12-16T23:56:48.437291886+09:00","level":"INFO","msg":"Hello, World!","foo":"bar","hoge":"fuga"}
デフォルトのロガーの更新
デフォルトのロガーを置き換えたい場合はslog.SetDefault(l *Logger)関数を使います。
以下は、JSONHandlerをデフォルトのロガーとして置き換えた場合の例です。
package main
import (
"log/slog"
"os"
)
func main() {
logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
slog.SetDefault(logger)
// デフォルトロガーを使ってInfoレベルのログを出力
slog.Info("Hello, World!", "foo", "bar")
slog.Info("Hello, Japan!", "hoge", "fuga")
}
$ go run main.go
{"time":"2023-12-17T00:13:24.043539852+09:00","level":"INFO","msg":"Hello, World!","foo":"bar"}
{"time":"2023-12-17T00:13:24.043606469+09:00","level":"INFO","msg":"Hello, Japan!","hoge":"fuga"}
共通の属性を複数のログに付与する
複数のログに対して共通のログを付与する場合、全てのログ出力時に同じキー/値のペアを与えていくのは冗長です。
その場合はLoggerのWithメソッドを使うことで共通化することができます。
package main
import (
"log/slog"
"os"
)
func main() {
logger := slog.New(slog.NewJSONHandler(os.Stdout, nil)).With("url", "https://example.com")
// url属性は付与しない
logger.Info("Hello, World!", "foo", "bar")
logger.Info("Hello, Japan!", "hoge", "fuga")
}
# url属性が付与されている
$ go run main.go
{"time":"2023-12-17T00:18:09.990452722+09:00","level":"INFO","msg":"Hello, World!","url":"https://example.com","foo":"bar"}
{"time":"2023-12-17T00:18:09.990524639+09:00","level":"INFO","msg":"Hello, Japan!","url":"https://example.com","hoge":"fuga"}
出力するログレベルの設定
デフォルトだとINFOレベル以上のログが出力されます。
それ以下のログレベル（デフォルトで用意されているのはDEBUGログ）を出力する場合は、
HandlerOptionsのLevelフィールドを変更する必要があります。
package main
import (
"log/slog"
"os"
)
func main() {
var debugLevel = new(slog.LevelVar)
debugLevel.Set(slog.LevelDebug)
infoLogger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
debugLogger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: debugLevel}))
// Debugログ出力
infoLogger.Debug("InfoLogger Debug")
debugLogger.Debug("DebugLogger Debug")
}
# debugLoggerのログのみ出力される
$ go run main.go
{"time":"2023-12-17T00:33:12.173001185+09:00","level":"DEBUG","msg":"DebugLogger Debug"}
属性の階層化
属性を階層化する場合はslog.Group(key string, args ...any)関数を使用します。
これまでの単純なstringのキー/値ペア同様、WithメソッドやInfoメソッドに直接引数として渡すことができます。
package main
import (
"log/slog"
"os"
)
func main() {
// リクエスト情報
req := slog.Group("request", "method", "GET", "url", "https://example.com")
// Withで共通属性を付与
logger := slog.New(slog.NewJSONHandler(os.Stdout, nil)).With(req)
// 多段の階層構造
attrs := slog.Group("attrs", slog.Group("attr1", "hoge", "fuga"), slog.Group("attr2", "hoge", "fuga"))
// Infoメソッドに直接渡す
logger.Info("Hello, World!", attrs)
}
$ go run main.go
{"time":"2023-12-17T00:57:13.665926599+09:00","level":"INFO","msg":"Hello, World!","request":{"method":"GET","url":"https://example.com"},"attrs":{"attr1":{"hoge":"fuga"},"attr2":{"hoge":"fuga"}}}
ちなみにTextHandlerを使う場合は以下のように出力されます。
time=2023-12-17T01:01:40.161+09:00 level=INFO msg="Hello, World!" request.method=GET request.url=https://example.com attrs.attr1.hoge=fuga attrs.attr2.hoge=fuga
キー/値をAttr型で指定する
slog.Attr型は属性のキー/値を表す型で、以下のように定義された構造体です。
type Attr struct {
Key string
Value Value
}
例えばキー/値を別々の引数として渡していた部分を以下のように書き換えることができます。
slog.String(key, value string)関数はslog.Attr型を返却します。
// Before
logger.Info("Hello, World!", "hoge", "fuga")
// After
logger.Info("Hello, World!", slog.String("hoge", "fuga"))
String以外にも、Int, Bool, Any等のAttrのコンストラクタ関数があります。
また、前述したslog.Group(key string, args ...any)関数もAttrを返却しています。
Contextから取り出した値をロギング
各種ロギング関数には、context.Context型の引数を取る別名関数が準備されています。
例えば、Info(msg string, args ...any)関数に対して、
第一引数にcontext.Contextを取るInfoContext(ctx context.Context, msg string, args ...any)関数が準備されています。
この関数の主な使用目的は、例えばトレースID等、ctxで引き回す値をロギング時に使用することです。
ただし、context.WithValue(ctx, key, val)でセットされたキー/値を自動的に取り出してくれる類の関数ではないので、
必要な値を取得する処理は自作する必要があります。
以下は、トレースIDを取得する自作のTraceHandlerです。
context.Contextから"traceID"というキーでセットされた値を取得してログレコードに属性として追加するよう、Handleメソッドを実装しています。
package main
import (
"context"
"log/slog"
)
type key struct{}
var traceIDKey = key{}
type TraceHandler struct {
slog.Handler
}
func NewTraceHandler(h slog.Handler) *TraceHandler {
return &TraceHandler{h}
}
func (h *TraceHandler) Handle(ctx context.Context, r slog.Record) error {
r.AddAttrs(slog.String("traceID", ctx.Value(traceIDKey).(string)))
return h.Handler.Handle(ctx, r)
}
main処理ではslog.New関数にTraceHandlerを渡しています。
package main
import (
"context"
"log/slog"
"os"
)
func main() {
ctx := context.WithValue(context.Background(), traceIDKey, "1234567890")
logger := slog.New(NewTraceHandler(slog.NewJSONHandler(os.Stdout, nil)))
logger.InfoContext(ctx, "Hello, World!")
}
実行結果にはtraceIDが含まれています。
$ go run main.go trace_handler.go
{"time":"2023-12-17T01:46:24.252425848+09:00","level":"INFO","msg":"Hello, World!","traceID":"1234567890"}
秘密情報をマスクする
パスワード等の秘密情報をそのままログ出力したくない場合は、
該当する型に以下のslog.LogValuerインターフェースを実装します。
type LogValuer interface {
LogValue() Value
}
stringの拡張型であるPassword型を定義して、slog.LogValuerを実装します。
package main
import "log/slog"
type Password string
func (p Password) LogValue() slog.Value {
return slog.StringValue("********")
}
ロギング処理は以下のように実装します。
package main
import (
"log/slog"
"os"
)
func main() {
logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
logger.Info("Hello, World!", slog.Any("password", Password("secret")))
}
実行結果を見ると、passwordがマスクされていることが分かります。
$ go run main.go password.go
{"time":"2023-12-17T01:55:29.979530405+09:00","level":"INFO","msg":"Hello, World!","password":"********"}
おわりに
簡単にではありますが、今回はlog/slogパッケージの使用方法をまとめてみました。
今後触る機会が増えるかと思うので、実践で更に使い方を身に着けていきたいと思います。
それでは、少し早いですがメリークリスマス！