欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页  >  IT编程

golang log4go的日志输出优化详解

程序员文章站 2022-04-09 20:37:59
前言 在go语言中,自身已经集成了一定log模块,开发者可以使用go语言自身的log包(import “log”) 。也有不少对自身log的开源封装。对于一些简单的开发,...

前言

在go语言中,自身已经集成了一定log模块,开发者可以使用go语言自身的log包(import “log”) 。也有不少对自身log的开源封装。对于一些简单的开发,自身的log模块就已经足够应付。但是对一些大型,复杂的开发,log需要分门别类的输出,或者通过网络进行输出,自身log模块将难以应对。

当前也有一些比较重量级的log模块,比如logrus,可以实现比较复杂的功能。这里介绍一个轻量级的log模块——log4go

最近又看了一些golang的日志包和相关的文章,仔细阅读了go 1.9.2系统提供的log和,产生了对log4go的日志输出进行优化的想法。

结构化与multiwriter

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 来关闭屏幕输出。

determine caller func - it's expensive

这句话注释在 log 源文件中,log4go也要调用runtime.caller(skip int)函数来获取源文件名和行号。它是昂贵的——消耗了cpu。建议在生产环境中关闭,log.setskip(-1) 。如果要对log4go进行封装,设置 log.setskip(log.getskip()+1)

format优化

其实,这才是文章的主题。

日志输出避免不了打印日期和时间,linux 环境下还要打印微秒,说不定还要打印时区。log4go的pattlog.go就是完成这些工作的。

  • 有一个1秒更新一次的cache机制。很漂亮。
  • 大量使用字符串格式化函数——fmt.sprintf。
  • 返回字符串。而writer一般支持的是[]byte。多做一次转换。
  • 每次都bytes.splite讲format字符串以%字符分解成[][]byte。

在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,格式化信息,且新增了输出信息到屏幕的时间。

字符串格式化——比较昂贵。

总结

以上就是这篇文章的全部内容了,希望本文的内容对大家的学习或者工作具有一定的参考学习价值,如果有疑问大家可以留言交流,谢谢大家对的支持。