2019独角兽企业重金招聘Python工程师标准>>>
nanolog vs zerolog
后端开发过程中,经常需要对一些重要的事件做日志,方便观察程序的控制流,建立对程序的理解和自信,对于缺少好用debugger (也许是delve) 的golang 来说, 日志更是重要的调试手段。大部分时候,使用标准库自带的log package 已经够用,log 包缺少输出级别的控制,不过我们可以基于log 包做简单的包装也足以够用,尽量减少对第三方包的依赖,我觉得应该是个好实践。
不过当你发现log 太多,对程序性能产生了明显的影响时,也许可以考虑下面介绍的两个日志库: nanolog和zerolog。 nanolog 是受到同名c++ 库nanolog 启发, zerolog 是受到uber 的日志库zap 的启发,golang社区里,对高性能日志库的追求,引发了编译器团队对一些使用模式的优化。
首先,看一下nanolog 是怎么个使用法:
package mainimport ("os""github.com/ScottMansfield/nanolog"
)var h nanolog.Handlefunc init() {nanolog.SetWriter(os.Stderr)h = nanolog.AddLogger("Example %i32 log %{s} line %c128")
}func main() {nanolog.Log(h, int32(4), "this is a string", 4i)nanolog.Flush()
}
nanolog 的思路是每个独特的printf风格的字符串模板,映射一个唯一的整数handle。当我们调用AddLogger方法时,触发解析string 模板,收集了三个string 片段: “Example", "log", "line" ; 三个占位符的类别:i32, s, c128; 然后往内存buffer 里先写一字节的ETLogLine(1), 然后就是暴露给用户的handle h, 字符串片段个数,一字节编码的多个类别,字符串片段本身。调用Log 方法时,开始写占位符对应的实际参数: 首先写ETLogEntry(2), 接着是handle, 然后是大小1,2,4,8,16字节的各种基础数据类型对应的值。需要注意的是,上面日志数据都是往buffer writer 里面发送,所以后面需要调用Flush()。不过,由于作者使用了自定义的格式编码日志,减少日志的磁盘空间占用,所以阅读日志不太方便,需要自带的inflate 工具还原:
$ go build github.com/ScottMansfield/nanolog/cmd/inflate
$ ./inflate -f foo.clog > foo-inflated.log
zerolog 基本上是logrus, zap这条路线上的, 输出带上下文信息的json , 但是在性能追求上更进一步。这种结构化日志库,人类易读性差点, 但是方便日志搜集程序的处理。api 设计成这种可chaining 模式,比zap 使用上感觉要优雅多了,和zap一样,输出json 时,手工定义的json序列化方法,避免使用相对昂贵的标准库encoding/json, zerolog 还引入了和context 库结合,方便将logger 存入context 。起初感到奇怪的是它的api 有不少地方方法接收器都是用T, 而非*T, 后来一想,这正在完成channing 模式,减少内存分配, children logger 不会干扰 parent logger 的支撑。
func New(w io.Writer) Logger {if w == nil {w = ioutil.Discard}lw, ok := w.(LevelWriter)if !ok {lw = levelWriterAdapter{w}}return Logger{w: lw}
}// Nop returns a disabled logger for which all operation are no-op.
func Nop() Logger {return New(nil).Level(Disabled)
}// With creates a child logger with the field added to its context.
func (l Logger) With() Context {context := l.contextl.context = make([]byte, 0, 500)if context != nil {l.context = append(l.context, context...)} else {// first byte of context is presence of timestamp or notl.context = append(l.context, 0)}return Context{l}
}// Level creates a child logger with the minimum accepted level set to level.
func (l Logger) Level(lvl Level) Logger {return Logger{w: l.w,level: lvl,sample: l.sample,counter: l.counter,context: l.context,}
}// Sample returns a logger that only let one message out of every to pass thru.
func (l Logger) Sample(every int) Logger {if every == 0 {// Create a child with no sampling.return Logger{w: l.w,level: l.level,context: l.context,}}return Logger{w: l.w,level: l.level,sample: uint32(every),counter: new(uint32),context: l.context,}
}
这几个构造器函数都是返回结构体实例,复制原有对象必要的字段,这样parent, child logger, 带有不同上下文的logger 之间互不干扰。
简单的benchmark 一下,nanolog,zerolog,std log:
package mainimport ("io/ioutil""log""testing""github.com/ScottMansfield/nanolog""github.com/rs/zerolog"
)func BenchmarkCompareToStdlib(b *testing.B) {b.Run("Nanolog", func(b *testing.B) {lw := nanolog.New()lw.SetWriter(ioutil.Discard)h := lw.AddLogger("foo thing bar thing %i64. Fubar %s foo. sadfasdf %u32 sdfasfasdfasdffds %u32.")args := []interface{}{int64(1), "string", uint32(2), uint32(3)}b.ResetTimer()for i := 0; i < b.N; i++ {lw.Log(h, args...)}})b.Run("Stdlib", func(b *testing.B) {args := []interface{}{int64(1), "string", uint32(2), uint32(3)}l := log.New(ioutil.Discard, "", 0)b.ResetTimer()for i := 0; i < b.N; i++ {l.Printf("foo thing bar thing %d. Fubar %s foo. sadfasdf %d sdfasfasdfasdffds %d.", args...)}})b.Run("Zerolog_printf", func(b *testing.B) {args := []interface{}{int64(1), "string", uint32(2), uint32(3)}logger := zerolog.New(ioutil.Discard)b.ResetTimer()for i := 0; i < b.N; i++ {logger.Log().Msgf("foo thing bar thing %d. Fubar %s foo. sadfasdf %d sdfasfasdfasdffds %d.", args...)}})b.Run("Zerolog_field", func(b *testing.B) {logger := zerolog.New(ioutil.Discard)b.ResetTimer()for i := 0; i < b.N; i++ {logger.Log().Int64("foo thing bar thing", 1).Str("Fubar foo", "string").Uint32("sadfasdf", 2).Uint32("sdfasfasdfasdffds", 3).Msg("")}})b.Run("Zerolog_context", func(b *testing.B) {logger := zerolog.New(ioutil.Discard).With().Int64("foo thing bar thing", 1).Str("Fubar foo", "string").Uint32("sadfasdf", 2).Uint32("sdfasfasdfasdffds", 3).Logger()b.ResetTimer()for i := 0; i < b.N; i++ {logger.Log().Msg("")}})
}
$ go test -bench Stdlib$ .
BenchmarkCompareToStdlib/Nanolog-8 20000000 90.2 ns/op
BenchmarkCompareToStdlib/Stdlib-8 5000000 364 ns/op
BenchmarkCompareToStdlib/Zerolog_printf-8 5000000 404 ns/op
BenchmarkCompareToStdlib/Zerolog_field-8 10000000 203 ns/op
BenchmarkCompareToStdlib/Zerolog_context-8 20000000 60.5 ns/op
PASS
ok examples/log 10.053s
zerolog 在打印printf 风格时,比标准库还稍慢些,因为这里它是通过调用fmt.Sprintf实现。