又看了一些 golang 的日志包和相关的文章,仔细阅读了 go 1.9.2 系统提供的 log 和 go-log ,产生了对 log4go 的日志输出进行优化的想法。
log 使用 multiwriter 支持多个日志输出,用 Mutex 加锁解决多线程日志输出的冲突。log4go 则采用结构化编程用 channel 传递 LogRecord 日志记录。
原来以为 channel 的效率比较高…… 其实这是一个伪命题。channel 是一个全局加锁的队列,可以用来加锁,但效率比较低。因为它多了传递数据、协调顺序处理、timout 等功能,并不仅仅是加锁。跟 Mutex 不是一回事儿。
log4go 将屏幕日志输出 termlog 放在了结构里,这带来一个小问题。当我们用 log4go 调试小程序时,运行的太快,termlog 的 goroutine 还没有运行起来,程序就退出了。结果屏幕上没有显示日志。这个问题只能通过在 Close() 时加延时,等待 goroutine 启动来解决。然后还要检查 channel ……
- func(f * Filter) Close() {
- if f.closed {
- return
- }
- // sleep at most one second and let go routine running
- // drain the log channel before closing
- for i: =10;
- i > 0;
- i--{
- // Must call Sleep here, otherwise, may panic send on closed channel
- time.Sleep(100 * time.Millisecond) if len(f.rec) <= 0 {
- break
- }
- }
- // block write channel
- f.closed = true
- defer f.LogWriter.Close()
- close(f.rec)
- if len(f.rec) <= 0 {
- return
- }
- // drain the log channel and write driect
- for rec: =range f.rec {
- f.LogWrite(rec)
- }
- }
log 直接将格式化日志信息输出到屏幕,简单多了。
试着兼顾两者,在 log4go 中增加了 writer,直接输出到屏幕。拟将 FileLog,SocketLog 作为 backend,仍然放在结构里。这样,调试小程序和生产程序可以使用同一个日志库。实测效率略有降低。不知道 windows 下的 ColorLog 如何,以后再说。
在 log4go 中可以通过调用 SetOutput(nil),使 out = nil 来关闭屏幕输出。
这句话注释在 log 源文件中,log4go 也要调用
函数来获取源文件名和行号。它是昂贵的——消耗了 CPU。建议在生产环境中关闭,log.SetSkip(-1)。如果要对 log4go 进行封装,设置
- runtime.Caller(skip int)
。
- log.SetSkip(log.GetSkip()+1)
其实,这才是文章的主题。
日志输出避免不了打印日期和时间,linux 环境下还要打印微秒,说不定还要打印时区。log4go 的 pattlog.go 就是完成这些工作的。
在 log 里边自备了一个 cheap 的 itoa 函数。
- // Cheap integer to fixed-width decimal ASCII. Give a negative width to avoid zero-padding.
- func itoa(buf *[]byte, i int, wid int) {
- // Assemble decimal in reverse order.
- var b [20]byte
- bp := len(b) - 1
- for i >= 10 || wid > 1 {
- wid--
- q := i / 10
- b[bp] = byte('0' + i - q*10)
- bp--
- i = q
- }
- // i < 10
- b[bp] = byte('0' + i)
- *buf = append(*buf, b[bp:]...)
- }
用这个函数替换日期和时间的字符串格式化函数。用 []byte 代替 string。
优化前,log4go 的 benchmark。
- BenchmarkFormatLogRecord-4 300000 4480 ns/op
- BenchmarkConsoleLog-4 1000000 1748 ns/op
- BenchmarkConsoleNotLogged-4 20000000 97.5 ns/op
- BenchmarkConsoleUtilLog-4 300000 3496 ns/op
- BenchmarkConsoleUtilNotLog-4 20000000 104 ns/op
优化后:
- BenchmarkFormatLogRecord-4 1000000 1443 ns/op
- BenchmarkConsoleLog-4 2000000 982 ns/op
- BenchmarkConsoleUtilLog-4 500000 3242 ns/op
- BenchmarkConsoleUtilNotLog-4 30000000 48.4 ns/op
格式化日期时间所花的时间是原来的 1/3。
打印无格式化信息所花的时间是原来的 1/2。
BenchmarkConsoleUtilLog 调用了 runtime.Caller,格式化信息,且新增了输出信息到屏幕的时间。
字符串格式化——比较昂贵。
来源: https://www.cnblogs.com/ccpaging/p/8125265.html