Go語言Zap庫Logger的客製化化和封裝使用詳解

2022-06-25 14:00:41

前言

紀錄檔無論對於程式還是程式設計師都非常重要，有多重要呢，想要長期在公司健健康康的幹下去就得學會階段性划水，階段性划水的一大關鍵的就是幹活快過預期但是裝作。。。不對，這個開頭不對勁，下面重來。

紀錄檔無論對於程式還是程式設計師都非常重要，程式設計師解決問題的快慢除了經驗外，就是看紀錄檔能不能有效地記錄問題發生的現場以及上下文等等。

那麼讓讓程式記錄有效的紀錄檔，除了程式內記紀錄檔的點位儘量精準外，還需要有一個稱手的 Logger 。一個好的 Logger (紀錄檔記錄器) 要能提供以下這些能力：

支援把紀錄檔寫入到多個輸出流中，比如可以選擇性的讓測試、開發環境同時向控制檯和紀錄檔檔案輸出紀錄檔，生產環境只輸出到檔案中。
支援多級別的紀錄檔等級，比如常見的有：TRACE，DEBUG，INFO，WARN，ERROR 等。
支援結構化輸出，結構化輸出現在常用的就是JSON形式的，這樣可以讓統一紀錄檔平臺，通過 logstash 之類的元件直接把紀錄檔聚合到紀錄檔平臺上去。
需要支援紀錄檔切割 -- log rotation，按照日期、時間間隔或者檔案大小對紀錄檔進行切割。
在 Log Entry 中（就是每行記錄）除了主動記錄的資訊外，還要包括如列印紀錄檔的函數、所在的檔案、行號、記錄時間等。

今天我帶大家一起看看怎麼在使用 Go 語言開發的專案裡打造一個稱手的 Logger，在這之前讓我們先回到 2009 年，看看 Go 語言自誕生之初就提供給我們的內建 Logger。

Go 語言原生的Logger

Go 語言自帶 log 內建包，為我們提供了一個預設的 Logger，可以直接使用。這個庫的詳細用法可以在官方的檔案裡找到：pkg.go.dev/log

使用 log 記錄紀錄檔，預設會輸出到控制檯中。比如下面這個例子：

package main
import (
	"log"
	"net/http"
)
func main() {
	simpleHttpGet("www.google.com")
	simpleHttpGet("https://www.baidu.com")
}
func simpleHttpGet(url string) {
	resp, err := http.Get(url)
	if err != nil {
		log.Printf("Error fetching url %s : %s", url, err.Error())
	} else {
		log.Printf("Status Code for %s : %s", url, resp.Status)
		resp.Body.Close()
	}
	return
}

這個例程中，分別向兩個網址進行 GET 請求，然後記錄了一下返回狀態碼 / 請求錯誤。執行程式後會有類似輸出：

2022/05/15 15:15:26 Error fetching url www.baidu.com : Get "www.baidu.com": unsupported protocol scheme "" 2022/05/15 15:15:26 Status Code for https://www.baidu.com : 200 OK

因為第一次請求的 URL 中協定頭缺失，所以不能成功發起請求，紀錄檔也很好的記錄了錯誤資訊。

Go 內建的 log 包當然也支援把紀錄檔輸出到檔案中，通過log.SetOutput 可以把任何 io.Writer 的實現設定成紀錄檔的輸出。下面我們把上面那個例程修改成向檔案輸出紀錄檔。

大家可以自己試一下執行效果，這裡不再做過多演示。

Go 語言原生Logger的缺點

原生 Logger 的優點，顯而易見，簡單、開箱即用，不用參照外部的三方庫。我們可以按照開頭處提出的對於一個 Logger 的五個標準再看一下預設Logger 是否能在專案裡使用。

僅限基本的紀錄檔級別
- 只有一個Print選項。不支援INFO/DEBUG等多個級別。
對於錯誤紀錄檔，它有Fatal和Panic
- Fatal紀錄檔通過呼叫os.Exit(1)來結束程式
- Panic紀錄檔在寫入紀錄檔訊息之後丟擲一個panic
- 但是它缺少一個ERROR紀錄檔級別，這個級別可以在不丟擲panic或退出程式的情況下記錄錯誤
缺乏結構化紀錄檔格式的能力——只支援簡單文字輸出，不能把紀錄檔記錄格式化成 JSON 格式。
不提供紀錄檔切割的能力。

Zap 紀錄檔庫

在 Go 的生態中，有不少可以選擇的紀錄檔庫，之前我們簡單介紹過 logrus 這個庫的使用:點我檢視，它與Go的內建 log 庫在 api 層面相容，直接實現了log.Logger介面，支援把程式的系統級 Logger 切換成它。

不過 logrus 在效能敏感的場景下就顯得不香了，用的更多的是 Uber 開源的 zap 紀錄檔庫。由於 Uber 在當今 Go 生態中的貢獻度很高，加之它本身業務—網約車的效能敏感場景，所以 Uber 開源的庫很受歡迎。現在做專案，使用 Zap 做紀錄檔Logger 的非常多。程式設計師的內心OS應該是，不管我這並行高不高，上就完事了，萬一哪天能從2個並行突然幹成 2W 並行呢。

Zap 效能高的一大原因是：不用反射，紀錄檔裡每個要寫入的欄位都得攜帶著型別

logger.Info(
  "Success..",
  zap.String("statusCode", resp.Status),
  zap.String("url", url))

上面向紀錄檔裡寫入了一條記錄，Message 是 "Success.." 另外寫入了兩個字串鍵值對。 Zap 針對紀錄檔裡要寫入的欄位，每個型別都有一個對應的方法把欄位轉成 zap.Field 型別。比如：

zap.Int('key', 123)
zap.Bool('key', true)
zap.Error('err', err)
zap.Any('arbitraryType', &User{})

還有很多中這種型別方法，就不一一列舉啦。這種記錄紀錄檔的方式造成在使用體驗上稍稍有點差，不過考慮到效能上收益這點使用體驗上的損失也能接受。

下面我們先來學習一下 Zap 的使用方法，再對專案中使用 Zap 時做些自定義的設定和封裝，讓它變得更好用，最重要的是匹配上我們開頭提出的關於好的 Logger 的五條標準。

Zap 的使用方法

安裝zap

首先說一下，zap 的安裝方式，直接執行以下命令下載 zap 到原生的依賴庫中。

go get -u go.uber.org/zap

設定 Logger

我們先說 zap 提供的設定好的 Logger ，稍後會對它進行自定義。

通過呼叫zap.NewProduction()、zap.NewDevelopment()、zap.Example() 這三個方法，都可以建立 Logger。
上面三個方法都可以建立 Logger，他們都對 Logger 進行了不同的設定，比如zap.NewProduction()建立的 Logger 在記錄紀錄檔時會自動記錄呼叫函數的資訊、打紀錄檔的時間等，這三個不用糾結，直接都用zap.NewProduction()，且在專案中使用的時候，我們不會直接用 zap 設定好的 Logger ，需要再做更細緻的客製化。

zap 的 Logger 提供了記錄不同等級的紀錄檔的方法，像從低到高的紀錄檔等級一般有：Debug、Info、Warn、Error 這些級別都有對應的方法。他們的使用方式都一樣，下面是 Info 方法的方法簽名。

func (log *Logger) Info(msg string, fields ...Field) {
	if ce := log.check(InfoLevel, msg); ce != nil {
		ce.Write(fields...)
	}
}

方法的第一個引數是紀錄檔裡 msg 欄位要記錄的資訊，msg是紀錄檔行記錄裡一個固定的欄位，要再新增其他欄位到紀錄檔，直接傳遞 zap.Field 型別的引數即可，上面我們已經說過zap.Field型別的欄位，就是由 zap.String("key", "value") 這類方法建立出來的。由於 Info 方法簽名裡 fileds引數宣告是可變引數，所以支援新增任意多個欄位到紀錄檔行記錄裡，比如例程裡的：

logger.Info("Success..", zap.String("statusCode", resp.Status), zap.String("url", url))

即紀錄檔行記錄裡，除了 msg 欄位，還新增了statusCode，url兩個自定義欄位。上面例程裡使用的zap.NewProduction()建立的 Logger 會向控制檯輸出JSON格式的紀錄檔行，比如上面使用Info方法後，控制檯會有類似下面的輸出。

{"level":"info","ts":1558882294.665447,"caller":"basiclogger/UberGoLogger.go:31","msg":"Success..","statusCode":"200 OK","url":"https://www.baidu.com"}

客製化 Zap 的 Logger

下面我們把 zap 做進一步的自定義設定，讓紀錄檔不光能輸出到控制檯，也能輸出到檔案，再把紀錄檔時間由時間戳格式，換成更容易被人類看懂的DateTime時間格式。

下面少說話，直接上程式碼，必要的解釋放在了註釋裡。

var logger *zap.Logger
func init() {
	encoderConfig := zap.NewProductionEncoderConfig()
  // 設定紀錄檔記錄中時間的格式
	encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
  // 紀錄檔Encoder 還是JSONEncoder，把紀錄檔行格式化成JSON格式的
	encoder := zapcore.NewJSONEncoder(encoderConfig)
	file, _ := os.OpenFile("/tmp/test.log", os.O_CREATE|os.O_APPEND|os.O_WRONLY, 644)
	fileWriteSyncer = zapcore.AddSync(file)
	core := zapcore.NewTee(
		// 同時向控制檯和檔案寫紀錄檔， 生產環境記得把控制檯寫入去掉，紀錄檔記錄的基本是Debug 及以上，生產環境記得改成Info
		zapcore.NewCore(encoder, zapcore.AddSync(os.Stdout), zapcore.DebugLevel),
		zapcore.NewCore(encoder, fileWriteSyncer, zapcore.DebugLevel),
	)
	logger = zap.New(core)
}

紀錄檔切割

Zap 本身不支援紀錄檔切割，可以藉助另外一個庫 lumberjack 協助完成切割。

func getFileLogWriter() (writeSyncer zapcore.WriteSyncer) {
	// 使用 lumberjack 實現 log rotate
	lumberJackLogger := &lumberjack.Logger{
		Filename:   "/tmp/test.log",
		MaxSize:    100, // 單個檔案最大100M
		MaxBackups: 60, // 多於 60 個紀錄檔檔案後，清理較舊的紀錄檔
		MaxAge:     1, // 一天一切割
		Compress:   false,
	}
	return zapcore.AddSync(lumberJackLogger)
}

封裝 Logger

我們不能每次使用紀錄檔，都這麼設定一番，所以最好的還是把這些設定初始化放在一個單獨的包裡，這樣在專案中初始化一次即可。

除了上面的那些設定外，我們的設定裡還少了些紀錄檔呼叫方的資訊，比如函數名、檔案位置、行號等，這樣在排查問題看紀錄檔的時候，定位問題的時效會提高不少。

我們對 Logger 再做一下封裝。

// 傳送私信 go-logger 給公眾號「網管叨bi叨」
// 可獲得完整程式碼和使用Demo
package zlog
// 簡單封裝一下對 zap 紀錄檔庫的使用
// 使用方式：
// zlog.Debug("hello", zap.String("name", "Kevin"), zap.Any("arbitraryObj", dummyObject))
// zlog.Info("hello", zap.String("name", "Kevin"), zap.Any("arbitraryObj", dummyObject))
// zlog.Warn("hello", zap.String("name", "Kevin"), zap.Any("arbitraryObj", dummyObject))
var logger *zap.Logger
func init() {
	......
}
func getFileLogWriter() (writeSyncer zapcore.WriteSyncer) {
	......
}
func Info(message string, fields ...zap.Field) {
	callerFields := getCallerInfoForLog()
	fields = append(fields, callerFields...)
	logger.Info(message, fields...)
}
func Debug(message string, fields ...zap.Field) {
	callerFields := getCallerInfoForLog()
	fields = append(fields, callerFields...)
	logger.Debug(message, fields...)
}
func Error(message string, fields ...zap.Field) {
	callerFields := getCallerInfoForLog()
	fields = append(fields, callerFields...)
	logger.Error(message, fields...)
}
func Warn(message string, fields ...zap.Field) {
	callerFields := getCallerInfoForLog()
	fields = append(fields, callerFields...)
	logger.Warn(message, fields...)
}
func getCallerInfoForLog() (callerFields []zap.Field) {
	pc, file, line, ok := runtime.Caller(2) // 回溯兩層，拿到寫紀錄檔的呼叫方的函數資訊
	if !ok {
		return
	}
	funcName := runtime.FuncForPC(pc).Name()
	funcName = path.Base(funcName) //Base函數返回路徑的最後一個元素，只保留函數名
	callerFields = append(callerFields, zap.String("func", funcName), zap.String("file", file), zap.Int("line", line))
	return
}

為啥不用 zap.New(core, zap.AddCaller())這種方式，在紀錄檔行裡新增呼叫方的資訊呢？主要還是想更靈活點，能自己制定對應的紀錄檔欄位，所以把 Caller的幾個資訊放到單獨的欄位裡，等把紀錄檔收集到紀錄檔平臺上去後，查詢紀錄檔的時候也更利於檢索。

在下面的例程中嘗試使用我們封裝好的紀錄檔 Logger 做個簡單的測試。

package main
import (
	"example.com/utils/zlog"
)
type User strunct {
  Name  stirng
}
func main() {
  user := &User{
    "Name": "Kevin"
  }
  zlog.Info("test log", zap.Any("user", user))
}

輸出類似下面的輸出。

{"level":"info","ts":"2022-05-15T21:22:22.687+0800","msg":"test log","res":{"Name":"Kevin"},"func":"main.Main","file":"/Users/Kevin/go/src/example.com/demo/zap.go","line":84}