golang - zap usage - 《gogogo》

Uber-go Zap
使用Lumberjack进行日志切割归档
gin中集成zap
参考链接：

本文介绍了非常流行的Uber开源的zap日志库，同时介绍了如何搭配Lumberjack实现日志的切割和归档以及在gin中集成zap和使用。

Uber-go Zap

Zap是非常快的、结构化的，分日志级别的Go日志库。

它同时提供了结构化日志记录和printf风格的日志记录
它非常的快

日志级别

DEBUG：输出调试信息；指出细粒度信息事件对调试应用程序是非常有帮助的。
INFO：输出提示信息；消息在粗粒度级别上突出强调应用程序的运行过程。
WARN：输出警告信息；表明会出现潜在错误的情形。
ERROR：输出错误信息；指出虽然发生错误事件，但仍然不影响系统的继续运行。
按照范围从小到大排序： ERROR > WARN > INFO > DEBUG；范围大的会包含范围小的，例如日志设置为INFO级别的话，则ERROR、WARN、INFO的日志开关都是打开的，而DEBUG的日志开关将是关闭的。

安装

运行下面的命令安装zap

go get -u go.uber.org/zap

配置Zap Logger

Zap提供了两种类型的日志记录器—Sugared Logger和Logger。

在性能很好但不是很关键的上下文中，使用SugaredLogger。它比其他结构化日志记录包快4-10倍，并且支持结构化和printf风格的日志记录。

在每一微秒和每一次内存分配都很重要的上下文中，使用Logger。它甚至比SugaredLogger更快，内存分配次数也更少，但它只支持强类型的结构化日志记录。

Logger

通过调用zap.NewProduction()/zap.NewDevelopment()或者zap.Example()创建一个Logger。
上面的每一个函数都将创建一个logger。唯一的区别在于它将记录的信息不同。例如production logger默认记录调用函数信息、日期和时间等。
通过Logger调用Info/Error等。
默认情况下日志都会打印到应用程序的console界面。

var logger *zap.Logger
func main() {
    InitLogger()
  defer logger.Sync()
    simpleHttpGet("www.google.com")
    simpleHttpGet("http://www.google.com")
}
func InitLogger() {
    logger, _ = zap.NewProduction()
}
func simpleHttpGet(url string) {
    resp, err := http.Get(url)
    if err != nil {
        logger.Error(
            "Error fetching url..",
            zap.String("url", url),
            zap.Error(err))
    } else {
        logger.Info("Success..",
            zap.String("statusCode", resp.Status),
            zap.String("url", url))
        resp.Body.Close()
    }
}

在上面的代码中，我们首先创建了一个Logger，然后使用Info/ Error等Logger方法记录消息。

日志记录器方法的语法是这样的：

func (log *Logger) MethodXXX(msg string, fields ...Field)

其中MethodXXX是一个可变参数函数，可以是Info / Error/ Debug / Panic等。每个方法都接受一个消息字符串和任意数量的zapcore.Field场参数。

每个zapcore.Field其实就是一组键值对参数。

我们执行上面的代码会得到如下输出结果：

{"level":"error","ts":1572159218.912792,"caller":"zap_demo/temp.go:25","msg":"Error fetching url..","url":"www.sogo.com","error":"Get www.sogo.com: unsupported protocol scheme \"\"","stacktrace":"main.simpleHttpGet\n\t/Users/q1mi/zap_demo/temp.go:25\nmain.main\n\t/Users/q1mi/zap_demo/temp.go:14\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:203"}
{"level":"info","ts":1572159219.1227388,"caller":"zap_demo/temp.go:30","msg":"Success..","statusCode":"200 OK","url":"http://www.sogo.com"}

Sugared Logger

现在让我们使用Sugared Logger来实现相同的功能。

大部分的实现基本都相同。
惟一的区别是，我们通过调用主logger的. Sugar()方法来获取一个SugaredLogger。
然后使用SugaredLogger以printf格式记录语句

下面是修改过后使用SugaredLogger代替Logger的代码：

var sugarLogger *zap.SugaredLogger
func main() {
    InitLogger()
    defer sugarLogger.Sync()
    simpleHttpGet("www.google.com")
    simpleHttpGet("http://www.google.com")
}
func InitLogger() {
  logger, _ := zap.NewProduction()
    sugarLogger = logger.Sugar()
}
func simpleHttpGet(url string) {
    sugarLogger.Debugf("Trying to hit GET request for %s", url)
    resp, err := http.Get(url)
    if err != nil {
        sugarLogger.Errorf("Error fetching URL %s : Error = %s", url, err)
    } else {
        sugarLogger.Infof("Success! statusCode = %s for URL %s", resp.Status, url)
        resp.Body.Close()
    }
}

当你执行上面的代码会得到如下输出：

{"level":"error","ts":1572159149.923002,"caller":"logic/temp2.go:27","msg":"Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme \"\"","stacktrace":"main.simpleHttpGet\n\t/Users/q1mi/zap_demo/logic/temp2.go:27\nmain.main\n\t/Users/q1mi/zap_demo/logic/temp2.go:14\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:203"}
{"level":"info","ts":1572159150.192585,"caller":"logic/temp2.go:29","msg":"Success! statusCode = 200 OK for URL http://www.sogo.com"}

定制logger

将日志写入文件而不是终端

我们要做的第一个更改是把日志写入文件，而不是打印到应用程序控制台。

我们将使用zap.New(…)方法来手动传递所有配置，而不是使用像zap.NewProduction()这样的预置方法来创建logger。

func New(core zapcore.Core, options ...Option) *Logger

zapcore.Core需要三个配置——Encoder，WriteSyncer，LogLevel。

1.Encoder:编码器(如何写入日志)。我们将使用开箱即用的NewJSONEncoder()，并使用预先设置的ProductionEncoderConfig()。

   zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig())

2.WriterSyncer ：指定日志将写到哪里去。我们使用zapcore.AddSync()函数并且将打开的文件句柄传进去。=

   file, _ := os.Create("./test.log")
   writeSyncer := zapcore.AddSync(file)

3.Log Level：哪种级别的日志将被写入。

我们将修改上述部分中的Logger代码，并重写InitLogger()方法。其余方法—main() /SimpleHttpGet()保持不变。

func InitLogger() {
    writeSyncer := getLogWriter()
    encoder := getEncoder()
    core := zapcore.NewCore(encoder, writeSyncer, zapcore.DebugLevel)
    logger := zap.New(core)
    sugarLogger = logger.Sugar()
}
func getEncoder() zapcore.Encoder {
    return zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig())
}
func getLogWriter() zapcore.WriteSyncer {
    file, _ := os.Create("./test.log")
    return zapcore.AddSync(file)
}

当使用这些修改过的logger配置调用上述部分的main()函数时，以下输出将打印在文件——test.log中。

{"level":"debug","ts":1572160754.994731,"msg":"Trying to hit GET request for www.sogo.com"}
{"level":"error","ts":1572160754.994982,"msg":"Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme \"\""}
{"level":"debug","ts":1572160754.994996,"msg":"Trying to hit GET request for http://www.sogo.com"}
{"level":"info","ts":1572160757.3755069,"msg":"Success! statusCode = 200 OK for URL http://www.sogo.com"}

将JSON Encoder更改为普通的Log Encoder

现在，我们希望将编码器从JSON Encoder更改为普通Encoder。为此，我们需要将NewJSONEncoder()更改为NewConsoleEncoder()。

return zapcore.NewConsoleEncoder(zap.NewProductionEncoderConfig())

当使用这些修改过的logger配置调用上述部分的main()函数时，以下输出将打印在文件——test.log中。

1.572161051846623e+09    debug    Trying to hit GET request for www.sogo.com
1.572161051846828e+09    error    Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme ""
1.5721610518468401e+09    debug    Trying to hit GET request for http://www.sogo.com
1.572161052068744e+09    info    Success! statusCode = 200 OK for URL http://www.sogo.com

更改时间编码并添加调用者详细信息

鉴于我们对配置所做的更改，有下面两个问题：

时间是以非人类可读的方式展示，例如1.572161051846623e+09
调用方函数的详细信息没有显示在日志中

我们要做的第一件事是覆盖默认的ProductionConfig()，并进行以下更改:

修改时间编码器
在日志文件中使用大写字母记录日志级别

func getEncoder() zapcore.Encoder {
    encoderConfig := zap.NewProductionEncoderConfig()
    encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
    encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder
    return zapcore.NewConsoleEncoder(encoderConfig)
}

接下来，我们将修改zap logger代码，添加将调用函数信息记录到日志中的功能。为此，我们将在zap.New(..)函数中添加一个Option。

logger := zap.New(core, zap.AddCaller())

当使用这些修改过的logger配置调用上述部分的main()函数时，以下输出将打印在文件——test.log中。

2019-10-27T15:33:29.855+0800    DEBUG    logic/temp2.go:47    Trying to hit GET request for www.sogo.com
2019-10-27T15:33:29.855+0800    ERROR    logic/temp2.go:50    Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme ""
2019-10-27T15:33:29.856+0800    DEBUG    logic/temp2.go:47    Trying to hit GET request for http://www.sogo.com
2019-10-27T15:33:30.125+0800    INFO    logic/temp2.go:52    Success! statusCode = 200 OK for URL http://www.sogo.com

使用Lumberjack进行日志切割归档

这个日志程序中唯一缺少的就是日志切割归档功能。

Zap本身不支持切割归档日志文件

为了添加日志切割归档功能，我们将使用第三方库Lumberjack来实现。

安装

执行下面的命令安装Lumberjack

go get -u github.com/natefinch/lumberjack

zap logger中加入Lumberjack

要在zap中加入Lumberjack支持，我们需要修改WriteSyncer代码。我们将按照下面的代码修改getLogWriter()函数：

func getLogWriter() zapcore.WriteSyncer {
    lumberJackLogger := &lumberjack.Logger{
        Filename:   "./test.log",
        MaxSize:    10,
        MaxBackups: 5,
        MaxAge:     30,
        Compress:   false,
    }
    return zapcore.AddSync(lumberJackLogger)
}

Lumberjack Logger采用以下属性作为输入:

Filename: 日志文件的位置
MaxSize：在进行切割之前，日志文件的最大大小（以MB为单位）
MaxBackups：保留旧文件的最大个数
MaxAges：保留旧文件的最大天数
Compress：是否压缩/归档旧文件

测试所有功能

最终，使用Zap/Lumberjack logger的完整示例代码如下：

package main
import (
    "net/http"
    "github.com/natefinch/lumberjack"
    "go.uber.org/zap"
    "go.uber.org/zap/zapcore"
)
var sugarLogger *zap.SugaredLogger
func main() {
    InitLogger()
    defer sugarLogger.Sync()
    simpleHttpGet("www.sogo.com")
    simpleHttpGet("http://www.sogo.com")
}
func InitLogger() {
    writeSyncer := getLogWriter()
    encoder := getEncoder()
    core := zapcore.NewCore(encoder, writeSyncer, zapcore.DebugLevel)
    logger := zap.New(core, zap.AddCaller())
    sugarLogger = logger.Sugar()
}
func getEncoder() zapcore.Encoder {
    encoderConfig := zap.NewProductionEncoderConfig()
    encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
    encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder
    return zapcore.NewConsoleEncoder(encoderConfig)
}
func getLogWriter() zapcore.WriteSyncer {
    lumberJackLogger := &lumberjack.Logger{
        Filename:   "./test.log",
        MaxSize:    1,
        MaxBackups: 5,
        MaxAge:     30,
        Compress:   false,
    }
    return zapcore.AddSync(lumberJackLogger)
}
func simpleHttpGet(url string) {
    sugarLogger.Debugf("Trying to hit GET request for %s", url)
    resp, err := http.Get(url)
    if err != nil {
        sugarLogger.Errorf("Error fetching URL %s : Error = %s", url, err)
    } else {
        sugarLogger.Infof("Success! statusCode = %s for URL %s", resp.Status, url)
        resp.Body.Close()
    }
}

执行上述代码，下面的内容会输出到文件——test.log中。

2019-10-27T15:50:32.944+0800    DEBUG    logic/temp2.go:48    Trying to hit GET request for www.sogo.com
2019-10-27T15:50:32.944+0800    ERROR    logic/temp2.go:51    Error fetching URL www.sogo.com : Error = Get www.sogo.com: unsupported protocol scheme ""
2019-10-27T15:50:32.944+0800    DEBUG    logic/temp2.go:48    Trying to hit GET request for http://www.sogo.com
2019-10-27T15:50:33.165+0800    INFO    logic/temp2.go:53    Success! statusCode = 200 OK for URL http://www.sogo.com

gin中集成zap

gin默认的中间件

首先我们来看一个最简单的gin项目：

func main() {
    r := gin.Default()
    r.GET("/hello", func(c *gin.Context) {
        c.String("hello liwenzhou.com!")
    })
    r.Run(
}

接下来我们看一下gin.Default()的源码：

func Default() *Engine {
    debugPrintWARNINGDefault()
    engine := New()
    engine.Use(Logger(), Recovery())
    return engine
}

也就是我们在使用gin.Default()的同时是用到了gin框架内的两个默认中间件Logger()和Recovery()。

其中Logger()是把gin框架本身的日志输出到标准输出（我们本地开发调试时在终端输出的那些日志就是它的功劳），而Recovery()是在程序出现panic的时候恢复现场并写入500响应的。

基于zap的中间件

我们可以模仿Logger()和Recovery()的实现，使用我们的日志库来接收gin框架默认输出的日志。

这里以zap为例，我们实现两个中间件如下：

// 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.Since(start)
        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()
    }
}

这样我们就可以在gin框架中使用我们上面定义好的两个中间件来代替gin框架默认的Logger()和Recovery()了。

r := gin.New()
r.Use(GinLogger(), GinRecovery())

在gin项目中使用zap

最后我们再加入我们项目中常用的日志切割，完整版的logger.go代码如下：

package logger
import (
    "gin_zap_demo/config"
    "net"
    "net/http"
    "net/http/httputil"
    "os"
    "runtime/debug"
    "strings"
    "time"
    "github.com/gin-gonic/gin"
    "github.com/natefinch/lumberjack"
    "go.uber.org/zap"
    "go.uber.org/zap/zapcore"
)
var lg *zap.Logger
// InitLogger 初始化Logger
func InitLogger(cfg *config.LogConfig) (err error) {
    writeSyncer := getLogWriter(cfg.Filename, cfg.MaxSize, cfg.MaxBackups, cfg.MaxAge)
    encoder := getEncoder()
    var l = new(zapcore.Level)
    err = l.UnmarshalText([]byte(cfg.Level))
    if err != nil {
        return
    }
    core := zapcore.NewCore(encoder, writeSyncer, l)
    lg = zap.New(core, zap.AddCaller())
    zap.ReplaceGlobals(lg) // 替换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)
}
// GinLogger 接收gin框架默认的日志
func GinLogger() gin.HandlerFunc {
    return func(c *gin.Context) {
        start := time.Now()
        path := c.Request.URL.Path
        query := c.Request.URL.RawQuery
        c.Next()
        cost := time.Since(start)
        lg.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，并使用zap记录相关日志
func GinRecovery(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 {
                    lg.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 {
                    lg.Error("[Recovery from panic]",
                        zap.Any("error", err),
                        zap.String("request", string(httpRequest)),
                        zap.String("stack", string(debug.Stack())),
                    )
                } else {
                    lg.Error("[Recovery from panic]",
                        zap.Any("error", err),
                        zap.String("request", string(httpRequest)),
                    )
                }
                c.AbortWithStatus(http.StatusInternalServerError)
            }
        }()
        c.Next()
    }
}

然后定义日志相关配置：

type LogConfig struct {
    Level string `json:"level"`
    Filename string `json:"filename"`
    MaxSize int `json:"maxsize"`
    MaxAge int `json:"max_age"`
    MaxBackups int `json:"max_backups"`
}

在项目中先从配置文件加载配置信息，再调用logger.InitLogger(config.Conf.LogConfig)即可完成logger实例的初识化。其中，通过r.Use(logger.GinLogger(), logger.GinRecovery(true))注册我们的中间件来使用zap接收gin框架自身的日志，在项目中需要的地方通过使用zap.L().Xxx()方法来记录自定义日志信息。

package main
import (
    "fmt"
    "gin_zap_demo/config"
    "gin_zap_demo/logger"
    "net/http"
    "os"
    "go.uber.org/zap"
    "github.com/gin-gonic/gin"
)
func main() {
    // load config from config.json
    if len(os.Args) < 1 {
        return
    }
    if err := config.Init(os.Args[1]); err != nil {
        panic(err)
    }
    // init logger
    if err := logger.InitLogger(config.Conf.LogConfig); err != nil {
        fmt.Printf("init logger failed, err:%v\n", err)
        return
    }
    gin.SetMode(config.Conf.Mode)
    r := gin.Default()
    // 注册zap相关中间件
    r.Use(logger.GinLogger(), logger.GinRecovery(true))
    r.GET("/hello", func(c *gin.Context) {
        // 假设你有一些数据需要记录到日志中
        var (
            name = "q1mi"
            age  = 18
        )
        // 记录日志并使用zap.Xxx(key, val)记录相关字段
        zap.L().Debug("this is hello func", zap.String("user", name), zap.Int("age", age))
        c.String(http.StatusOK, "hello liwenzhou.com!")
    })
    addr := fmt.Sprintf(":%v", config.Conf.Port)
    r.Run(addr)
}

参考链接：

zap-github
李文周的博客-在Go语言项目中使用Zap日志库
 zap_demo