高效能 Go 日誌庫 zap 設計與實現

轉載請宣告出處哦~，本篇文章釋出於luozhiyun的部落格：https://www.luozhiyun.com/archives/542

最近我也在學習如何在開發中讓程式碼執行更加高效，然後在瀏覽各種優秀的日誌設計的時候看到 uber 有一個叫 zap 的日誌庫引起了我的注意，它主要特性是對效能和記憶體分配都做到了極致的優化。

對於我來說，原本在專案中是使用 logrus 來作為日誌輸出，但是看到 zap 的 benchmark，感覺在效能方面甩 logrus 不知道多少條街，所以這也是驅使我來看看它是如何進行優化的原因。

當然除了這個問題以外，還是想更有把握地熟悉它，以便能更高效地利用這個庫，以及避免在出現問題的時候無法定位。

下面先放一下比較唬人的 benchmark ，給大家提供一下看下去的動力：

Package	Time	Time % to zap	Objects Allocated
⚡ zap	862 ns/op	+0%	5 allocs/op
⚡ zap (sugared)	1250 ns/op	+45%	11 allocs/op
zerolog	4021 ns/op	+366%	76 allocs/op
go-kit	4542 ns/op	+427%	105 allocs/op
apex/log	26785 ns/op	+3007%	115 allocs/op
logrus	29501 ns/op	+3322%	125 allocs/op
log15	29906 ns/op	+3369%	122 allocs/op

zap 設計

log 的例項化

在開始使用的時候，我們可以通過官方的例子來了解 zap 內部的元件：

log := zap.NewExample()

NewExample 函式裡面展示了要通過 NewCore 來建立一個 Core 結構體，根據名字我們應該也能猜到這個結構體是 zap 的核心。

對於一個日誌庫來說，最主要是無非是這三類：

1. 對於輸入的資料需要如何序列化；
2. 將輸入的資料序列化後存放到哪裡，是控制檯還是檔案，還是別的地方；
3. 然後就是日誌的級別，是 Debug、Info 亦或是 Error；

同理 zap 也是這樣，在使用 NewCore 建立 Core 結構體的時候需要傳入的三個引數分別對應的就是：輸入資料的編碼器 Encoder、日誌資料的目的地 WriteSyncer，以及日誌級別 LevelEnabler。

除了 NewExample 這個構造方法以外，zap 還提供了 NewProduction、NewDevelopment 來構造日誌例項：

log, _  = zap.NewProduction()
log, _  = zap.NewDevelopment()

這兩個函式會通過構建一個 Config 結構體然後呼叫 Build 方法來建立 NewCore 所需要的引數，然後例項化日誌例項。

日誌資料的輸出

在初始化 log 例項之後，可以用 Info、Debug、Error等方法列印日誌：

	log  = zap.NewExample()
	url := "http://example.org/api"
	log.Info("failed to fetch URL",
		zap.String("url", url),
		zap.Int("attempt", 3),
		zap.Duration("backoff", time.Hour),
	)

我們再來看一下 zap 列印一條結構化的日誌的實現步驟：

1. 首先會校驗一下日誌配置的等級，例如 Error 日誌配置等級肯定是不能輸出 Debug 日誌出來；
2. 然後會將日誌資料封裝成一個 Entry 例項；
3. 因為在 zap 中可以傳入 multiCore，所以會把多個 Core 新增到 CheckedEntry 例項中；
4. 遍歷 CheckedEntry 例項中 Cores，
   1. 根據 Core 中的 Encoder 來序列化日誌資料到 Buffer 中；
   2. 再由 WriteSyncer 將 Buffer 的日誌資料進行輸出；

介面與框架設計

在程式碼結構設計上，通過簡單的介面封裝，實現了多種樣式的配置組合，從而滿足各種需求。在最上層的設計上實現了三種 log 用來實現不同的功能：

Logger：使用較為繁瑣，只能使用結構化輸出，但是效能更好；

SugaredLogger：可以使用 Printf 來輸出日誌，效能較 Logger 相比差 40% 左右；

zapgrpc：用做 grpc 的日誌輸出；

在設計上 Logger 可以很方便的轉化為 SugaredLogger 和 zapgrpc。這幾個 Logger 需要傳入一個 Core 介面的實現類才能建立。

Core 介面：zap 也提供了多種實現的選擇：NewNopCore 、ioCore、multiCore 、hook。

最常用的是 ioCore、multiCore ，從名字便可看出來 multiCore 是可以包含多個 ioCore 的一種配置，比方說可以讓 Error 日誌輸出一種日誌格式以及設定一個日誌輸出目的地，讓 Info 日誌以另一種日誌格式輸出到別的地方。

在上面也說了，對於 Core 的實現類 ioCore 來說它需要傳入三個物件：輸入資料的編碼器 Encoder、日誌資料的目的地 WriteSyncer，以及日誌級別 LevelEnabler。

Encoder 介面：zap 提供了 consoleEncoder、jsonEncoder 的實現，分別提供了 console 格式與 JSON 格式日誌輸出，這些 Encoder 都有自己的序列化實現，這樣可以更快的格式化程式碼；

EncoderConfig：上面所說的 Encoder 還可以根據 EncoderConfig 的配置允許使用者靈活的配置日誌的輸出格式，從日誌訊息的鍵名、日誌等級名稱，到時間格式輸出的定義，方法名的定義都可以通過它靈活配置。

WriteSyncer 介面：zap 提供了 writerWrapper 的單日誌輸出實現，以及可以將日誌輸出到多個地方的 multiWriteSyncer 實現；

Entry ：配置說完了，到了日誌資料的封裝。首先日誌資料會封裝成一個 Entry，包含了日誌名、日誌時間、日誌等級，以及日誌資料等資訊，沒有 Field 資訊，然後經驗 Core 的 Check 方法對日誌等級校驗通過之後會生成一個 CheckedEntry 例項。

CheckedEntry 包含了日誌資料所有資訊，包括上面提到的 Entry、呼叫棧資訊等。

效能

使用物件池

zap 通過 sync.Pool 提供的物件池，複用了大量可以複用的物件，如果對 sync.Pool 不是很瞭解的同學，可以看這篇文章：《多圖詳解Go的sync.Pool原始碼 https://www.luozhiyun.com/archives/416 》。

zap 在例項化 CheckedEntry 、Buffer、Encoder 等物件的時候，會直接從物件池中獲取，而不是直接例項化一個新的，這樣複用物件可以降低 GC 的壓力，減少記憶體分配。

避免反射

如果我們使用官方的 log 庫，像這樣輸出日誌：

log.Printf("%s login, age:%d", "luoluo", 19)

log 呼叫的 Printf 函式實際上會呼叫 fmt.Sprintf函式來格式化日誌資料，然後進行輸出：

func Printf(format string, v ...interface{}) {
	std.Output(2, fmt.Sprintf(format, v...))
}

但是fmt.Sprintf效率實際上是很低的，通過檢視fmt.Sprintf原始碼， 可以看出效率低有兩個原因：

1. fmt.Sprintf 接受的型別是 interface{}，內部使用了反射；
2. fmt.Sprintf 的用途是格式化字串，需要去解析格式串，比如 %s、 %d之類的，增加了解析的耗時。

但是在 zap 中，使用的是內建的 Encoder，它會通過內部的 Buffer 以 byte 的形式來拼接日誌資料，減少反射所帶來效能損失；以及 zap 是使用的結構化的日誌，所以沒有 %s、 %d之類的識別符號需要解析，也是一個效能提升點。

更高效且靈活的序列化器

在 zap 中自己實現了 consoleEncoder、jsonEncoder 兩個序列化器，這兩個序列化器都可以根據傳入的 EncoderConfig 來實現日誌格式的靈活配置，這個靈活配置不只是日誌輸出的 key 的名稱，而是通過在 EncoderConfig 中傳入函式來呼叫到使用者自定義的 Encoder 實現。

而像 logrus 在序列化 JSON 的時候使用的是標準庫的序列化工具，效率也是更低。

zap 程式碼分析

由於我感覺 zap 的程式碼還是寫的比較優雅的，所以這裡稍微分析一些原始碼。

初始化

初始化 Core

我們在上面的圖中也瞭解到，Core 是有 4個實現類，我們這裡以最常用的 ioCore 作為例子來進行講解。

type ioCore struct {
	LevelEnabler
	enc Encoder
	out WriteSyncer
}

ioCore 裡面非常簡單，總共需要三個欄位，分別是：輸入資料的編碼器 Encoder、日誌資料的目的地 WriteSyncer，以及日誌級別 LevelEnabler。

func NewCore(enc Encoder, ws WriteSyncer, enab LevelEnabler) Core {
	return &ioCore{
		LevelEnabler: enab,
		enc:          enc,
		out:          ws,
	}
}

在使用 NewCore 函式建立 ioCore 的時候也是返回一個物件指標。

初始化 Logger

zap 會通過 New 函式來例項化一個 Logger：

func New(core zapcore.Core, options ...Option) *Logger {
	if core == nil {
		return NewNop()
	}
	log := &Logger{
		core:        core,
		errorOutput: zapcore.Lock(os.Stderr),
		addStack:    zapcore.FatalLevel + 1,
		clock:       _systemClock,
	}
	return log.WithOptions(options...)
}

New 函式會設定好相應的預設欄位，包括 core 例項、錯誤日誌輸出地、堆疊日誌的輸出級別、日誌時間等，然後例項化一個 Logger 物件返回指標。

Logger 結構的資訊如下：

type Logger struct {
	core zapcore.Core
	// 是否是開發模式
	development bool
	// 是否列印行號
	addCaller   bool
	onFatal     zapcore.CheckWriteAction // default is WriteThenFatal

	name        string
	// 錯誤日誌輸出
	errorOutput zapcore.WriteSyncer
	// 輸出呼叫堆疊
	addStack zapcore.LevelEnabler
	// 列印呼叫者的行號
	callerSkip int

	clock Clock
}

Logger 結構體中會包含很多配置資訊，我們在開發中可以通過 WithOptions 來新增相應的引數。如新增日誌行號：

log := zap.New(core).WithOptions(zap.AddCaller())

AddCaller 函式會建立一個回撥鉤子給 WithOptions 執行，這也是函數語言程式設計的魅力所在：

func (log *Logger) WithOptions(opts ...Option) *Logger {
	c := log.clone()
	for _, opt := range opts {
    // 呼叫 Option 介面的方法 
		opt.apply(c)
	}
	return c
}

WithOptions 可以傳入 Option 陣列，然後遍歷陣列並呼叫 apply 方法，Option 是一個介面，只提供了 apply 方法：

type optionFunc func(*Logger)

func (f optionFunc) apply(log *Logger) {
	f(log)
}
// 定義 Option 介面
type Option interface {
	apply(*Logger)
}

func AddCaller() Option {
  // 返回 Option
	return WithCaller(true)
}

func WithCaller(enabled bool) Option {
  // 將 func 強轉成 optionFunc 型別
	return optionFunc(func(log *Logger) {
		log.addCaller = enabled
	})
}

這裡這個程式碼寫的非常有意思，在 go 中一個函式也是一種型別，和 struct 一樣可以用有一個方法。

在這裡 optionFunc 作為一種函式型別，它實現了 apply 方法，所以相當於繼承了 Option 這個介面。然後在 WithCaller 中使用 optionFunc 將一個函式包了一層，看起來有些奇妙，但是實際上和 int64(123)沒有本質區別。

然後在 WithOptions 函式中會獲取到 WithCaller 返回的這個轉成 optionFunc 型別的函式，並傳入 log 執行，這樣就相當於改變了 log 的 addCaller 屬性。

沒看懂的可以自己在編譯器上試一下。

列印日誌

整個列印日誌的過程如下：

1. 首先是獲取 CheckedEntry 例項，封裝相應的日誌資料；
2. 然後根據 core 裡面封裝的 encoder 進行編碼，將編碼的內容放入到 buffer 中；
3. 將 buffer 中的內容輸出到 core 裡封裝的 WriteSyncer 中。

在我們初始化完成 Logger 後，就可以使用它來呼叫相應的 Info、Warn、Error 等方法列印日誌輸出。由於所有的日誌級別的輸出方法是一樣的，所以這裡通過 Info 方法來進行分析。

func (log *Logger) Info(msg string, fields ...Field) {
    // 檢查該日誌是否應該被列印
	if ce := log.check(InfoLevel, msg); ce != nil {
        // 列印日誌
		ce.Write(fields...)
	}
}

這個方法首先會呼叫 check 方法進行校驗，主要是檢視在配置的日誌等級下當前日誌資料是否應該被列印。

對於 Info 日誌級別來說會傳入 InfoLevel，Error 日誌級別來說會傳入 ErrorLevel，在 zap 裡面日誌級別是通過這幾個常量來進行定義：

type Level int8

const ( 
	DebugLevel Level = iota - 1 
	InfoLevel 
	WarnLevel 
	ErrorLevel 
	DPanicLevel 
	PanicLevel 
	FatalLevel

	_minLevel = DebugLevel
	_maxLevel = FatalLevel
)

最小的 DebugLevel 從 -1 開始。

check 檢查

func (log *Logger) check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry { 
	const callerSkipOffset = 2
	// 判斷傳入的日誌等級是否應該列印
	if lvl < zapcore.DPanicLevel && !log.core.Enabled(lvl) {
		return nil
	}
 
	// 將日誌資料封裝成一個 Entry
	ent := zapcore.Entry{
		LoggerName: log.name,
		Time:       log.clock.Now(),
		Level:      lvl,
		Message:    msg,
	}
	//如果能寫日誌則返回一個 CheckedEntry 例項指標
	ce := log.core.Check(ent, nil)
	willWrite := ce != nil 
	... 
	if !willWrite {
		return ce
	}
 
	ce.ErrorOutput = log.errorOutput
	// 判斷是否列印呼叫行號
	if log.addCaller {
		// 獲取呼叫者的棧幀
		frame, defined := getCallerFrame(log.callerSkip + callerSkipOffset)
		if !defined {
			fmt.Fprintf(log.errorOutput, "%v Logger.check error: failed to get caller\n", ent.Time.UTC())
			log.errorOutput.Sync()
		}
		// 設值呼叫者 entry
		ce.Entry.Caller = zapcore.EntryCaller{
			Defined:  defined,
			PC:       frame.PC,
			File:     frame.File,
			Line:     frame.Line,
			Function: frame.Function,
		}
	}
	if log.addStack.Enabled(ce.Entry.Level) {
		// 封裝呼叫棧資訊
		ce.Entry.Stack = StackSkip("", log.callerSkip+callerSkipOffset).String
	} 
	return ce
}

這裡首先會呼叫 core 的 Enabled 方法判斷一下該日誌是否應該被列印。這個判斷由於日誌等級實際上是一個 int8 型別的，所以直接根據大小直接就可以判斷。

func (l Level) Enabled(lvl Level) bool {
	return lvl >= l
}

判斷完沒有問題會呼叫 Check 方法獲取 CheckedEntry 例項指標。獲取完 CheckedEntry 例項指標後會根據配置資訊設值，然後返回。

下面看看是如何獲取 CheckedEntry 例項指標。

func (c *ioCore) Check(ent Entry, ce *CheckedEntry) *CheckedEntry {
	// 檢查該 level 日誌是否應該被列印
	if c.Enabled(ent.Level) {
		// 獲取 CheckedEntry
		return ce.AddCore(ent, c)
	}
	return ce
}

這裡會通過 CheckedEntry 的 AddCore 方法獲取，需要主要的是傳入的 ce 是個 nil 指標，但是這樣也不方便 Go 呼叫其 AddCore 方法（要是放在 java 上該報錯了）。

var (
	_cePool = sync.Pool{New: func() interface{} {
		// Pre-allocate some space for cores.
		return &CheckedEntry{
			cores: make([]Core, 4),
		}
	}}
)

func (ce *CheckedEntry) AddCore(ent Entry, core Core) *CheckedEntry {
	if ce == nil {
		// 從 _cePool 裡面獲取 CheckedEntry 例項
		ce = getCheckedEntry()
		ce.Entry = ent
	}
    // 因為可能為 multi core 所以這裡需要 append 一下
	ce.cores = append(ce.cores, core)
	return ce
}

func getCheckedEntry() *CheckedEntry {
	// 從 pool 中獲取物件
	ce := _cePool.Get().(*CheckedEntry)
	// 重置物件的屬性
	ce.reset()
	return ce
}

AddCore 方法也是十分簡潔，大家應該看一眼就明白了，不多說。

Write 日誌列印

func (ce *CheckedEntry) Write(fields ...Field) {
	if ce == nil {
		return
	}
	... 
	var err error
	// 遍歷所有 core 寫入日誌資料
	for i := range ce.cores {
		err = multierr.Append(err, ce.cores[i].Write(ce.Entry, fields))
	}
	...
	// 將 CheckedEntry 放回到快取池中
	putCheckedEntry(ce)
	...
}

這裡就是呼叫 core 的 Write 方法寫日誌資料，繼續往下。

func (c *ioCore) Write(ent Entry, fields []Field) error {
	// 呼叫 Encoder 的 EncodeEntry 方法將日誌資料編碼
	buf, err := c.enc.EncodeEntry(ent, fields)
	if err != nil {
		return err
	}
	// 將日誌資料通過 WriteSyncer 寫入
	_, err = c.out.Write(buf.Bytes())
	// 將buffer放回到快取池中
	buf.Free()
	if err != nil {
		return err
	}
	if ent.Level > ErrorLevel {
		c.Sync()
	}
	return nil
}

Write 方法會根據編碼器的不同，然後呼叫相應編碼器的 EncodeEntry 方法。無論是 jsonEncoder 還是 consoleEncoder 都會在 EncodeEntry 方法中從 bufferpool 獲取一個 Buffer 例項，然後將資料按照一定的格式封裝到 Buffer 例項中。

獲取到資料後，會呼叫 WriteSyncer 的 Write 方法將日誌資料寫入。

最後將 Buffer 例項釋放回 bufferpool 中。

總結

這篇文章主要講解了 zap 的設計原理以及程式碼的實現。我們可以看到它通過編碼結構上的設計使得可以通過簡單的配置從而實現豐富的功能。在效能方面，主要是通過使用物件池，減少記憶體分配的開銷；內建高效能序列化器，減少在序列化上面的開銷；以及通過結構化的日誌格式，減少 fmt.Sprintf格式化日誌資料的開銷。

Reference

https://mp.weixin.qq.com/s/i0bMh_gLLrdnhAEWlF-xDw

https://segmentfault.com/a/1190000022461706

https://github.com/uber-go/zap