Zenn
📘

slog を触る(ログレベル, フォーマット)

2023/09/18に公開
Go
Go
tech

はじめに

先月、Go のバージョン 1.21 のリリースがアナウンスされました。
今回のリリースで slog パッケージが登場し、注目度も高かったと思います。
タイミングが遅めですが、さっと触ってみたので備忘録的に残します。

slog とは

公式ドキュメント の冒頭には以下のように書いてあります。

Package slog provides structured logging, in which log records include a message, a severity level, and various other attributes expressed as key-value pairs.

slog は Structured LOGging から来ているようです。
(ちなみに slog は「スログ」のような発音のようです)
今回の Go1.21 のリリースで標準パッケージとして導入されました。
ログメッセージはもちろん、ログレベル、そしてその他の情報をキー・バリューで表現した構造化ログを実現する機能を提供します。

Go でロギングといえば、リリース初期から log パッケージが存在していますが、ログを構造化するための機能はありません。人間がさっと読むには問題ないですが、機械的に処理してフィルタリングしたり、グルーピングしたりする場合は不便です。そのため、Go での構造化ロギングの実現には、多くの場合、zap などのサードパーティのパッケージに頼らざるを得ない状態でした。

もちろん、Go チームもこの需要は把握しており、このたび標準としてサポートされることとなりました。また、構造化以外にもログレベルの導入など、他の機能も含まれています。

slog での主な登場人物

slog でキーとなる型は下の3つです。

  • Logger
    • slog のフロントエンド的立ち位置
    • Info, Error などのメソッドを提供
    • 情報を構造化し Handler に渡す
    • Legger は一つの Handler を持つ
    • おそらく多くのケースでは Logger を触るのみで Record や Handler はいじらないと思われる
  • Record
    • ログメッセージ、時間、ログレベルなどの各情報が詰められる
    • Info, Error などのメソッドのコール後に作成される
    • Handler に渡される
  • Handler
    • slog のバックエンド的立ち位置
    • Record をアウトプットしたり後続の処理に渡す

実際に試してみる

まずは公式ブログの A tour of slog からそのまま使ってみます。

package main

import "log/slog"

func main() {
	slog.Info("hello, world")
	// 2023/09/17 15:17:25 INFO hello, world
}

実行すると、関数呼び出しの下にあるコメントのような出力がされます。今回は Info 関数を読んでいるので INFO というログレベルが一緒に出力されています。ほとんど log パッケージをデフォルトのロガーで使った場合の出力と同じように見えるので、試しに改めて出力してみます。

package main

import "log"

func main() {
	log.Println("hello, world")
	// 2023/09/17 15:17:54 hello, world
}

INFO 以外は同じです。公式ドキュメントには下記のように書いてあり、slog のデフォルトのハンドラは、フォーマットした文字列を log パッケージに渡しているようです。

The default handler formats the log record’s message, time, level, and attributes as a string and passes it to the log package.

続いて、気になるキー・バリューの出力ですが、 メッセージの引数に続けて渡すと指定できます。デフォルトでは key=value の形式で出力されます。フォーマットの変更(JSON)は後述します。

	slog.Info("hello, world", "name", "slog")
	// 2023/09/17 15:18:28 INFO hello, world name=slog

ただ、パフォーマンスという観点と、バリューの指定漏れなどのミス防止の観点から、前の例のようにリテラルで引数を並べるより、下記の例の slog.String のような、slog で用意されている関数を利用してキー・バリューを指定する方が良いようです。

	slog.Info("hello, world", slog.String("name", "slog"))
	// 2023/09/17 15:19:04 INFO hello, world name=slog

ログレベル

デフォルトで用意されているログレベルは DEBUG, INFO, WARN, ERROR の4つです。slog 内部ではこれらは int として下のように定義されています。

type Level int

const (
	LevelDebug Level = -4
	LevelInfo  Level = 0
	LevelWarn  Level = 4
	LevelError Level = 8
)

独自のレベルを追加する必要があるなら、これらと被らないような値を設定し、追加で幾分かの実装をすれば良いです。下記は CRITICAL レベルを追加した例になります。

	const LevelCriticlal = slog.Level(12)

	handler := slog.NewTextHandler(
		os.Stdout,
		&slog.HandlerOptions{
			ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
				if a.Key == slog.LevelKey && a.Value.Any().(slog.Level) == LevelCriticlal {
					a.Value = slog.StringValue("CRITICAL")
				}
				return a
			},
		})

	logger := slog.New(handler)
	logger.Info("hello, world")
	// time=2023-09-17T20:00:44.761+09:00 level=INFO msg="hello, world"
	logger.Log(context.Background(), LevelCriticlal, "the world is ending")
	// time=2023-09-17T20:00:44.762+09:00 level=CRITICAL msg="the world is ending"

また、デフォルトで設定されている、出力する最低限のログレベルは INFO です。
これを変更するには、オプションをつけてロガーを作成すれば良いです。

	slog.Info("hello, world", slog.Int("number", 1))
	// 2023/09/17 15:57:48 INFO hello, world number=1
	slog.Debug("hello, world", slog.Int("number", 1))
	// 出力されない

	slog.SetDefault(
		slog.New(
			slog.NewTextHandler(
				os.Stdout,
				&slog.HandlerOptions{Level: slog.LevelDebug},
			),
		),
	)

	slog.Info("hello, world", slog.Int("number", 2))
	// time=2023-09-17T15:57:48.328+09:00 level=INFO msg="hello, world" number=2
	slog.Debug("hello, world", slog.Int("number", 2))
	// 今度は出力される
	// time=2023-09-17T15:57:48.329+09:00 level=DEBUG msg="hello, world" number=2

フォーマットを JSON に変えたい

何もせず slog.Info を呼ぶと、出力結果は下記のようなものでした。

	slog.Info("hello, world")
	// 2023/09/17 15:17:25 INFO hello, world

これを JSON に変えてみます。
やり方はシンプルで、ロガーを作成する時に slog で用意されている JSON 用のハンドラを指定すれば良いです。

	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
	logger.Info("hello world", "name", "slog")
	// {"time":"2023-09-17T15:20:05.216004+09:00","level":"INFO","msg":"hello world","name":"slog"}

出力が JSON 形式になりました。

終わりに

slog はシンプルでありつつも、自分にとって欲しい機能が用意されており、今後利用する機会は大いにあるだろうと感じました。
コンテキストやグループ周りなど、正直まだ触れるべきところはたくさんありそうです。
もう少し触ってみたいと思います。

参考文献

Discussion