> Source: https://www.ymotongpoo.com/works/goblog-ja/slog/ # slogによる構造化ロギング [Structured Logging with slog](https://go.dev/blog/slog) by Jonathan Amsterdam Go 1.21で新たに追加された `log/slog` パッケージは、構造化ロギングを標準ライブラリにもたらします。 構造化ログはキーと値のペアを使うため、迅速かつ確実にパース、フィルタリング、検索、分析ができます。 サーバーにとって、ロギングは開発者がシステムの詳細な挙動を観察するための重要な手段であり、デバッグの際に 最初に頼ることも多いものです。そのため、ログは大量になりがちで、迅速に検索してフィルタリングできることが 欠かせません。 標準ライブラリには、10年以上前のGoの最初のリリース以来、 `log` というロギングパッケージが存在してきました。 時間が経つにつれ、構造化ロギングがGoプログラマにとって重要であることがわかってきました。Goの年次アンケート調査では 一貫して高い順位にランクインしており、Goのエコシステムには構造化ロギングを提供するパッケージが数多く存在します。 中には非常に人気の高いものもあります。Go向けの初期の構造化ロギングパッケージの1つである [logrus](https://pkg.go.dev/github.com/sirupsen/logrus) は、10万を超える他のパッケージで使われています。 選択肢となる構造化ロギングパッケージが数多く存在する結果、大規模なプログラムでは依存関係を通じて複数の ロギングパッケージを取り込んでしまうことがよくあります。メインプログラム側では、ログの出力が同じ場所に 同じフォーマットで揃うように、それぞれのロギングパッケージを設定しなければならないかもしれません。 構造化ロギングを標準ライブラリに含めることで、他のすべての構造化ロギングパッケージが共有できる共通の基盤を 提供できます。 ## slogを一通り見る 次は `slog` を使った最もシンプルなプログラムです。 ```go package main import "log/slog" func main() { slog.Info("hello, world") } ``` この記事の執筆時点では、次のように出力されます。 ``` 2023/08/04 16:09:19 INFO hello, world ``` `Info` 関数は、デフォルトロガーを使ってInfoログレベルでメッセージを出力します。このデフォルトロガーは、 今回のケースでは `log` パッケージのデフォルトロガー、つまり `log.Printf` を書いたときに使われるのと 同じロガーです。これで出力がよく似ている理由がわかります。新しいのは「INFO」の部分だけです。標準の状態でも、 `slog` と元々の `log` パッケージは連携して動作するので、簡単に使い始められます。 `Info` の他にも、 `Debug` 、 `Warn` 、 `Error` という3つのレベル用の関数があり、さらにレベルを引数に取る より汎用的な `Log` 関数もあります。 `slog` ではレベルは単なる整数なので、名前の付いた4つのレベルだけに 縛られることはありません。例えば `Info` は0、 `Warn` は4なので、この間のレベルがロギングシステムに 必要であれば、2を使えます。 `log` パッケージとは異なり、メッセージの後にキーと値のペアを書くだけで簡単に出力に追加できます。 ```go slog.Info("hello, world", "user", os.Getenv("USER")) ``` 出力は次のようになります。 ``` 2023/08/04 16:27:19 INFO hello, world user=jba ``` 先に触れたとおり、 `slog` のトップレベル関数はデフォルトロガーを使います。このロガーを明示的に取得して、 そのメソッドを呼び出すこともできます。 ```go logger := slog.Default() logger.Info("hello, world", "user", os.Getenv("USER")) ``` すべてのトップレベル関数は `slog.Logger` のメソッドに対応しています。出力は先ほどと同じです。 初期状態では、 `slog` の出力はデフォルトの `log.Logger` を経由するため、ここまで見てきたような出力に なります。ロガーが使う _ハンドラ_ を変更することで、出力を変えられます。 `slog` には2つの組み込みハンドラが 用意されています。 `TextHandler` は、すべてのログ情報を `key=value` という形式で出力します。次の プログラムは `TextHandler` を使って新しいロガーを作成し、同じように `Info` メソッドを呼び出します。 ```go logger := slog.New(slog.NewTextHandler(os.Stdout, nil)) logger.Info("hello, world", "user", os.Getenv("USER")) ``` 出力は次のようになります。 ``` time=2023-08-04T16:56:03.786-04:00 level=INFO msg="hello, world" user=jba ``` すべてがキーと値のペアに変換され、構造を保つために必要に応じて文字列がクォートされています。 JSON形式で出力したい場合は、代わりに組み込みの `JSONHandler` を設定します。 ```go logger := slog.New(slog.NewJSONHandler(os.Stdout, nil)) logger.Info("hello, world", "user", os.Getenv("USER")) ``` これで出力は、ロギングの呼び出し1回につき1つのJSONオブジェクトが並ぶ形になります。 ``` {"time":"2023-08-04T16:58:02.939245411-04:00","level":"INFO","msg":"hello, world","user":"jba"} ``` 組み込みのハンドラだけに限られているわけではありません。誰でも `slog.Handler` インターフェースを 実装することでハンドラを書けます。ハンドラは特定のフォーマットで出力を生成することも、別のハンドラを ラップして機能を追加することもできます。 `slog` のドキュメントにある [サンプル](https://pkg.go.dev/log/slog@master#example-Handler-LevelHandler)の1つでは、ログメッセージが 表示される最小レベルを変更するラッピングハンドラの書き方を示しています。 これまで使ってきた、属性をキーと値を交互に並べる構文は便利ですが、頻繁に実行されるログ出力文では、 `Attr` 型を使って `LogAttrs` メソッドを呼び出すほうが効率的な場合があります。これらは連携してメモリ アロケーションを最小限に抑えます。文字列や数値、その他一般的な型から `Attr` を組み立てるための関数が 用意されています。次の `LogAttrs` の呼び出しは上記と同じ出力を生成しますが、より高速です。 ```go slog.LogAttrs(context.Background(), slog.LevelInfo, "hello, world", slog.String("user", os.Getenv("USER"))) ``` `slog` にはこの他にもたくさんの機能があります。 * 先ほどの `LogAttrs` の呼び出しで示したとおり、一部のログ関数には `context.Context` を渡せるので、 ハンドラがトレースIDのようなコンテキスト情報を取り出せます。（コンテキストをキャンセルしても、 ログエントリの書き込みが妨げられることはありません。） * `Logger.With` を呼び出すことで、そのロガーのすべての出力に現れる属性を追加でき、複数のログ出力文に 共通する部分を実質的に括り出せます。これは便利なだけでなく、後述するようにパフォーマンスの向上にも 役立ちます。 * 属性はグループにまとめられます。これによってログ出力により多くの構造を持たせられ、そのままでは 同じになってしまうキーを区別しやすくなります。 * 値の型に `LogValue` メソッドを実装することで、その値がログにどう現れるかを制御できます。これは、 例えば構造体のフィールドをグループとして [ログ出力する](https://pkg.go.dev/log/slog@master#example-LogValuer-Group)ことや、 [機密データを伏せ字にする](https://pkg.go.dev/log/slog@master#example-LogValuer-Secret)といった 用途に使えます。 `slog` のすべてを学ぶには、[パッケージのドキュメント](https://pkg.go.dev/log/slog)を読むのが一番です。 ## パフォーマンス 私たちは `slog` を高速にしたいと考えました。大規模なパフォーマンス向上のために、 [`Handler` インターフェース](https://pkg.go.dev/log/slog#Handler)を、最適化の余地を残す形で設計しました。 `Enabled` メソッドはすべてのログイベントの最初に呼び出され、ハンドラが不要なログイベントを素早く捨てる 機会を与えます。 `WithAttrs` と `WithGroup` メソッドによって、ハンドラは `Logger.With` で追加された 属性を、ログ出力の呼び出しごとではなく一度だけフォーマットできます。この事前フォーマットは、 `http.Request` のような大きな属性を `Logger` に追加し、それを多数のログ出力呼び出しで使う場合に、 大きな高速化をもたらします。 パフォーマンス最適化の作業の指針とするために、既存のオープンソースプロジェクトにおけるロギングの典型的な パターンを調査しました。その結果、ロギングメソッドの呼び出しの95%以上が5個以下の属性しか渡していない ことがわかりました。また属性の型も分類し、少数の一般的な型が大部分を占めていることがわかりました。 そこで、よくあるケースを捉えたベンチマークを書き、それを指針として時間がどこに費やされているかを 調べました。最も大きな成果が得られたのは、メモリアロケーションに注意深く気を配った部分でした。 ## 設計プロセス `slog` パッケージは、2012年にGo 1がリリースされて以来、標準ライブラリに対する最大級の追加の1つです。 私たちはこの設計にじっくり時間をかけたいと考えており、コミュニティからのフィードバックが不可欠で あることもわかっていました。 2022年4月までに、構造化ロギングがGoコミュニティにとって重要であることを示すのに十分なデータが 集まりました。Goチームは、これを標準ライブラリに追加することを検討することにしました。 私たちはまず、既存の構造化ロギングパッケージがどのように設計されているかを調べることから始めました。 またGoモジュールプロキシに保存されている大量のオープンソースGoコードを活用して、これらのパッケージが 実際にどう使われているかを学びました。最初の設計は、この調査とGoのシンプルさという精神の両方に 基づいたものでした。パフォーマンスを犠牲にすることなく、コード上で軽く、理解しやすいAPIにしたいと 考えました。 既存のサードパーティ製ロギングパッケージを置き換えることは、そもそも目標にしていませんでした。 それらはいずれもそれぞれの役割をうまく果たしていますし、うまく動いている既存のコードを置き換えるのは、 開発者の時間の使い方としてはめったに良い選択ではありません。私たちはAPIをフロントエンドである `Logger` とバックエンドのインターフェースである `Handler` に分けました。こうすることで、既存の ロギングパッケージが共通のバックエンドとやりとりできるようになり、それらを使っているパッケージは 書き直すことなく相互運用できます。 [Zap](https://github.com/uber-go/zap/tree/master/exp/zapslog) 、 [logr](https://github.com/go-logr/logr/pull/196) 、 [hclog](https://github.com/evanphx/go-hclog-slog) をはじめとする、多くの一般的なロギングパッケージ向けの ハンドラがすでに書かれているか、開発が進められています。 最初の設計は、Goチーム内と、ロギングについて豊富な経験を持つ他の開発者たちに共有しました。彼らからの フィードバックをもとに変更を加え、2022年8月までには実用に足る設計になったと感じました。8月29日、 [実験的な実装](https://github.com/golang/exp/tree/master/slog)を公開し、コミュニティの意見を聞くための [GitHub discussion](https://github.com/golang/go/discussions/54763)を開始しました。反響は熱心で、 おおむね好意的なものでした。他の構造化ロギングパッケージの設計者やユーザーからの洞察に富んだコメントの おかげで、いくつかの変更を行い、グループや `LogValuer` インターフェースといった機能をいくつか 追加しました。ログレベルと整数の対応付けは2度変更しました。 2か月と約300件のコメントを経て、正式な[プロポーザル](https://go.dev/issue/56345)と、それに付随する [設計ドキュメント](https://go.googlesource.com/proposal/+/03441cb358c7b27a8443bca839e5d7a314677ea6/design/56345-structured-logging.md)を 出せる状態になったと感じました。このプロポーザルのissueには800件を超えるコメントが寄せられ、APIと 実装の両方に多くの改善がもたらされました。ここでは、いずれも `context.Context` に関するAPI変更の例を 2つ紹介します。 1. 当初のAPIでは、ロガーをコンテキストに追加できるようになっていました。多くの人が、ロガーを気にしない コード層を通じて簡単に受け渡すための便利な方法だと感じました。しかし別の人たちは、これは暗黙の 依存関係をこっそり持ち込むものであり、コードを理解しにくくすると感じました。最終的に、議論を呼び すぎるという理由でこの機能を削除しました。 2. また、ロギングメソッドにコンテキストを渡すべきかという関連する問題にも取り組み、いくつもの設計を 試しました。当初は、すべてのロギング呼び出しでコンテキストを必須にしたくなかったため、コンテキストを 第一引数として渡すという標準的なパターンに抵抗していましたが、最終的にはコンテキストありと コンテキストなしの、2種類のロギングメソッドを用意しました。 変更しなかった点の1つが、属性を表現するためのキーと値を交互に並べる構文についてです。 ```go slog.Info("message", "k1", v1, "k2", v2) ``` 多くの人が、これは良くない考え方だと強く感じていました。読みにくく、キーや値を書き漏らすといった 間違いも起こしやすいという意見です。彼らは、構造を表現するために明示的な属性を使うほうを好みました。 ```go slog.Info("message", slog.Int("k1", v1), slog.String("k2", v2)) ``` しかし私たちは、特にGoを使い始めたばかりのプログラマにとって、Goを簡単で楽しく使えるものであり続ける ためには、この軽量な構文が重要だと考えました。また、 `logr` 、 `go-kit/log` 、（ `SugaredLogger` を 使った） `zap` といった複数のGo向けロギングパッケージが、キーと値を交互に並べる方式をうまく使いこなして いることも知っていました。私たちはよくある間違いを捕まえるための [vetチェック](https://pkg.go.dev/golang.org/x/tools/go/analysis/passes/slog)を追加しましたが、設計自体は 変更しませんでした。 2023年3月15日にこのプロポーザルは受理されましたが、まだいくつかの細かい未解決の問題が残っていました。 その後の数週間で、さらに10件の変更が提案され、解決されました。7月初旬までには、 `log/slog` パッケージの 実装が完成し、ハンドラを検証するための `testing/slogtest` パッケージや、キーと値を交互に並べる書き方が 正しいかを確認するvetチェックも揃いました。 そして8月8日、Go 1.21がリリースされ、 `slog` もそれとともに世に出ました。 `slog` が皆さんの役に立ち、 私たちが作っていて楽しかったのと同じくらい、使っていて楽しいものであることを願っています。 最後に、議論とプロポーザルのプロセスに参加してくださったすべての方に、大きな感謝を伝えます。皆さんの 貢献のおかげで、 `slog` は大きく改善されました。 ## 参考資料 `log/slog` パッケージの[ドキュメント](https://pkg.go.dev/log/slog)には、使い方の説明といくつかの サンプルが用意されています。 [wikiページ](https://go.dev/wiki/Resources-for-slog)には、様々なハンドラをはじめとする、Goコミュニティが 提供する追加のリソースがあります。 ハンドラを書きたい場合は、 [ハンドラ作成ガイド](https://github.com/golang/example/blob/master/slog-handler-guide/README.md)を 参照してください。 By Jonathan Amsterdam