🌲

🪵 Go1.21 log/slogパッケージ超入門

2023/07/01に公開
1

はじめに

2023年8月9日(日本の場合)Go1.21がリリースされました🎉。Go1.21ではさまざまな変更点や追加機能が加わります。その中でもGo標準ライブラリに導入される構造化ロギングパッケージlog/slog(以下、slog)を楽しみにしている方は多いのではないでしょうか?
本稿では、slogを実際に触りつつ、機能の解説をしていきます。

TL;DR

本稿の概要をスライドにもまとめているので、ご参考にして下さい。

従来のlogパッケージについて

slogの説明に入る前に、Go標準のlogパッケージについて簡単に紹介する。logパッケージを用いると、 io.Writer インターフェースを実装する任意の型にログメッセージを書き込むことができる。しかし以下のような制限があった。

  • ログレベルをサポートしていない
    • ログレベルはほとんどのログパッケージの定番機能の一つだが、logパッケージにはない。すべてのログメッセージが同じように扱われるため、重要度に基づいてログメッセージをフィルタリングしたり、分離したりすることが難しい。
  • 構造化ロギングをサポートしていない
    • logパッケージはプレーンテキストメッセージしか出力しない。JSON形式での出力ができないので、ログの調査や分析が行いにくい。
  • コンテキストを意識したロギングをサポートしていない
    • logパッケージはコンテキストを意識したロギングをサポートしないため、ログメッセージにコンテキスト情報(リクエストID、ユーザーID、その他の変数など)を自動的に付与することが難しい。
  • ログのサンプリングをサポートしていない
    • ログのサンプリングは、高スループットのアプリケーションでログの量を減らすのに便利である。サードパーティのロギングライブラリは、しばしばこの機能を提供するが、 logパッケージにはない。
  • 設定オプションが豊富でない
    • logパッケージは、ログの出力先や接頭辞の設定など、基本的な設定オプションしかサポートしていない。高度なロギングライブラリは、カスタムログフォーマット、フィルタリング、コンテキストデータの自動追加、非同期ロギングの有効化、エラー処理動作など、より多くの設定を提供している。

上記のような制限があったため、zaplogruszerologといったサードパーティーライブラリを利用する必要があった。そのため、アプリケーションごとに使用しているロギングライブラリが異なり、出力の一貫性がないなどの問題もあった。

Go1.21では、このような制限を解消すべく、slogと呼ばれる新しいロギングパッケージが導入される予定である。また、こちらにあるように、開発者は既存のサードパーティーライブラリの置き換えを期待しているわけではなく、当面の間は共存することを期待している。

slogパッケージについて

slog(structured logging, 読み方はスロッグ)パッケージは、Jonathan Amsterdamによって開かれたDiscussion #54763が元になっており、その後 Proposal #56345 につながっている。デザインドキュメントはこちら。最終的な実装はlog/slogに置かれる。それまでは、golang.org/x/exp/slogに試験的な実装が置かれている。

以下のコマンドでダウンロードできる。

go get golang.org/x/exp/slog@latest

slogの目標

デザインドキュメントには以下のような記載がある。

The goals of this design are:

  • Ease of use. A survey of the existing logging packages shows that programmers want an API that is light on the page and easy to understand. This proposal adopts the most popular way to express key-value pairs: alternating keys and values.
  • High performance. The API has been designed to minimize allocation and locking. It provides an alternative to alternating keys and values that is more cumbersome but faster (similar to Zap's Fields).
  • Integration with runtime tracing. The Go team is developing an improved runtime tracing system. Logs from this package will be incorporated seamlessly into those traces, giving developers the ability to correlate their program's actions with the behavior of the runtime.

ref. https://go.googlesource.com/proposal/+/master/design/56345-structured-logging.md

  • 使いやすさ
  • 高パフォーマンス
  • 実行トレースとの統合

である。

アーキテクチャ


アーキテクチャの概略図(ref. https://youtu.be/gd_Vyb5vEw0?t=262)

デザインドキュメントにも記載の通り、slogには3つの主要なタイプがある。

  • Logger : slogの「フロントエンド」。InfoLogAttrs のような、開発者がログを生成するために呼び出す出力メソッドを提供する。

    type Logger struct {
        handler Handler
    }
    
  • Record : Logger 出力メソッドを呼び出すごとに作成されるログレコード。

    type Record struct {
        Time time.Time
        Message string
        Level Level
        PC uintptr
        front [nAttrsInline]Attr
        nFront int
        back []Attr
    }
    
  • Handler : slogの「バックエンド」。Record が渡され、フォーマットと出力先を決定する。slogでは TextHandlerJSONHandler が提供されている。

    type Handler interface {
        Enabled(context.Context, Level) bool
        Handle(context.Context, Record) error
        WithAttrs(attrs []Attr) Handler
        WithGroup(name string) Handler
    }
    

例えば、以下の関数を実行してログレベルがINFOのログをJSON形式で標準出力する場合を考える。

func main() {
    logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
    logger.Info("Info message")
}

この場合、

  1. slog.New でまずLoggerが生成される。
  2. 次に、 slog.Info が呼び出され、関数内部で Record が生成され、Handler に渡される。
  3. 最終的に、Handler によって、ログが出力される。

という流れになる。1で slog.NewJSONHandler(os.Stdout, nil) から Logger の生成をしているので、標準出力にJSON形式でログが出力される。

ここで、Handler はインターフェースなので、インターフェースを満たすようなハンドラーを作ってあげればslogの「バックエンド」として用いることができる(後ほど解説)。

ロガーの解説

ロガーの概要

slogでは、パッケージのトップレベル関数からアクセスできるデフォルトのロガーを提供している。
デフォルトロガーではログレベルがINFO以上のログがプレーンテキストで標準出力される。

func main() {
    slog.Debug("Debug message")
    slog.Info("Info message")
    slog.Warn("Warning message")
    slog.Error("Error message")
}
結果
2023/07/01 13:04:56 INFO Info message
2023/07/01 13:04:56 WARN Warning message
2023/07/01 13:04:56 ERROR Error message

slog.New() でカスタムロガーを作成できる。ハンドラーを指定してあげることで、ログのフォーマットや、出力先を指定することができる。例えば、以下はJSON形式でログを標準出力する例である。この場合も、ログレベルがINFO以上のログのみ出力される。

func main() {
    logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
    slog.Info("Info message") // デフォルトロガーが適用されるため、プレーンテキストで出力される。
    logger.Debug("Debug message")
    logger.Info("Info message")
    logger.Warn("Warning message")
    logger.Error("Error message")
}
結果
2023/07/01 13:06:23 INFO Info message
{"time":"2023-07-01T13:06:23.326683+09:00","level":"INFO","msg":"Info message"}
{"time":"2023-07-01T13:06:23.326698+09:00","level":"WARN","msg":"Warning message"}
{"time":"2023-07-01T13:06:23.326701+09:00","level":"ERROR","msg":"Error message"}

ハンドラーを次のように変更すると、出力がプレーンテキストになる。

logger := slog.New(slog.NewTextHandler(os.Stdout, nil))
結果
2023/07/01 13:07:13 INFO Info message
time=2023-07-01T13:07:13.397+09:00 level=INFO msg="Info message"
time=2023-07-01T13:07:13.397+09:00 level=WARN msg="Warning message"
time=2023-07-01T13:07:13.397+09:00 level=ERROR msg="Error message"

ロガーのカスタマイズ

自身で指定したカスタムロガーをデフォルトロガーとして扱いたい場合、 slog.SetDefault を用いることで実現できる。

func main() {
    logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
    slog.SetDefault(logger) // 以降、JSON形式で出力される。

    slog.Info("Info message")
    log.Println("log message by old logger")
}
結果
{"time":"2023-07-01T13:07:34.43201+09:00","level":"INFO","msg":"Info message"}
{"time":"2023-07-01T13:07:34.432185+09:00","level":"INFO","msg":"log message by old logger"}

こうすることで、slogパッケージのトップレベルのロギング関数( slog.Info など)がJSON形式で出力されるようになる。さらに、従来のlogパッケージの関数による出力にもカスタマイズが適用される

また、 slog.NewLogLogger() を用いることで、 slog.Logger から log.Logger を作成することができる。これによって、従来の log.Logger を使用している箇所にも slog.Logger を適用できるようになる。

func main() {
    handler := slog.NewJSONHandler(os.Stdout, nil)

    infoLog := slog.NewLogLogger(handler, slog.LevelInfo)
    WarningLog := slog.NewLogLogger(handler, slog.LevelWarn)
    errorLog := slog.NewLogLogger(handler, slog.LevelError)

    infoLog.Println("Something has occurred...")
    WarningLog.Println("Warning!...")
    errorLog.Println("error has occurred")
}
結果
{"time":"2023-07-01T13:09:28.084509+09:00","level":"INFO","msg":"Something has occurred..."}
{"time":"2023-07-01T13:09:28.084648+09:00","level":"WARN","msg":"Warning!..."}
{"time":"2023-07-01T13:09:28.084652+09:00","level":"ERROR","msg":"error has occurred"}

key=valueペアでログ情報を追加

slogでは、ログメッセージの後に、追加情報をkey=valueのペアで登録可能である。

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))

	logger.Info(
		"structured logger message",
		"id", 1,
		"method", "GET",
		"path", "/v1/users",
		"status", 200,
	)
}

結果
{"time":"2023-07-01T13:10:52.849883+09:00","level":"INFO","msg":"structured logger message","id":1,"method":"GET","path":"/v1/users","status":200}

ここで、不適切なペアを登録してみる。そうすると、 !BADKEY がkey、 status がvalueとして扱われてしまう。

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))

	logger.Info(
		"structured logger message",
		"id", 1,
		"method", "GET",
		"path", "/v1/users",
		"status", // keyであるstatusに対するvalueが無い
	)
}

結果
{"time":"2023-07-01T13:11:23.175974+09:00","level":"INFO","msg":"structured logger message","id":1,"method":"GET","path":"/v1/users","!BADKEY":"status"}

このように、key=valueペアをリテラルで書いてしまうと、予期しないログメッセージが出力されてしまう。以下のように、 slog.Attr 型を返す関数を用いてログを生成するのがよい。さらに、こうすることでパフォーマンスが良くなる。

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
	slog.SetDefault(logger)
	slog.LogAttrs(
		context.Background(),
		slog.LevelInfo,
		"structured logger message",
		slog.Int("id", 1),                // 内部でslog.Attr型に変換されている
		slog.String("method", "GET"),     // 内部でslog.Attr型に変換されている
		slog.String("path", "/v1/users"), // 内部でslog.Attr型に変換されている
		slog.Int("status", 200),          // 内部でslog.Attr型に変換されている
	)
}

結果
{"time":"2023-07-01T13:12:30.396675+09:00","level":"INFO","msg":"structured logger message","id":1,"method":"GET","path":"/v1/users","status":200}

子ロガー

slogでは、すべてのレコードに同じ属性を含めることもできる。

func main() {
    logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))

    child := logger.With(
        slog.String("id", "1"),
    )

    child.Info("Info message")
    child.Warn("Warn message")
}
結果
{"time":"2023-07-01T13:13:06.106638+09:00","level":"INFO","msg":"Info message","id":"1"}
{"time":"2023-07-01T13:13:06.106776+09:00","level":"WARN","msg":"Warn message","id":"1"}

グルーピング

slogには、複数のログ情報を一つの名前でグルーピングできる機能がある。

例えば、Handlerとして JSONHandler を用いる場合、以下のようにネストされたJSONが出力される。

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))

	logger.Info(
		"nest json",
		slog.Int("id", 1),
		slog.Group("nest1",
			slog.Int("key1", 1000),
			slog.Int("key2", 2000),
		),
	)
}

結果
{"time":"2023-07-01T13:15:54.955404+09:00","level":"INFO","msg":"nest json","id":1,"nest1":{"key1":1000,"key2":2000}}

また、Handlerとして TextHandler を用いる場合、以下のように接頭辞が付与される。

func main() {
	logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

	logger.Info(
		"nest json",
		slog.Int("id", 1),
		slog.Group("nest1",
			slog.Int("key1", 1000),
			slog.Int("key2", 2000),
		),
	)
}
結果
time=2023-07-01T13:15:37.259+09:00 level=INFO msg="nest json" id=1 nest1.key1=1000 nest1.key2=2000

出力結果のカスタマイズ

slogでは、 LogValuerインターフェースを満たす実装をすることで、出力結果をカスタマイズできる。例えば、読み込んだ環境変数をログに出すユースケースを考える。ログに残したくない値(例えばPASSWORD)があるとする。


var (
	logger = slog.New(slog.NewJSONHandler(os.Stdout, nil))
)

type MysqlConfig struct {
	User     string
	PassWord string
	Addr     string
	DBName   string
}

func loadMySQLConfig() *MysqlConfig {
	conf := &MysqlConfig{
		User:     os.Getenv("USER"),
		PassWord: os.Getenv("PASSWORD"),
		Addr:     os.Getenv("ADDRESS"),
		DBName:   os.Getenv("DB_NAME"),
	}
	logger.Info("env info", "mysql config", conf)
	return conf
}

func main() {
	os.Setenv("USER", "John")
	os.Setenv("PASSWORD", "password")
	os.Setenv("ADDRESS", "3306")
	os.Setenv("DB_NAME", "sample_db")

	slog.SetDefault(logger)

	_ = loadMySQLConfig()
}
結果
{"time":"2023-07-01T13:20:34.761846+09:00","level":"INFO","msg":"env info","mysql config":{"User":"John","PassWord":"password","Addr":"3306","DBName":"sample_db"}}

上記の実装だと、隠蔽したい環境変数(PASSWORD)が出力されてしまうので、LogValuer インターフェースを実装してログの出力をカスタマイズしてあげる。

var (
    logger = slog.New(slog.NewJSONHandler(os.Stdout, nil))
)

type MySQLConfig struct {
    User     string
    PassWord string
    Addr     string
    DBName   string
}

// 追加
func (c *MySQLConfig) LogValue() slog.Value {
    return slog.GroupValue(
    slog.String("user", c.User),
    slog.String("password", strings.Repeat("*", len(c.PassWord))),
    slog.String("address", c.Addr),
    slog.String("db_name", c.DBName),
    )
}

func loadMySQLConfig() *MySQLConfig {
    conf := &MySQLConfig{
    User:     os.Getenv("USER"),
    PassWord: os.Getenv("PASSWORD"),
    Addr:     os.Getenv("ADDRESS"),
    DBName:   os.Getenv("DB_NAME"),
    }
    logger.Info("env info", "mysql config", conf)
    return conf
}

func main() {
    os.Setenv("USER", "John")
    os.Setenv("PASSWORD", "password")
    os.Setenv("ADDRESS", "3306")
    os.Setenv("DB_NAME", "sample_db")

    slog.SetDefault(logger)

    _ = loadMySQLConfig()
}
結果
{"time":"2023-06-29T19:57:14.784366+09:00","level":"INFO","msg":"env info","mysql config":{"user":"John","password":"********","address":"3306","db_name":"sample_db"}}

ハンドラーの解説

ハンドラーオプション

上記でも、少しふれたが slogでは TextHandlerJSONHandler がハンドラーとして提供されている。それぞれ、第2引数に HandlerOptions を設定することで、ハンドラーの出力をカスタマイズできる。HandlerOptions は次のような構造体になっており、 AddSource でソースコード上でのlogステートメント場所をログに含めるか否かを設定でき、 Level では出力すべき最小のログレベルの設定、 ReplaceAttr ではログのkey=valueペアのカスタマイズ設定が可能である。

type HandlerOptions struct {
    AddSource bool
    Level Leveler
    ReplaceAttr func(groups []string, a Attr) Attr
}
func main() {
	ops := slog.HandlerOptions{
		AddSource: true,
		Level:     slog.LevelDebug,
		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
			if a.Key == "msg" && a.Value.String() == "Debug message" {
				a.Value = slog.StringValue("New Debug message")
			}
			return a
		},
	}
	logger := slog.New(slog.NewJSONHandler(os.Stdout, &ops))
	slog.Info("Info message")
	logger.Debug("Debug message")
	logger.Info("Info message")
	logger.Warn("Warning message")
	logger.Error("Error message")
}

結果
2023/07/01 13:23:39 INFO Info message
{"time":"2023-07-01T13:23:39.95628+09:00","level":"DEBUG","source":{"function":"main.main","file":"/Users/kota/sandbox/slog-study/main.go","line":22},"msg":"New Debug message"}
{"time":"2023-07-01T13:23:39.956375+09:00","level":"INFO","source":{"function":"main.main","file":"/Users/kota/sandbox/slog-study/main.go","line":23},"msg":"Info message"}
{"time":"2023-07-01T13:23:39.956393+09:00","level":"WARN","source":{"function":"main.main","file":"/Users/kota/sandbox/slog-study/main.go","line":24},"msg":"Warning message"}
{"time":"2023-07-01T13:23:39.956399+09:00","level":"ERROR","source":{"function":"main.main","file":"/Users/kota/sandbox/slog-study/main.go","line":25},"msg":"Error message"}

ログレベル

ログレベルについて補足すると、上記ではロガーを生成した時点で、ログレベルがDEBUGに固定されてしまうが、以下のようにすることで、ロガー生成以降でも動的にログレベルを変更できる。

func main() {
	logLevel := new(slog.LevelVar)
	ops := slog.HandlerOptions{
		Level: logLevel,
	}

	logger := slog.New(slog.NewJSONHandler(os.Stdout, &ops))
	// INFO 以上が出力される
	logger.Debug("Debug message")
	logger.Info("Info message")
	logger.Warn("Warning message")
	logger.Error("Error message")

	// いつでもログレベルを変えられる。
	logLevel.Set(slog.LevelDebug) // set log level as DEBUG.

	// DEBUG 以上が出力される
	logger.Debug("Debug message")
	logger.Info("Info message")
	logger.Warn("Warning message")
	logger.Error("Error message")
}

結果
{"time":"2023-07-01T13:24:28.99944+09:00","level":"INFO","msg":"Info message"}
{"time":"2023-07-01T13:24:28.999585+09:00","level":"WARN","msg":"Warning message"}
{"time":"2023-07-01T13:24:28.999588+09:00","level":"ERROR","msg":"Error message"}
{"time":"2023-07-01T13:24:28.999591+09:00","level":"DEBUG","msg":"Debug message"}
{"time":"2023-07-01T13:24:28.999593+09:00","level":"INFO","msg":"Info message"}
{"time":"2023-07-01T13:24:28.999595+09:00","level":"WARN","msg":"Warning message"}
{"time":"2023-07-01T13:24:28.999597+09:00","level":"ERROR","msg":"Error message"}

slogでは4つのログレベルが提供されており、4つのログレベルそれぞれに、整数が対応付けられている。

const (
    LevelDebug Level = -4 // DEBUG
    LevelInfo  Level = 0  // INFO
    LevelWarn  Level = 4  // WARN
    LevelError Level = 8  // ERROR
)

各ログレベルに対応する整数が飛び飛びの値になっているが、これは、slogの使用者が独自のログレベルを定義して、拡張できるようにするためである。例えば、ログレベルNOTICEを使用したい場合、 INFOとWARNの間の1~3のいずれかを割り当てることができる。試しに2を割り当ててみる。

const (
	LevelNotice = slog.Level(2)
)

func main() {
	opts := &slog.HandlerOptions{
		Level: slog.LevelInfo,
	}

	logger := slog.New(slog.NewJSONHandler(os.Stdout, opts))

	ctx := context.Background()
	logger.Log(ctx, slog.LevelDebug, "Debug message")
	logger.Log(ctx, slog.LevelInfo, "Info message")
	logger.Log(ctx, LevelNotice, "Notice message")
	logger.Log(ctx, slog.LevelWarn, "Warn message")
}

結果
{"time":"2023-07-01T13:25:13.844754+09:00","level":"INFO","msg":"Info message"}
{"time":"2023-07-01T13:25:13.844937+09:00","level":"INFO+2","msg":"Notice message"}
{"time":"2023-07-01T13:25:13.84499+09:00","level":"WARN","msg":"Warn message"}

出力結果の2行目を見ると、本来、 "level":"NOTICE" となって欲しいところが、 "level":"INFO+2" となっている。これは、ログレベルを表す Level 型に対して以下のようなStringerインターフェースが実装されているためである。

// String returns a name for the level.
// If the level has a name, then that name
// in uppercase is returned.
// If the level is between named values, then
// an integer is appended to the uppercased name.
// Examples:
//
// LevelWarn.String() => "WARN"
// (LevelInfo+2).String() => "INFO+2"
func (l Level) String() string {
	str := func(base string, val Level) string {
		if val == 0 {
			return base
		}
		return fmt.Sprintf("%s%+d", base, val)
	}

	switch {
	case l < LevelInfo:
		return str("DEBUG", l-LevelDebug)
	case l < LevelWarn:
		return str("INFO", l-LevelInfo)
	case l < LevelError:
		return str("WARN", l-LevelWarn)
	default:
		return str("ERROR", l-LevelError)
	}
}

独自定義したログレベルを出力に出したい場合、 slog.HandlerOptionsReplaceAttr で書き換えてあげればよい。

const (
	LevelNotice = slog.Level(2)
)

func main() {
	opts := &slog.HandlerOptions{
		Level: slog.LevelInfo,
		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
			if a.Key != slog.LevelKey {
				return a
			}
			if level := a.Value.Any().(slog.Level); level == LevelNotice {
				a.Value = slog.StringValue("NOTICE")
			}
			return a
		},
	}

	logger := slog.New(slog.NewJSONHandler(os.Stdout, opts))

	ctx := context.Background()
	logger.Log(ctx, slog.LevelDebug, "Debug message")
	logger.Log(ctx, slog.LevelInfo, "Info message")
	logger.Log(ctx, LevelNotice, "Notice message")
	logger.Log(ctx, slog.LevelWarn, "Warn message")
}

結果
{"time":"2023-07-01T13:26:03.110154+09:00","level":"INFO","msg":"Info message"}
{"time":"2023-07-01T13:26:03.110367+09:00","level":"NOTICE","msg":"Notice message"}
{"time":"2023-07-01T13:26:03.110371+09:00","level":"WARN","msg":"Warn message"}

これで想定通りの出力結果になる。

独自のハンドラーを用いる

アーキテクチャ部分で説明したが、slogのハンドラーはインターフェースなので、インターフェースを満たすようなハンドラーを作ってあげればslogの「バックエンド」として用いることができる。ここでは、独自のハンドラーをslogの「バックエンド」として用いてみる。

ここでは、ログの出力結果がインデント付きのJSONになる prettyJSONHandler を実装してみる。


// slog.Handlerをラップして独自のハンドラーを定義
type prettyJSONHandler struct {
	slog.Handler
	w      io.Writer
	indent int
}

func NewJSONPrettyHandler(w io.Writer, opts prettyJSONHandlerOptions) *prettyJSONHandler {
	return &prettyJSONHandler{
		Handler: slog.NewJSONHandler(w, &opts.slogOps),
		w:       w,
		indent:  opts.indent,
	}
}

// 独自のハンドラーに対するオプション
type prettyJSONHandlerOptions struct {
	slogOps slog.HandlerOptions
	indent  int
}

func addFields(fields map[string]any, a slog.Attr) {
	value := a.Value.Any()
	if _, ok := value.([]slog.Attr); !ok {
		fields[a.Key] = value
		return
	}

	attrs := value.([]slog.Attr)
	// ネストしている場合、再起的にフィールドを探索する。
	innerFields := make(map[string]any, len(attrs))
	for _, attr := range attrs {
		addFields(innerFields, attr)
	}
	fields[a.Key] = innerFields
}

// Handleメソッドを差し替える
func (h *prettyJSONHandler) Handle(_ context.Context, r slog.Record) error {
	fields := make(map[string]any, r.NumAttrs())
	fields["time"] = r.Time
	fields["level"] = r.Level
	fields["message"] = r.Message

	r.Attrs(func(a slog.Attr) bool {
		addFields(fields, a)
		return true
	})

	b, err := json.MarshalIndent(fields, "", strings.Repeat(" ", h.indent))
	if err != nil {
		return err
	}

	h.w.Write(b)

	return nil
}

func main() {
	ops := prettyJSONHandlerOptions{
		slogOps: slog.HandlerOptions{
			Level: slog.LevelDebug,
		},
		indent: 4,
	}
	handler := NewJSONPrettyHandler(os.Stdout, ops)
	logger := slog.New(handler)

	logger.Debug("Debug message")
	logger.Info("Info message")
	logger.Warn("Warning message")
	logger.Error("Error message")

	logger.Debug(
		"nest log",
		slog.String("key", "1"),
		slog.Group(
			"inner1",
			slog.String("inner1Key1", "1"),
			slog.String("inner1Key2", "2"),
			slog.Group(
				"inner2",
				slog.String("inner2Key1", "1"),
				slog.String("inner2Key2", "2"),
			),
		),
	)
}

結果
{
    "level": "DEBUG",
    "message": "Debug message",
    "time": "2023-07-01T13:26:53.639027+09:00"
}{
    "level": "INFO",
    "message": "Info message",
    "time": "2023-07-01T13:26:53.639276+09:00"
}{
    "level": "WARN",
    "message": "Warning message",
    "time": "2023-07-01T13:26:53.639296+09:00"
}{
    "level": "ERROR",
    "message": "Error message",
    "time": "2023-07-01T13:26:53.639305+09:00"
}{
    "inner1": {
        "inner1Key1": "1",
        "inner1Key2": "2",
        "inner2": {
            "inner2Key1": "1",
            "inner2Key2": "2"
        }
    },
    "key": "1",
    "level": "DEBUG",
    "message": "nest log",
    "time": "2023-07-01T13:26:53.639314+09:00"
}

まず、 slog.Handler インターフェースをラップして構造体 prettyJSONHandler を定義している。こうすることで、prettyJSONHandler自身がslog.Handler インターフェースを満たすようになる。今回、ログ出力のフォーマットを変えたいので、 Handle メソッドを差し替えている。 addFieldsでは、ネストしたJSONを出力するためにゴリゴリ実装している。

パフォーマンス

slogと既存のロギングライブラリのパフォーマンス比較については、zapのレポジトリに記載されていた。
結果だけ載せておく。

最後に

本稿では、Go1.21で導入予定の新しいロギングライブラリslogについて紹介しました。執筆しているのが2023年7月1日なので、正式リリースまで1ヶ月程度あります。その間に、実装に変更が加わる可能性が十分ありますので、最新の情報を追いかけることをおすすめします。筆者自身も、キャッチアップして本稿をアップデートしていきたいと思います🙋。

本稿が読者の技術的な成長の糧になれば幸いです。

参考文献

注意:過去の参考文献は現在のslogの実装と所々ずれている部分があるので、常に最新の情報を信用しましょう。

Discussion