摘要

日誌在整個工程實踐中的重要性不言而喻，在選擇日誌元件的時候也有多方面的考量。詳細、正確和及時的反饋是必不可少的，但是整個效能表現是否也是必要考慮的點呢？在長期的實踐中發現有的日誌元件對於計算資源的消耗十分巨大，這將導致整個服務成本的居高不下。此文從設計原理深度分析了 zap 的設計與實現上的權衡，也希望整個的選擇、考量的過程能給其他的技術團隊在開發高效能的 Go 元件時帶來一定的借鑑意義。

前言

日誌作為整個程式碼行為的記錄，是程式執行邏輯和異常最直接的反饋。對於整個系統來說，日誌是至關重要的組成部分。通過分析日誌我們不僅可以發現系統的問題，同時日誌中也蘊含了大量有價值可以被挖掘的資訊，因此合理地記錄日誌是十分必要的。

我們的業務通常會記錄大量的 Debug 日誌，但在實際測試過程中，發現我們使用的日誌庫 seelog 效能存在嚴重的瓶頸，在我們的對比結果中發現：zap 表現非常突出，單執行緒 Qps 也是 logrus、seelog 的數倍。

在分析原始碼後 zap 設計與實現上的考量讓我感到受益頗多，在這裡我們主要分享一下以下幾個方面：

1. zap 為何有這麼高的效能
2. 對於我們自己的開發有什麼值得借鑑的地方
3. 如何正確的使用 Go 開發高效能的元件

為什麼選擇使用ZAP

• 它同時提供了結構化日誌記錄和printf風格的日誌記錄
• 它非常的快

根據Uber-go Zap的文件，它的效能比類似的結構化日誌包更好——也比標準庫更快。 以下是Zap釋出的基準測試資訊

記錄一條訊息和10個欄位:

記錄一個靜態字串，沒有任何上下文或printf風格的模板：

安裝

go get -u go.uber.org/zap

示例

簡單示例

格式化輸出

package main
import (
    "go.uber.org/zap"
    "time"
)
func main() {
    // zap.NewDevelopment 格式化輸出
    logger, _ := zap.ewDevelopment()
    defer logger.Sync()
    logger.Info("無法獲取網址",
        zap.String("url", "http://www.baidu.com"),
        zap.Int("attempt", 3),
        zap.Duration("backoff", time.Second),
    )
}

格式化輸出列印結果：

2019-01-02T15:01:13.923+0800    INFO    spikeProxy/main.go:17   failed to fetch URL {"url": "http://www.baidu.com", "attempt": 3, "backoff": "1s"}

json 序列化輸出

package main
import (
    "go.uber.org/zap"
    "time"
)
func main() {
   // zap.NewProduction json序列化輸出
    logger, _ := zap.NewProduction()
    defer logger.Sync()
    logger.Info("無法獲取網址",
        zap.String("url", "http://www.baidu.com"),
        zap.Int("attempt", 3),
        zap.Duration("backoff", time.Second),
    )
}

json序列化輸出列印結果：

{"level":"info","ts":1546413239.1466308,"caller":"spikeProxy/main.go:16","msg":"無法獲取網址","url":"http://www.baidu.com","attempt":3,"backoff":1}

自定義示例

選擇一個日誌庫除了高效能是考量的一個標準，高擴充套件也非常重要，例如：json key 自定義、時間格式化、日誌級別等。

package main
import (
    "go.uber.org/zap"
    "go.uber.org/zap/zapcore"
    "fmt"
    "time"
)
func main() {
    encoderConfig := zapcore.EncoderConfig{
        TimeKey:        "time",
        LevelKey:       "level",
        NameKey:        "logger",
        CallerKey:      "caller",
        MessageKey:     "msg",
        StacktraceKey:  "stacktrace",
        LineEnding:     zapcore.DefaultLineEnding,
        EncodeLevel:    zapcore.LowercaseLevelEncoder,  // 小寫編碼器
        EncodeTime:     zapcore.ISO8601TimeEncoder,     // ISO8601 UTC 時間格式
        EncodeDuration: zapcore.SecondsDurationEncoder,
        EncodeCaller:   zapcore.FullCallerEncoder,      // 全路徑編碼器
    }
    // 設定日誌級別
    atom := zap.NewAtomicLevelAt(zap.DebugLevel)
    config := zap.Config{
        Level:            atom,                                                // 日誌級別
        Development:      true,                                                // 開發模式，堆疊跟蹤
        Encoding:         "json",                                              // 輸出格式 console 或 json
        EncoderConfig:    encoderConfig,                                       // 編碼器配置
        InitialFields:    map[string]interface{}{"serviceName": "spikeProxy"}, // 初始化欄位，如：新增一個伺服器名稱
        OutputPaths:      []string{"stdout", "./logs/spikeProxy.log"},         // 輸出到指定檔案 stdout（標準輸出，正常顏色） stderr（錯誤輸出，紅色）
        ErrorOutputPaths: []string{"stderr"},
    }
    // 構建日誌
    logger, err := config.Build()
    if err != nil {
        panic(fmt.Sprintf("log 初始化失敗: %v", err))
    }
    logger.Info("log 初始化成功")
    logger.Info("無法獲取網址",
        zap.String("url", "http://www.baidu.com"),
        zap.Int("attempt", 3),
        zap.Duration("backoff", time.Second),
    )
}

列印結果：

{"level":"info","time":"2019-01-02T15:38:33.778+0800","caller":"/Users/lcl/go/src/spikeProxy/main.go:54","msg":"log 初始化成功","serviceName":"spikeProxy"}
{"level":"info","time":"2019-01-02T15:38:33.778+0800","caller":"/Users/lcl/go/src/spikeProxy/main.go:56","msg":"無法獲取網址","serviceName":"spikeProxy","url":"http://www.baidu.com","attempt":3,"backoff":1}

寫入歸檔檔案示例

安裝 lumberjack

go get gopkg.in/natefinch/lumberjack.v2

lumberjack介紹

Lumberjack是一個Go包，用於將日誌寫入滾動檔案。
zap 不支援檔案歸檔，如果要支援檔案按大小或者時間歸檔，需要使用lumberjack，lumberjack也是zap官方推薦的。

示例

package main
import (
    "go.uber.org/zap"
    "go.uber.org/zap/zapcore"
    "time"
    "gopkg.in/natefinch/lumberjack.v2"
    "os"
)
func main() {
    hook := lumberjack.Logger{
        Filename:   "./logs/spikeProxy1.log", // 日誌檔案路徑
        MaxSize:    128,                      // 每個日誌檔案儲存的最大尺寸 單位：M
        MaxBackups: 30,                       // 日誌檔案最多儲存多少個備份
        MaxAge:     7,                        // 檔案最多儲存多少天
        Compress:   true,                     // 是否壓縮
    }
    encoderConfig := zapcore.EncoderConfig{
        TimeKey:        "time",
        LevelKey:       "level",
        NameKey:        "logger",
        CallerKey:      "linenum",
        MessageKey:     "msg",
        StacktraceKey:  "stacktrace",
        LineEnding:     zapcore.DefaultLineEnding,
        EncodeLevel:    zapcore.LowercaseLevelEncoder,  // 小寫編碼器
        EncodeTime:     zapcore.ISO8601TimeEncoder,     // ISO8601 UTC 時間格式
        EncodeDuration: zapcore.SecondsDurationEncoder, //
        EncodeCaller:   zapcore.FullCallerEncoder,      // 全路徑編碼器
        EncodeName:     zapcore.FullNameEncoder,
    }
    // 設定日誌級別
    atomicLevel := zap.NewAtomicLevel()
    atomicLevel.SetLevel(zap.InfoLevel)
    core := zapcore.NewCore(
        zapcore.NewJSONEncoder(encoderConfig),                                           // 編碼器配置
        zapcore.NewMultiWriteSyncer(zapcore.AddSync(os.Stdout), zapcore.AddSync(&hook)), // 列印到控制檯和檔案
        atomicLevel,                                                                     // 日誌級別
    )
    // 開啟開發模式，堆疊跟蹤
    caller := zap.AddCaller()
    // 開啟檔案及行號
    development := zap.Development()
    // 設定初始化欄位
    filed := zap.Fields(zap.String("serviceName", "serviceName"))
    // 構造日誌
    logger := zap.New(core, caller, development, filed)
    logger.Info("log 初始化成功")
    logger.Info("無法獲取網址",
        zap.String("url", "http://www.baidu.com"),
        zap.Int("attempt", 3),
        zap.Duration("backoff", time.Second))
}

控制檯列印結果：

{"level":"info","time":"2019-01-02T16:14:43.608+0800","linenum":"/Users/lcl/go/src/spikeProxy/main.go:56","msg":"log 初始化成功","serviceName":"serviceName"}
{"level":"info","time":"2019-01-02T16:14:43.608+0800","linenum":"/Users/lcl/go/src/spikeProxy/main.go:57","msg":"無法獲取網址","serviceName":"serviceName","url":"http://www.baidu.com","attempt":3,"backoff":1}

檔案列印結果：

{"level":"info","time":"2019-01-02T16:14:43.608+0800","linenum":"/Users/lcl/go/src/spikeProxy/main.go:56","msg":"log 初始化成功","serviceName":"serviceName"}
{"level":"info","time":"2019-01-02T16:14:43.608+0800","linenum":"/Users/lcl/go/src/spikeProxy/main.go:57","msg":"無法獲取網址","serviceName":"serviceName","url":"http://www.baidu.com","attempt":3,"backoff":1}

gin框架使用zap+lumberjack

初始化zap,lumberjack

// viperconfig
type Log struct {
	FileName   string `yaml:"filename"`
	MaxSize    int    `yaml:"maxsize"`
	MaxBackups int    `yaml:"maxbackups"`
	MaxAges    int    `yaml:"maxages"`
	Compress   bool   `yaml:"compress"`
	Level      string `yaml:"-"`
}

// init
var ZapLog *zap.Logger
// InitLogger 初始化Logger
func InitLogger(cfg *viperConfig.Log) (err error) {
	writeSyncer := getLogWriter(cfg.FileName, cfg.MaxSize, cfg.MaxBackups, cfg.MaxAges)
	encoder := getEncoder()
	var l = new(zapcore.Level)
	err = l.UnmarshalText([]byte(cfg.Level))
	if err != nil {
		return
	}
	core := zapcore.NewCore(encoder, writeSyncer, l)
	ZapLog = zap.New(core, zap.AddCaller())
	zap.ReplaceGlobals(ZapLog) // 替換zap包中全域性的logger例項，後續在其他包中只需使用zap.L()呼叫即可
	return
}
func getEncoder() zapcore.Encoder {
	encoderConfig := zap.NewProductionEncoderConfig()
	encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
	encoderConfig.TimeKey = "time"
	encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder
	encoderConfig.EncodeDuration = zapcore.SecondsDurationEncoder
	encoderConfig.EncodeCaller = zapcore.ShortCallerEncoder
	return zapcore.NewJSONEncoder(encoderConfig)
}
func getLogWriter(filename string, maxSize, maxBackup, maxAge int) zapcore.WriteSyncer {
	lumberJackLogger := &lumberjack.Logger{
		Filename:   filename,
		MaxSize:    maxSize,
		MaxBackups: maxBackup,
		MaxAge:     maxAge,
	}
	return zapcore.AddSync(lumberJackLogger)
}

gin日誌中介軟體

模仿Logger()和Recovery()的實現，使用我們的日誌庫來接收gin框架預設輸出的日誌。

// GinLogger 接收gin框架預設的日誌
func GinLogger(logger *zap.Logger) gin.HandlerFunc {
	return func(c *gin.Context) {
		start := time.Now()
		path := c.Request.URL.Path
		query := c.Request.URL.RawQuery
		c.Next()
		cost := time.S***art)
		logger.Info(path,
			zap.Int("status", c.Writer.Status()),
			zap.String("method", c.Request.Method),
			zap.String("path", path),
			zap.String("query", query),
			zap.String("ip", c.ClientIP()),
			zap.String("user-agent", c.Request.UserAgent()),
			zap.String("errors", c.Errors.ByType(gin.ErrorTypePrivate).String()),
			zap.Duration("cost", cost),
		)
	}
}
// GinRecovery recover掉專案可能出現的panic
func GinRecovery(logger *zap.Logger, stack bool) gin.HandlerFunc {
	return func(c *gin.Context) {
		defer func() {
			if err := recover(); err != nil {
				// Check for a broken connection, as it is not really a
				// condition that warrants a panic stack trace.
				var brokenPipe bool
				if ne, ok := err.(*net.OpError); ok {
					if se, ok := ne.Err.(*os.SyscallError); ok {
						if strings.Contains(strings.ToLower(se.Error()), "broken pipe") || strings.Contains(strings.ToLower(se.Error()), "connection reset by peer") {
							brokenPipe = true
						}
					}
				}
				httpRequest, _ := httputil.DumpRequest(c.Request, false)
				if brokenPipe {
					logger.Error(c.Request.URL.Path,
						zap.Any("error", err),
						zap.String("request", string(httpRequest)),
					)
					// If the connection is dead, we can't write a status to it.
					c.Error(err.(error)) // nolint: errcheck
					c.Abort()
					return
				}
				if stack {
					logger.Error("[Recovery from panic]",
						zap.Any("error", err),
						zap.String("request", string(httpRequest)),
						zap.String("stack", string(debug.Stack())),
					)
				} else {
					logger.Error("[Recovery from panic]",
						zap.Any("error", err),
						zap.String("request", string(httpRequest)),
					)
				}
				c.AbortWithStatus(http.StatusInternalServerError)
			}
		}()
		c.Next()
	}
}

使用

// 全域性中介軟體
func InitMiddleWares(eng *gin.Engine) {
	eng.Use(GinLogger(log.ZapLog), GinRecovery(log.ZapLog, true))
}

參考文章:

• https://mp.weixin.qq.com/s/i0bMh_gLLrdnhAEWlF-xDw
• https://studygolang.com/articles/17394