从Go log库到Zap,怎么打造出好用又实用的Logger
日志无论对于程序还是程序员都非常重要,有多重要呢,想要长期在公司健健康康的干下去就得学会阶段性划水,阶段性划水的一大关键的就是干活快过预期但是装作。。。不对,这个开头不对劲,下面重来。日志无论对于程序还是程序员都非常重要,程序员解决问题的快慢除了经验外,就是看日志能不能有效地记录问题发生的现场以及上下文等等。
那么让让程序记录有效的日志,除了程序内记日志的点位尽量精准外,还需要有一个称手的 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}
总结
关于 Zap Logger 的定制化和封装,这里只是举了一些基本又必要的入门级定制化,等大家掌握后,可以参照官方文档提供的接口进行更多定制化。