【Gin-API系列】Gin中間件之日志模塊（四）

日志是程序開發中必不可少的模塊，同時也是日常運維定位故障的最重要環節之一。一般日志類的操作包括日志采集，日志查詢，日志監控、日志統計等等。本文，我們將介紹日志模塊在Gin中的使用。

Golang如何打印日志

• 日志打印需要滿足幾個條件

1. 重定向到日志文件
2. 區分日志級別，一般有DEBUG,INFO,WARNING,ERROR,CRITICAL
3. 日志分割，按照日期分割或者按照大小分割

• Golang中使用logrus打印日志

var LevelMap = map[string]logrus.Level{
	"DEBUG": logrus.DebugLevel,
	"ERROR": logrus.ErrorLevel,
	"WARN":  logrus.WarnLevel,
	"INFO":  logrus.InfoLevel,
}

// 創建 @filePth: 如果路徑不存在會創建 @fileName: 如果存在會被覆蓋  @std: os.stdout/stderr 標准輸出和錯誤輸出
func New(filePath string, fileName string, level string, std io.Writer, count uint) (*logrus.Logger, error) {
	if _, err := os.Stat(filePath); os.IsNotExist(err) {
		if err := os.MkdirAll(filePath, 755); err != nil {
			return nil, err
		}
	}
	fn := path.Join(filePath, fileName)

	logger := logrus.New()
	//timeFormatter := &logrus.TextFormatter{
	//	FullTimestamp:   true,
	//	TimestampFormat: "2006-01-02 15:04:05.999999999",
	//}
	logger.SetFormatter(&logrus.JSONFormatter{
		TimestampFormat: "2006-01-02 15:04:05.999999999",
	}) // 設置日志格式為json格式

	if logLevel, ok := LevelMap[level]; !ok {
		return nil, errors.New("log level not found")
	} else {
		logger.SetLevel(logLevel)
	}

	//logger.SetFormatter(timeFormatter)

	/*  根據文件大小分割日志
	// import "gopkg.in/natefinch/lumberjack.v2"
	logger := &lumberjack.Logger{
		// 日志輸出文件路徑
		Filename:   "D:\\test_go.log",
		// 日志文件最大 size, 單位是 MB
		MaxSize:    500, // megabytes
		// 最大過期日志保留的個數
		MaxBackups: 3,
		// 保留過期文件的最大時間間隔,單位是天
		MaxAge:     28,   //days
		// 是否需要壓縮滾動日志, 使用的 gzip 壓縮
		Compress:   true, // disabled by default
	}
	*/
	if 0 == count {
		count = 90 // 0的話則是默認保留90天
	}
	logFd, err := rotatelogs.New(
		fn+".%Y-%m-%d",
		// rotatelogs.WithLinkName(fn),
		//rotatelogs.WithMaxAge(time.Duration(24*count)*time.Hour),
		rotatelogs.WithRotationTime(time.Duration(24)*time.Hour),
		rotatelogs.WithRotationCount(count),
	)
	if err != nil {
		return nil, err
	}
	defer func() {
		_ = logFd.Close() // don't need handle error
	}()

	if nil != std {
		logger.SetOutput(io.MultiWriter(logFd, std)) // 設置日志輸出
	} else {
		logger.SetOutput(logFd) // 設置日志輸出
	}
	// logger.SetReportCaller(true)   // 測試環境可以開啟，生產環境不能開，會增加很大開銷
	return logger, nil
}

Gin中間件介紹

Gin中間件的是Gin處理Http請求的一個模塊或步驟，也可以理解為Http攔截器。

我們將Http請求拆分為四個步驟
1、服務器接到客戶端的Http請求
2、服務器解析Http請求進入到路由轉發系統
3、服務器根據實際路由執行操作並得到結果
4、服務器返回結果給客戶端

Gin中間件的執行包括2個部分（first和last），分布對應的就是在步驟1-2之間（first)和3-4之間（last)的操作。常見的Gin中間件包括日志、鑒權、鏈路跟蹤、異常捕捉等等

• 默認中間件

router := gin.Default()

查看源碼可以看到

// Default returns an Engine instance with the Logger and Recovery middleware already attached.
func Default() *Engine {
	debugPrintWARNINGDefault()
	engine := New()
	engine.Use(Logger(), Recovery())  // 包含 Logger、Recovery 中間件
	return engine
}

• 自定義中間件方式1

func Middleware1(c *gin.Context)  {
	...  // do something first
	c.Next()  // 繼續執行后續的中間件
	// c.Abort() 不再執行后面的中間件
	...  // do something last
}

• 自定義中間件方式2

func Middleware2()  gin.HandlerFunc {
    return func(c *gin.Context) {
        ...  // do something first
        c.Next()  // 繼續執行后續的中間件
        // c.Abort() 不再執行后面的中間件
        ...  // do something last
	}
}

• 全局使用中間件

route := gin.Default()
route.Use(Middleware1)
route.Use(Middleware2())

• 指定路由使用中間件

route := gin.Default()
route.Get("/test", Middleware1)
route.POST("/test", Middleware2())

• 多個中間件執行順序

Gin里面多個中間件的執行順序是按照調用次序來執行的。
無論在全局使用還是指定路由使用，Gin都支持多個中間件順序執行

Gin中間件之日志模塊

• 模塊代碼

type BodyLogWriter struct {
	gin.ResponseWriter
	body *bytes.Buffer
}

func (w BodyLogWriter) Write(b []byte) (int, error) {
	w.body.Write(b)
	return w.ResponseWriter.Write(b)
}
func (w BodyLogWriter) WriteString(s string) (int, error) {
	w.body.WriteString(s)
	return w.ResponseWriter.WriteString(s)
}

var SnowWorker, _ = uuid.NewSnowWorker(100) // 隨機生成一個uuid，100是節點的值（隨便給一個）

// 打印日志
func Logger() gin.HandlerFunc {
	accessLog, _ := mylog.New(
		configure.GinConfigValue.AccessLog.Path, configure.GinConfigValue.AccessLog.Name,
		configure.GinConfigValue.AccessLog.Level, nil, configure.GinConfigValue.AccessLog.Count)
	detailLog, _ := mylog.New(
		configure.GinConfigValue.DetailLog.Path, configure.GinConfigValue.DetailLog.Name,
		configure.GinConfigValue.DetailLog.Level, nil, configure.GinConfigValue.DetailLog.Count)
	return func(c *gin.Context) {
		var buf bytes.Buffer
		tee := io.TeeReader(c.Request.Body, &buf)
		requestBody, _ := ioutil.ReadAll(tee)
		c.Request.Body = ioutil.NopCloser(&buf)

		user := c.Writer.Header().Get("X-Request-User")
		bodyLogWriter := &BodyLogWriter{body: bytes.NewBufferString(""), ResponseWriter: c.Writer}
		c.Writer = bodyLogWriter

		start := time.Now()

		c.Next()

		responseBody := bodyLogWriter.body.Bytes()
		response := route_response.Response{}
		if len(responseBody) > 0 {
			_ = json.Unmarshal(responseBody, &response)
		}
		end := time.Now()
		responseTime := float64(end.Sub(start).Nanoseconds()) / 1000000.0 // 納秒轉毫秒才能保留小數
		logField := map[string]interface{}{
			"user":            user,
			"uri":             c.Request.URL.Path,
			"start_timestamp": start.Format("2006-01-02 15:04:05"),
			"end_timestamp":   end.Format("2006-01-02 15:04:05"),
			"server_name":     c.Request.Host,
			"server_addr": fmt.Sprintf("%s:%d", configure.GinConfigValue.ApiServer.Host,
				configure.GinConfigValue.ApiServer.Port), // 無法動態讀取
			"remote_addr":    c.ClientIP(),
			"proto":          c.Request.Proto,
			"referer":        c.Request.Referer(),
			"request_method": c.Request.Method,
			"response_time":  fmt.Sprintf("%.3f", responseTime), // 毫秒
			"content_type":   c.Request.Header.Get("Content-Type"),
			"status":         c.Writer.Status(),
			"user_agent":     c.Request.UserAgent(),
			"trace_id":       SnowWorker.GetId(),
		}
		accessLog.WithFields(logField).Info("Request Finished")
		detailLog.WithFields(logField).Info(c.Request.URL)
		detailLog.WithFields(logField).Info(string(requestBody)) // 不能打印GET請求參數
		if response.Code != configure.RequestSuccess {
			detailLog.WithFields(logField).Errorf("code=%d, message=%s", response.Code, response.Message)
		} else {
			detailLog.WithFields(logField).Infof("total=%d, page_size=%d, page=%d, size=%d",
				response.Data.Total, response.Data.PageSize, response.Data.Page, response.Data.Size)
		}
	}
}

• 啟用全局日志中間件

route := gin.New()  // 不用默認的日志中間件
route.Use(route_middleware.Logger())

異步打印日志

由於我們的日志中間件使用的是全局中間件，在高並發處理請求時日志落地會導致大量的IO操作，這些操作會拖慢整個服務器，所以我們需要使用異步打印日志

• 異步函數

var logChannel = make(chan map[string]interface{}, 300)

func logHandlerFunc() {
	accessLog, _ := mylog.New(
		configure.GinConfigValue.AccessLog.Path, configure.GinConfigValue.AccessLog.Name,
		configure.GinConfigValue.AccessLog.Level, nil, configure.GinConfigValue.AccessLog.Count)
	detailLog, _ := mylog.New(
		configure.GinConfigValue.DetailLog.Path, configure.GinConfigValue.DetailLog.Name,
		configure.GinConfigValue.DetailLog.Level, nil, configure.GinConfigValue.DetailLog.Count)
	for logField := range logChannel {
		var (
			msgStr   string
			levelStr string
			detailStr string
		)
		if msg, ok := logField["msg"]; ok {
			msgStr = msg.(string)
			delete(logField, "msg")
		}
		if level, ok := logField["level"]; ok {
			levelStr = level.(string)
			delete(logField, "level")
		}
		if detail, ok := logField["detail"]; ok {
			detailStr = detail.(string)
			delete(logField, "detail")
		}
		accessLog.WithFields(logField).Info("Request Finished")
		if "info" == levelStr {
			detailLog.WithFields(logField).Info(detailStr)
			detailLog.WithFields(logField).Info(msgStr)
		} else {
			detailLog.WithFields(logField).Error(detailStr)
			detailLog.WithFields(logField).Error(msgStr)
		}
	}
}

• 調用方法

go logHandlerFunc()
... // 省略
logChannel <- logField

至此，我們完成了Gin中間件的介紹和日志模塊的設計，接下來，我們將使用更多的中間件，完善我們的Api服務。

Github 代碼

請訪問 Gin-IPs 或者搜索 Gin-IPs