Golang实践录：gin框架使用自定义日志模块

本文介绍在 Golang 的 gin 框架中使用自定义日志模块的一些方法。

背景

很早之前就实现并使用了自己封装的日志模块，但一直没有将gin框架内部的日志和日志模块结合。gin的日志都是在终端上打印的，排查问题不方便。趁五一假期，集中研究把此事了了。

实践

gin支持中间件，对于一些常用接口，也提供了自定义函数。本文主要是从这2方面着手。

据官方demo，在初始化时基本都使用如下语句初始化内部日志（Logger()）和panic恢复功能（Recovery()）。

router.Use(gin.Logger())
router.Use(gin.Recovery())

默认输出日志：

[GIN] 2024/05/08 - 09:09:13 | 200 |    1.082244ms |             ::1 | GET      "/info"

自定义Writer

gin对外提供了DefaultWriter，类型为io.Writer，默认输出终端，定义如下：

var DefaultWriter io.Writer = os.Stdout

因此可以修改该参数达到自定义输出日志的目的。代码如下：

f, _ := os.OpenFile(filepath.Join("./", "gin.log"), os.O_RDWR|os.O_APPEND|os.O_CREATE, 0666)
gin.DefaultWriter = io.MultiWriter(f)

上述代码在当前目录创建gin.log文件，将gin的日志输出到该文件，效果如下：

[GIN] 2024/05/08 - 09:10:54 | 200 |     844.357µs |             ::1 | GET      "/info"

评：自由度不够。

使用中间件

调用语句router.Use(gin.Logger())中的gin.Logger()实际可理解为中间件函数。函数定义：

func XXX() HandlerFunc {
...
}type HandlerFunc func(*Context)

自定义的中间件函数模板：

func XXXs() gin.HandlerFunc {return func(c *gin.Context) {
...// 下一处理c.Next()
...}
}

日志中间件实现如下：

func filterLogs() gin.HandlerFunc {return func(c *gin.Context) {// Start timerstart := time.Now()path := c.Request.URL.Path// Process requestc.Next()// Stop timerlatency := time.Now().Sub(start)clientIP := c.ClientIP()method := c.Request.MethodstatusCode := c.Writer.Status()klog.Printf("middleware | %3d | %13v | %15s | %-7s %#v\n", statusCode, latency,clientIP, method, path)}
}调用：
router.Use(filterLogs())

注：klog.Printf为自封装的日志模块输出函数。源码可参考klog项目。

效果如下：

[2024-05-08 09:44:34 515] [INFO] middleware | 404 |         738ns |             ::1 | GET     "/info"

评：参数gin框架的日志中间件实现简洁版本，自由度较大。可在此函数中再做其它处理。如统计某path的次数，等。

使用日志格式化回调函数

gin中自带了日志格式化的函数LoggerWithFormatter，该函数参数为函数，原型为type LogFormatter func(params LogFormatterParams) string。其本意是可以自定义输出的日志的字段内容，因此返回值为字符串，默认输出还是使用gin.DefaultWriter。

因此，可以在该函数中添加日志的打印，但不返回字符串，这样gin框架就不会输出日志了。代码如下：

router.Use(gin.LoggerWithFormatter(func(param gin.LogFormatterParams) string {klog.Printf("| %3d | %13v | %15s | %-7s %#v\n%s", param.StatusCode, param.Latency,param.ClientIP, param.Method, param.Path, param.ErrorMessage)return ""
}))

效果如下：

[2024-05-08 09:44:34 516] [INFO] | 200 |    1.580895ms |             ::1 | GET     "/info"

评：利用现有的中间件，自实现部分代码较简洁。可在此函数中再做其它处理。如统计某path的次数，等。

Recovery中间件实现

gin框架默认的Recovery处理函数gin.Recovery()。与上类似，输出信息也是使用内部日志模块的。为保存可能出现的panic信息，因此需要重新实现。由于原代码已经很完备，只是日志与需求不符，因此并无大改，具体代码如下：

// panic日志记录 替换gin的Recovery函数
func filterRecovery() gin.HandlerFunc {return func(c *gin.Context) {defer func() {if err := recover(); err != nil {// Check for a broken connection, as it is not really a// condition that warrants a panic stack trace.var brokenPipe boolif ne, ok := err.(*net.OpError); ok {if se, ok := ne.Err.(*os.SyscallError); ok {if strings.Contains(strings.ToLower(se.Error()), "broken pipe") ||strings.Contains(strings.ToLower(se.Error()), "connection reset by peer") {brokenPipe = true}}}stack := com.GetStack(3)httpRequest, _ := httputil.DumpRequest(c.Request, false)headers := strings.Split(string(httpRequest), "\r\n")for idx, header := range headers {current := strings.Split(header, ":")if current[0] == "Authorization" {headers[idx] = current[0] + ": *"}}headersToStr := strings.Join(headers, "\r\n")if brokenPipe {klog.Printf("%s\n%s", err, headersToStr)} else {klog.Printf("[Recovery] panic recovered:\n%s\n%s", err, stack)}if brokenPipe {// If the connection is dead, we can't write a status to it.c.Error(err.(error)) // nolint: errcheckc.Abort()}}}()c.Next()}
}使用：
router.Use(filterRecovery())

小结

本文介绍的几种方法，基本上都可达到使用自定义日志的目的。笔者实际工程中使用中间件形式，可定制性较高。

附：gin框架日志源码跟踪

外部使用：router.Use(gin.Logger())
--> LoggerWithConfig--> 如未指定formatter，则用defaultLogFormatter--> 如未指定日志输出Write，则用DefaultWriter--> 记录无需要输出的path，存放于skip--> 有请求，遍历skip，如找不到，则组装LogFormatterParams，使用fmt.Fprint输出日志。

从上述流程可以看出，可以通过指定formatter在框架里内嵌自定义的函数，由于会调用fmt.Fprint，因此formatter不返回字符串。当然，可实现自己的中间件替换gin.Logger()。