Go ロギングライブラリ

Go でログを出力する時に色々方法がありすぎたので、調べたことを簡単にメモ

:::note warn
[2023/8/21 追記]
2023年8月にリリースされた Go1.21 から公式の準標準ライブラリに [slog](https://pkg.go.dev/log/slog) というライブラリが追加されました。
これが構造化ログに対応しているため、サードパーティライブラリを使わずとも json フォーマットでログを出力することが可能になりました。これから新規にプロジェクトを作る場合はまず slog から始めるのが良いと思います。

[参考]
https://go.dev/blog/slog
https://zenn.dev/88888888_kota/articles/7e97ff874083cf
https://future-architect.github.io/articles/20230731a/
:::

# 標準ライブラリ
- https://golang.org/pkg/log/
- 一番サクッとやるならこれ
- print 関数で palin text 出力なので構造化しづらくてきつい
    - 構造化したい場合は printf で自分で整形して頑張るかたち
- ログレベルによるフィルタリング機能はないので本番運用に乗せるのは厳しい感じ
- デバッグ用にサクッと標準出力するのに使うとかかな

```go
log.Print("something happened")
// => 2021/04/01 12:00:00 something happened

log.Printf("something happened, %s", "nanika ga okimashita")
// => 2021/04/01 12:00:00 something happened, nanika ga okimashita
```

# サードパーティ製ライブラリ
サードパーティ製の Go のロギングライブラリはたくさんあって選べない...
https://github.com/avelino/awesome-go#logging

以下、github star が多いものをいくつかピックアップ

## logrus 
- https://github.com/Sirupsen/logrus
- かなりポピュラーらしく github の star も多い
- go の構造化ログライブラリの草分け的存在らしく、後続の Zerolog や Zap、 Apex などが思想を受け継いで開発されている
- 現在は枯れており、以下のように述べている

> Seeing weird case-sensitive problems? It's in the past been possible to import Logrus as both upper- and lower-case. Due to the Go package environment, this caused issues in the community and we needed a standard. Some environments experienced problems with the upper-case variant, so the lower-case was decided. Everything using logrus will need to use the lower-case: github.com/sirupsen/logrus. Any package that isn't, should be changed.

- v2 の開発予定はないらしいが、現行バージョンのメンテは今でも続いている
- フォーマットを指定でき、簡単に json 形式でログを出力できる
- ログレベルによるフィルタリングももちろんできるので、本番環境ではデバッグレベルは出力しないなどの設定が可能

```go
logrus.Info("something happened")
// => INFO[0000] something happened 

logrus.SetFormatter(&logrus.JSONFormatter{})

logrus.Info("something happened")
// => {"level":"info","msg":"something happened","time":"2021-04-01T12:00:00+09:00"}

logrus.WithFields(logrus.Fields{
    "code":    "001",
    "content": "何かが起きました",
}).Info("something happened")
// => {"code":"001","content":"何かが起きました","level":"info","msg":"something happened","time":"2021-04-01T12:00:00+09:00"}
```


## zap
- https://github.com/uber-go/zap
- uber が開発したライブラリで、高速なのが売り
    -  独自の zap 構造体に依存し、`interface{}` 型に依存しないことで、reflection less な作りらしい
    - `sync.Pool` で `Buffer` や `Encoder` を再利用できるので速いらしい
- grpc の middleware 郡にも組み込まれていて、intercepter でのロギングでも活躍するそう
    - https://github.com/grpc-ecosystem/go-grpc-middleware/tree/master/logging/zap
- 高速な `Logger` とそれより少し低速な `SugaredLogger` がある
    - シビアな速度パフォーマンスが求められる場合は `Logger` を使い、それ以外なら基本は `SugaredLogger` を使うで良さそう
        - `Logger` だと渡すメッセージとして `zap.String` のように zap 構造体を毎回記述しないといけないので開発効率的にはあまり良くなさそう
    - 処理の途中で（リコンパイルせずに）簡単に切り替えができるので、プロジェクト設定自体はカジュアルに決めちゃって良さそう

```go
logger, _ := zap.NewDevelopment()

logger.Info("something happened")
// => {"level":"info","ts":1618302530.16781,"caller":"example/main.go:24","msg":"something happened"}

logger.Info("something happened",
    zap.String("code", "001"),
    zap.String("content", "何かが起きました"),
)
// => {"level":"info","ts":1618302530.167862,"caller":"example/main.go:25","msg":"something happened","code":"001","content":"何かが起きました"}

// SugaredLogger は低速な代わりに Zap 構造体に縛られない
slogger := logger.Sugar()
slogger.Info("something happened",
    "code", "001",
    "content", "何かが起きました",
)
// => {"level":"info","ts":1618302530.167874,"caller":"example/main.go:31","msg":"something happenedcode001content何かが起きました"}

```

## glog
- https://github.com/golang/glog
- ラストコミットが2016年でメンテされてなさそう
- 見た感じ構造化はできなくて、plain text 出力っぽい
- フォーマットも固定でなぜか year が出力されない（容量節約？）ので、本番運用には難しそう
- 設定値を起動オプションで渡すという仕様がイマイチ
- `-logtostderr` をコマンドライン引数で渡して実行してみた結果が以下
    - flag をパースせずに使おうとすると怒られる

```go
glog.Info("something happened")
// => ERROR: logging before flag.Parse: I0413 12:00:00.452402   47903 main.go:36] something happened

flag.Parse()
glog.Info("something happened")
// => I0401 12:00:00.452492   47903 main.go:39] something happened
```

## seelog 
- https://github.com/cihub/seelog
- 高機能なんだけど設定ファイルが XML 形式
- 最後のコミットが2017年とかなのでこれもメンテされてなさそう

```go
defer seelog.Flush()
seelog.Info("something happened")
// => 1618304287968713000 [Info] something happened

const logConfig = `<seelog type="sync">
                    <outputs>
                            <filter levels="trace,debug,info">
                                    <console formatid="ltsv"/>
                            </filter>
                            <filter levels="warn,error,critical">
                                    <console formatid="ltsv_error"/>
                            </filter>
                    </outputs>
                    <formats>
                            <format id="ltsv" format="time:%Date(2006-01-02T15:04:05.000Z07:00)%tlev:%l%tmsg:%Msg%n"/>
                            <format id="ltsv_error"
                                    format="%EscM(31)time:%Date(2006-01-02T15:04:05.000Z07:00)%tlev:%l%tmsg:%Msg%EscM(0)%n"/>
                    </formats>
                </seelog>`

logger, _ := seelog.LoggerFromConfigAsBytes([]byte(logConfig))
seelog.ReplaceLogger(logger)
logger.Info("something happened")
// => time:2021-04-01T12:00:00.968+09:00      lev:i   msg:something happened

```

## go-spew
- https://github.com/davecgh/go-spew
- readme にも書いてあるんだけど、デバッグ用ログライブラリらしい

# ベンチ取ってみた
- 手前味噌だけど一応ベンチマークを取ってみた
- 書き出し内容とかをそこまで厳密に揃えたわけではないので単純比較できないけど、それでも zap が桁違いに速い

```
$ go test -bench . 
goos: darwin
goarch: amd64
pkg: example.com/go-log-test
BenchmarkOutputLog_builtin-8      162410              9434 ns/op
BenchmarkOutputLog_zap-8         3314227               353 ns/op
BenchmarkOutputLog_logrus-8        75792             13932 ns/op
BenchmarkOutputLog_zerolog-8      140047              9740 ns/op
```

- ベンチで実行するのに使ったスクリプトを一応

```go
package main

import (
	"io"
	"log"
	"os"
	"testing"

	"github.com/rs/zerolog"
	"github.com/sirupsen/logrus"
	"go.uber.org/zap"
)

func BenchmarkOutputLog_builtin(b *testing.B) {
	file, _ := os.OpenFile("./output.log", os.O_APPEND|os.O_WRONLY, os.ModeAppend)
	log.SetOutput(io.Writer(file))

	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		log.Print("output log")
	}
}

func BenchmarkOutputLog_zap(b *testing.B) {
	c := zap.NewProductionConfig()
	c.OutputPaths = []string{"./output.log"}
	logger, _ := c.Build()

	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		logger.Info("output log")
	}
}

func BenchmarkOutputLog_logrus(b *testing.B) {
	logger := logrus.New()
	logger.Out, _ = os.OpenFile("./output.log", os.O_APPEND|os.O_WRONLY, os.ModeAppend)

	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		logger.Info("output log")
	}
}

func BenchmarkOutputLog_zerolog(b *testing.B) {
	file, _ := os.OpenFile("./output.log", os.O_APPEND|os.O_WRONLY, os.ModeAppend)
	logger := zerolog.New(file)

	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		logger.Info().Msg("output log")
	}
}
```

# まとめ
- デファクトスタンダード的なものはないけど、無難なら logrus を使っておけば良さそう
- 速度パフォーマンスを気にするなら zap
- 正直以下の要素が満たされればそんなに悩む必要もない気がする
    - 構造化
    - ログレベルによるフィルタリング
    - 設定のファイル管理