从Go log库到Zap，怎么打造出好用又实用的Logger

发表于 2年以前 | 总阅读数：301 次

日志无论对于程序还是程序员都非常重要，有多重要呢，想要长期在公司健健康康的干下去就得学会阶段性划水，阶段性划水的一大关键的就是干活快过预期但是装作。。。不对，这个开头不对劲，下面重来。

日志无论对于程序还是程序员都非常重要，程序员解决问题的快慢除了经验外，就是看日志能不能有效地记录问题发生的现场以及上下文等等。

那么让让程序记录有效的日志，除了程序内记日志的点位尽量精准外，还需要有一个称手的 Logger 。一个好的 Logger (日志记录器) 要能提供以下这些能力：

支持把日志写入到多个输出流中，比如可以选择性的让测试、开发环境同时向控制台和日志文件输出日志，生产环境只输出到文件中。
支持多级别的日志等级，比如常见的有：TRACE，DEBUG，INFO，WARN，ERROR 等。
支持结构化输出，结构化输出现在常用的就是JSON形式的，这样可以让统一日志平台，通过 logstash 之类的组件直接把日志聚合到日志平台上去。
需要支持日志切割 -- log rotation，按照日期、时间间隔或者文件大小对日志进行切割。
在 Log Entry 中（就是每行记录）除了主动记录的信息外，还要包括如打印日志的函数、所在的文件、行号、记录时间等。

今天我带大家一起看看怎么在使用 Go 语言开发的项目里打造一个称手的 Logger，在这之前让我们先回到 2009 年，看看 Go 语言自诞生之初就提供给我们的内置 Logger。

Go 语言原生的Logger

Go 语言自带 log 内置包，为我们提供了一个默认的 Logger，可以直接使用。这个库的详细用法可以在官方的文档里找到：https://pkg.go.dev/log

使用 log 记录日志，默认会输出到控制台中。比如下面这个例子：

package main

import (
 "log"
 "net/http"
)

func main() {
 simpleHttpGet("www.baidu.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 的实现设置成日志的输出。下面我们把上面那个例程修改成向文件输出日志。

package main

import (
 "log"
 "net/http"
 "os"
)

func main() {
 SetupLogger()
 simpleHttpGet("www.baidu.com")
 simpleHttpGet("https://www.baidu.com")
}

func SetupLogger() {
 logFileLocation, _ := os.OpenFile("/tmp/test.log", os.O_CREATE|os.O_APPEND|os.O_RDWR, 0644)
 log.SetOutput(logFileLocation)
}

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
}

大家可以自己试一下运行效果，这里不再做过多演示。

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

我们不能每次使用日志，都这么设置一番，所以最好的还是把这些配置初始化放在一个单独的包里，这样在项目中初始化一次即可。

除了上面的那些配置外，我们的配置里还少了些日志调用方的信息，比如函数名、文件位置、行号等，这样在排查问题看日志的时候，定位问题的时效会提高不少。

这里用到了我们之前文章的知识点，忘记的可以等看完这篇文章后，回去复习一下，现在先不要点走：[如何在 Go 函数中获取调用者的函数名、文件名、行号...]

我们对 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}