從0寫一個Golang日誌處理包
WHY
日誌概述
日誌幾乎是每個實際的軟件項目從開發到最後實際運行過程中都必不可少的東西。它對於查看代碼運行流程，記錄發生的事情等方面都是很重要的。
一個好的日誌系統應當能準確地記錄需要記錄的信息，同時兼具良好的性能，接下來本文將從0寫一個Golang日誌處理包。
通常Go應用程序多為並發模型應用，在並發處理實際應用的過程中也無法避免並發地調用日誌方法。
通常來說，Go中除非聲明方法是協程安全的，否則最好都視為協程不安全，Go中默認的日誌方法為log,該方法協程安全，但是功能有限。
第三方Go日誌包如ZAP、logrus等均為較為不錯的日誌庫，也提供了較多的配置選項，但是對於高度定製需求的日誌則有些不適用，從0開始自己寫一個就較為適用。
設計概述
- 按json方式輸出到文件
- 日誌類型支持豐富
- 有日誌分級設定
- 按天分隔日誌文件
- 異常退出能把未寫入的日誌寫完
HOW
整體流程
怎麼填充日誌內容
要做到按json方式輸出到文件，並且支持豐富的類型，第一個能想到的則是Golang中強大的interface
設計兩種類型分別用於接收map型和string型日誌，再根據日誌分級設定分別暴露出對外接口：
func Debug(msg map[string]interface{}) {
writeLog("DEBUG", msg)
}
func DebugMsg(msg interface{}) {
writeLog("DEBUG", map[string]interface{}{"msg": msg})
}
func Info(msg map[string]interface{}) {
writeLog("INFO", msg)
}
func InfoMsg(msg interface{}) {
writeLog("INFO", map[string]interface{}{"msg": msg})
}
func Warn(msg map[string]interface{}) {
writeLog("WARN", msg)
}
func WarnMsg(msg interface{}) {
writeLog("WARN", map[string]interface{}{"msg": msg})
}
func Error(msg map[string]interface{}) {
writeLog("ERROR", msg)
}
func ErrorMsg(msg interface{}) {
writeLog("ERROR", map[string]interface{}{"msg": msg})
}
最終都是使用writeLog進行日誌的處理，writeLog方法定義如下：
func writeLog(level string, msg map[string]interface{})
用哪種方式寫入文件
Golang對於文件的寫入方式多種多樣，通常來講最後都是使用操作系統的磁盤IO方法把數據寫入文件
在選型上這塊使用bufio方式來構建，使用默認的4096長度，如果收集的日誌長度超過了緩衝區長度則自動將內容寫入到文件，同時增加一組定時器，每秒將緩衝區內容寫入到文件中，這樣在整體性能上較為不錯
處理協程搶佔問題
針對多協程搶佔的問題，Golang提供有兩個比較標準的應對方式：使用channel或者加鎖
在這裡採用讀寫鎖的方式來進行處理bufio，bufio的WriteString方法需串行處理，要不然會導致錯誤，而Flush方法可以多協程同時操作
基於這些特性，我們在使用WriteString方法的時候使用寫鎖，使用Flush方法時採用讀鎖：
fileWriter.Mu.Lock()
fileWriter.Writer.WriteString(a)
fileWriter.Mu.Unlock()
fileWriter.Mu.RLock()
err = fileWriter.Writer.Flush()
if err != nil {
log.Println("flush log file err", err)
}
fileWriter.Mu.RUnlock()
跨天的日誌文件處理
首先明確一個問題，在每日結束次日開始時將打開一個新的日誌文件，那麼還在緩衝區未完成刷新的數據怎麼處理呢？
bufio提供了Reset方法，但是該方法注釋說明將丟棄未刷新的數據而直接重新指向新的io writer，因此我們不能直接使用該方法，否則這個時間節點附近的數據將會丟掉
實際測試證明如果先關閉原IO，再重新創建新的文件描述符，最後調用Reset方法指向新的描述符過後這段時間將會丟掉達約20ms的數據
基於此，我們使用了二級指針：
1.判斷當前日期是否就是今天，如果是則等待下個判斷周期，如果不是則開始準備指針重定向操作
2.判斷哪一個文件描述符為空，如果為空則為其創建新的描述符，並指定配對的filebuffer，如果不為空則說明它就是當前正在操作的文件
3.將filewriter指向新的filebuffer
4.對老的filebuffer進行Flush操作，之後將filebuffer和file都置為空
經過這樣的操作過後，跨天的日誌文件處理就不會有數據丟失的情況了
if today != time.Now().Day() {
today = time.Now().Day()
if file[0] == nil {
file[0], err = os.OpenFile(filePath+"/"+config.Get("app", "name")+"_"+time.Now().Format("2006-01-02")+".log", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0666)
if err != nil {
log.Fatal("open log file err: ", err)
}
fileBuffer[0] = bufio.NewWriterSize(file[0], 4096)
fileWriter.Writer = fileBuffer[0]
if fileBuffer[1].Buffered() > 0 {
fileBuffer[1].Flush()
}
fileBuffer[1] = nil
file[1].Close()
file[1] = nil
} else if file[1] == nil {
file[1], err = os.OpenFile(filePath+"/"+config.Get("app", "name")+"_"+time.Now().Format("2006-01-02")+".log", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0666)
if err != nil {
log.Fatal("open log file err: ", err)
}
fileBuffer[1] = bufio.NewWriterSize(file[1], 4096)
fileWriter.Writer = fileBuffer[1]
if fileBuffer[0].Buffered() > 0 {
fileBuffer[0].Flush()
}
fileBuffer[0] = nil
file[0].Close()
file[0] = nil
}
}
異常退出的處理
一個基本的概念就是程序在操作系統退出的時候通常都會得到系統信號，比如linux的kill操作就是給應用程序發送系統信號
信號分很多種，比如常見的ctrl+c對應的信號則是Interrupt信號，這塊去搜索「posix信號」也有詳細的解釋說明
基於此，常規的異常處理我們可以捕獲系統信號然後做一些結束前的處理操作，這樣的信號可以在多個包同時使用，均會收到信號，不用擔心信號強佔的問題
比如這個包在接收到退出信號時則刷新所有緩存數據並關閉所有文件描述符：
func exitHandle() {
<-exitChan
if file != nil {
if fileWriter.Writer.Buffered() > 0 {
fileWriter.Writer.Flush()
}
//及時關閉file句柄
if file[0] != nil {
file[0].Close()
}
if file[1] != nil {
file[1].Close()
}
}
os.Exit(1) //使用os.Exit強行關掉
}
完整源碼
package logger
import (
"bufio"
"bytes"
"encoding/json"
"fmt"
"log"
"os"
"os/signal"
"xxx/config"
"sync"
"syscall"
"time"
)
var file []*os.File
var err error
var fileBuffer []*bufio.Writer
var exitChan chan os.Signal
type fileWriterS struct {
Writer *bufio.Writer
Mu sync.RWMutex
}
var fileWriter fileWriterS
var today int
func LoggerInit() {
filePath := config.Get("app", "log_path") //config處可以直接換成自己的config甚至直接寫死
_, err := os.Stat(filePath)
if err != nil {
if os.IsNotExist(err) {
os.MkdirAll(filePath, os.ModePerm)
} else {
log.Fatal("log path err:", err)
}
}
file = make([]*os.File, 2)
file[0] = nil
file[1] = nil
fileBuffer = make([]*bufio.Writer, 2)
fileBuffer[0] = nil
fileBuffer[1] = nil
today = time.Now().Day()
file[0], err = os.OpenFile(filePath+"/"+config.Get("app", "name")+"_"+time.Now().Format("2006-01-02")+".log", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0666)
if err != nil {
log.Fatal("open log file err: ", err)
}
fileBuffer[0] = bufio.NewWriterSize(file[0], 4096)
fileWriter.Writer = fileBuffer[0]
exitChan = make(chan os.Signal)
signal.Notify(exitChan, os.Interrupt, os.Kill, syscall.SIGTERM)
go exitHandle()
go func() {
time.Sleep(1 * time.Second)
for {
if fileWriter.Writer.Buffered() > 0 {
fileWriter.Mu.RLock()
err = fileWriter.Writer.Flush()
if err != nil {
log.Println("flush log file err", err)
}
fileWriter.Mu.RUnlock()
}
time.Sleep(1 * time.Second)
if today != time.Now().Day() {
today = time.Now().Day()
if file[0] == nil {
file[0], err = os.OpenFile(filePath+"/"+config.Get("app", "name")+"_"+time.Now().Format("2006-01-02")+".log", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0666)
if err != nil {
log.Fatal("open log file err: ", err)
}
fileBuffer[0] = bufio.NewWriterSize(file[0], 4096)
fileWriter.Writer = fileBuffer[0]
if fileBuffer[1].Buffered() > 0 {
fileBuffer[1].Flush()
}
fileBuffer[1] = nil
file[1].Close()
file[1] = nil
} else if file[1] == nil {
file[1], err = os.OpenFile(filePath+"/"+config.Get("app", "name")+"_"+time.Now().Format("2006-01-02")+".log", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0666)
if err != nil {
log.Fatal("open log file err: ", err)
}
fileBuffer[1] = bufio.NewWriterSize(file[1], 4096)
fileWriter.Writer = fileBuffer[1]
if fileBuffer[0].Buffered() > 0 {
fileBuffer[0].Flush()
}
fileBuffer[0] = nil
file[0].Close()
file[0] = nil
}
}
}
}()
}
func exitHandle() {
<-exitChan
if file != nil {
if fileWriter.Writer.Buffered() > 0 {
fileWriter.Writer.Flush()
}
if file[0] != nil {
file[0].Close()
}
if file[1] != nil {
file[1].Close()
}
}
os.Exit(1)
}
func Debug(msg map[string]interface{}) {
writeLog("DEBUG", msg)
}
func DebugMsg(msg interface{}) {
writeLog("DEBUG", map[string]interface{}{"msg": msg})
}
func Info(msg map[string]interface{}) {
writeLog("INFO", msg)
}
func InfoMsg(msg interface{}) {
writeLog("INFO", map[string]interface{}{"msg": msg})
}
func Warn(msg map[string]interface{}) {
writeLog("WARN", msg)
}
func WarnMsg(msg interface{}) {
writeLog("WARN", map[string]interface{}{"msg": msg})
}
func Error(msg map[string]interface{}) {
writeLog("ERROR", msg)
}
func ErrorMsg(msg interface{}) {
writeLog("ERROR", map[string]interface{}{"msg": msg})
}
func writeLog(level string, msg map[string]interface{}) {
will_write_map := make(map[string]interface{})
t := time.Now()
will_write_map["@timestamp"] = fmt.Sprintf("%d-%02d-%02dT%02d:%02d:%02d.%03d", t.Year(), t.Month(), t.Day(), t.Hour(), t.Minute(), t.Second(), t.Nanosecond()/1e6)
will_write_map["level"] = level
for p, v := range msg {
will_write_map[p] = v
}
//buffer滿了會自動flush
bf := bytes.NewBuffer([]byte{})
jsonEncoder := json.NewEncoder(bf)
jsonEncoder.SetEscapeHTML(false)
jsonEncoder.Encode(will_write_map)
a := bf.String()
// fmt.Println(a)
fileWriter.Mu.Lock()
fileWriter.Writer.WriteString(a)
fileWriter.Mu.Unlock()
// fileWriter.WriteString("\n")
}
