前言

在go語言中，自身已經集成了一定log模塊，開發者可以使用go語言自身的log包(import “log”) 。也有不少對自身log的開源封裝。對于一些簡單的開發，自身的log模塊就已經足夠應付。但是對一些大型，復雜的開發，log需要分門別類的輸出，或者通過網絡進行輸出，自身log模塊將難以應對。

當前也有一些比較重量級的log模塊，比如logrus，可以實現比較復雜的功能。這里介紹一個輕量級的log模塊——log4go

最近又看了一些golang的日志包和相關的文章，仔細閱讀了go 1.9.2系統提供的log和go-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，格式化信息，且新增了輸出信息到屏幕的時間。

字符串格式化——比較昂貴。

總結

以上就是這篇文章的全部內容了，希望本文的內容對大家的學習或者工作具有一定的參考學習價值，如果有疑問大家可以留言交流，謝謝大家對腳本之家的支持。