两个高性能golang日志库比较

2019独角兽企业重金招聘Python工程师标准>>>

nanolog vs zerolog

后端开发过程中，经常需要对一些重要的事件做日志，方便观察程序的控制流，建立对程序的理解和自信，对于缺少好用debugger (也许是delve) 的golang 来说， 日志更是重要的调试手段。大部分时候，使用标准库自带的log package 已经够用，log 包缺少输出级别的控制，不过我们可以基于log 包做简单的包装也足以够用，尽量减少对第三方包的依赖，我觉得应该是个好实践。

不过当你发现log 太多，对程序性能产生了明显的影响时，也许可以考虑下面介绍的两个日志库: nanolog和zerolog。 nanolog 是受到同名c++ 库nanolog 启发， zerolog 是受到uber 的日志库zap 的启发，golang社区里，对高性能日志库的追求，引发了编译器团队对一些使用模式的优化。

首先，看一下nanolog 是怎么个使用法：

package main

import (
	"os"
	"github.com/ScottMansfield/nanolog"
)

var h nanolog.Handle

func 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.context
	l.context = make([]byte, 0, 500)
	if context != nil {
		l.context = append(l.context, context...)
	} else {
		// first byte of context is presence of timestamp or not
		l.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 main

import (
	"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实现。

转载于:https://my.oschina.net/evilunix/blog/1142754