[Go] slog で Cloud Logging 向けのロガーを実装してみる

2023/11/03 追記
こちらの記事は slog が Go1.21 で標準パッケージに取り込まれる前に書かれています。
最新の情報と乖離している可能性があることをご了承ください。

はじめに

最近 slog なるロガーパッケージがあることを知り、ちょっと使ってみたくなったので試しに API サーバの実装に組み込んでみました。自分は主に GCP 使うことが多いので Cloud Logging でログを見ることを前提に実装しました。

slog とは

slog は構造化ログを出力するための Go の準標準パッケージです。Go で構造化ログを吐くためのライブラリだと uber-go/zap や sirupsen/logrus あたりが有名ですが、slog はそれらと比べ機能としては非常にシンプルな印象でした。

基本的な使い方は以下の記事がわかりやすかったです。

https://zenn.dev/mizutani/articles/golang-exp-slog

上記の記事でも言及されている通り、slog は Go の標準パッケージとして提案されており、本記事の執筆現在も以下の issue でやり取りが行われています。

https://github.com/golang/go/issues/56345

準標準パッケージ exp

slog は記事を執筆している現在は Go の準標準パッケージの exp パッケージに含まれています。「準標準パッケージ」と呼ばれる golang.org/x はいくつかのサブパッケージから成り立つ Go の公式パッケージです。その中でも slog が含まれる exp は準標準パッケージの中でも実験的なパッケージや非推奨のパッケージが含まれたものです。exp は Go 1 系の後方互換性を約束しないことも明記されています。

In short, code in this subrepository is not subject to the Go 1 compatibility promise.^[1]

そのため、実際に slog (および exp) を import するときはこのことを念頭に、ライブラリを捨ててもアプリケーション側に致命傷を及ぼさないような作りにしておくのが良さそうです。

実装内容の紹介

まだ slog が experimental だということは承知の上で API サーバに組み込んでみました。最終的には Cloud Run へデプロイすることとします。

コードはこちらに置いておきましたので詳しく見たい方はご覧ください。ディレクトリ構成やエラーハンドリング周りが少々雑なのはご了承ください。

https://github.com/kmtym1998/slog-gcp-example

以降はこちらの実装についての説明になります。

ディレクトリ構成は下記のとおりです。

$ tree
.
├── Dockerfile
├── Makefile
├── go.mod
├── go.sum
├── logger     # slog をラップしたパッケージ
│   └── logger.go
├── main.go
├── middleware # trace_id を logger に詰め込む
│   └── logger_injector.go

slog のラッパーパッケージ

https://github.com/kmtym1998/slog-gcp-example/blob/cb34b1dd86d4f5a80c8e55c8bed65dc73ad33937/logger/logger.go

slog.Logger をラップしたパッケージです。NewJSONHandler メソッドを使うことで構造化ログを JSON 形式で出力できます。Logger 構造体を New するときにいくつかのオプションを渡しています。

Level は出力するログレベルの下限を指定します。slog ではログレベルが低い順に DEBUG、INFO、WARN、ERROR の 4 つが定義されています。

ReplaceAttr には構造化ログの key / value を加工するための処理を関数として渡します。ここでは Cloud Logging の仕様^[2]に合わせて以下のように加工をしています。

• ログレベルのキー を level から severity に
• ログレベルの値 WARN を WARNING に
• ログの本文のキーを message に

プラットフォームに合わせたログのフォーマットの加工だけでなく、ログに出したくない情報のマスキングもやろうと思えばやれそうですね。

OnError にはエラーログを吐いたあとに実行される関数を渡しています。Level と ReplaceAttr は slog のオプションとして提供されているものをそのまま使っているだけですが、これは完全に自分の独自実装です。uber-go/zap や sirupsen/logrus には、ログを吐いてからそのログレベルに応じた hook を登録できる機能が提供されており、そこに着想を得ました。ここでエラー通知サービスにエラーを送ったりするような動きをさせる想定で作りました。

middleware でロガーにトレース ID を詰め込む

https://github.com/kmtym1998/slog-gcp-example/blob/cb34b1dd86d4f5a80c8e55c8bed65dc73ad33937/main.go#L50-L53

go-chi/chi を使ってミドルウェアを差し込んでいます。

https://github.com/kmtym1998/slog-gcp-example/blob/cb34b1dd86d4f5a80c8e55c8bed65dc73ad33937/middleware/logger_injector.go

ミドルウェアの中でトレース ID を抽出しています。Cloud Run では X-Cloud-Trace-Context というリクエストヘッダにトレース ID が含まれています。トレース ID はリクエストごとで一意になるよう割り振られた 32 文字の 16 進数の値です。取得したトレース ID は logging.googleapis.com/trace というキーに projects/[プロジェクトID]/traces/[トレースID] の形式で出力するようにしています。トレース ID をこのように出力することで Cloud Logging 上でリクエストごとにログをグルーピングすることが可能になります。

Cloud Logging 上だとこんな感じ

serve している /healthcheck エンドポイントのリクエストハンドラで DEBUG、INFO、WARNING、ERROR のそれぞれのレベルでログを吐くようにしています。

https://github.com/kmtym1998/slog-gcp-example/blob/cb34b1dd86d4f5a80c8e55c8bed65dc73ad33937/main.go#L80-L84

このとき Cloud Logging 上ではこんな感じに見えています。

ログレベル (重大度) によってログの左側のアイコンが変わっていることがわかります。

トレース ID で絞り込むと、該当のリクエストで出力されたログのみを抽出できます。障害・不具合調査の際に役立ちそうな予感がします。

まとめ

Go の準標準パッケージ slog で GCP 向けにロギングの仕組みを作ってみました。準標準パッケージだということもあり、zap や logrus 等のサードパーティ製のパッケージよりも機能的には質素な印象でした。そのシンプルさが自分にとっては好感触でしたが、ロギング周りであれこれやりたい野望のある方には物足りないかもしれません。個人的にはログレベルをもっと細かくしてくれても良い気はしました (それか使う側が勝手に足せるようにするとか)。

参考

https://zenn.dev/mizutani/articles/golang-exp-slog

https://tech.buysell-technologies.com/entry/2022/08/29/120000

https://zenn.dev/glassonion1/articles/c58505bf594868

脚注

1. https://pkg.go.dev/golang.org/x/exp#section-readme

2. 出力する JSON のログと Cloud Logging に出力されるログのマッピングはこちらを参照