高性能 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