实现自定义的 Gin Logger 中间件

gin 的中间件原理解析

在 gin 中，中间件是一系列 gin.HandlerFunc 链，它的函数签名类型和我们业务中写的URL对应的 handler 是一样的，都是gin.HandlerFunc。

gin 创建实例时返回一个 Engine，该 Engine 包含一个 RouterGroup，而 RouterGroup 是一个 IRoutes 接口的实现，实现了路由注册的各种方法。

使用 engine.Use 方法可以全局注册多个中间件，也可以在注册URL handler 时局部添加中间件。

gin 在处理请求时，按顺序调用这条 gin.HandlerFunc 链，我们注册到对应请求方法上的 URL handler 在调用链路的最末端，类似于M1(M2(M3(hander())))，执行时由内而外的执行全部 gin.HandlerFunc。

engine.Use 方法是将传入的 gin.HandlerFunc 函数添加到 engine.RouterGroup 的 HandlersChain 中，HandlersChain 是一个 gin.HandlerFunc 列表。

而对应的 GET(string, ...HandlerFunc), POST(string, ...HandlerFunc) 等方法调用时，会将这里面传入的 HandlerFunc 和 engine.RouterGroup 中已存在的 HandlersChain 合并到一起成为一个新的 HandlersChain 注册在对应的URL上，因此请求进来后会执行这里合并后新的 HandlersChain 。

在中间件函数中通过 c.Next() 方法来执行当前 gin.HandlerFunc 后面的全部 gin.HandlerFunc ，即后续的中间件函数和最末端我们的 handler。

因此在一个中间件函数中可以对 handler 执行的前后做你想要做的操作。

c.Next() 之前的操作会在 handler 执行之前执行；c.Next() 之后的操作是在 handler 执行之后再执行。

注意：c.Abort() 方法的作用是停止执行当前 handler 后面的全部 handler，当前 handler 仍然会继续执行。

实际它只是将当前 handler 的执行 index 设置为了一个足够大的值，相当于游标移到了全部 handler 的最后面，下一个 c.Next() 时就跳过了剩余的 handler。

gin 官方的 Logger 中间件

在使用 gin.Default() 创建默认 router 时，其实只是对在原始 router 上默认为你添加了 Logger() 和 Recovery() 两个中间件。

添加 Logger 中间件后有请求进来就会打印请求信息日志，包含当前时间、状态码、请求耗时、客户端 IP、请求路径等信息。支持根据状态码和请求方法的不同在终端展示出不同的背景色。

Logger 中间件对应源码地址： https://github.com/gin-gonic/gin/blob/master/logger.go

配置默认 Logger

Logger 中间件会获取请求相关信息，并通过 LoggerConfig 来控制这些信息的打印输出。

gin 提供了 4 个方法来创建日志中间件：

1. Logger() 以默认配置创建日志中间件，将所有请求信息按指定格式打印到标准输出。

2. LoggerWithWriter(out io.Writer, notlogged ...string) 可以自行设置日志输出位置和不打印日志的 URL 路径，日志格式使用默认配置。

3. LoggerWithFormatter(f LogFormatter) 可以设置自定义的日志格式打印全部请求信息到标准输出，需要自己实现 func(param LogFormatterParams) string 函数，可以参考默认的格式函数defaultLogFormatter。

4. LoggerWithConfig(conf LoggerConfig) 可以自定义 LogFormatter 日志内容格式化函数，io.Writer 类型的日志输出位置（默认为stdout） 和 SkipPaths 列表（其中设置的 URL 路径将不打印日志，默认为空）。

官方 Logger 中间件使用代码示例：

1、使用默认的 Logger:

package main

import (
    "github.com/gin-gonic/gin"
)

func hello(c *gin.Context) {
    c.JSON(200, "world")
}

func main() {
    app := gin.New()
    app.Use(gin.Logger())

    app.GET("/hello", hello)

    app.Run()
}

启动服务并请求 curl https://localhost:8080/hello，会打印出请求信息日志，如图：

2、使用 LoggerWithWriter:

package main

import (
    "os"

    "github.com/gin-gonic/gin"
)

func hello(c *gin.Context) {
    c.JSON(200, "world")
}

func main() {
    app := gin.New()

    logfile := "./gin.log"
    f, err := os.Create(logfile)
    if err != nil {
        panic(err)
    }
    defer f.Close()

        // 将日志输出位置设置为输出到文件
    app.Use(gin.LoggerWithWriter(f))

    app.GET("/hello", hello)

    app.Run()
}

启动服务请求接口，请求信息日志会被打印到当前路径下的 gin.log 中。

如果 notlogged 传了 /hello，这该请求的日志不会被记录。

3、使用 LoggerWithFormatter：

package main

import (
    "fmt"
    "time"

    "github.com/gin-gonic/gin"
)

func hello(c *gin.Context) {
    c.JSON(200, "world")
}

func main() {
    app := gin.New()

    f := func(p gin.LogFormatterParams) string {
        return fmt.Sprintf("--------> time=%v path=%v code=%v\n",
                    p.TimeStamp.Format(time.Kitchen),
                    p.Path, p.StatusCode)
    }
    app.Use(gin.LoggerWithFormatter(f))

    app.GET("/hello", hello)

    app.Run()
}

启动服务请求接口后，日志输出内容如图：

4、使用 LoggerWithConfig:

package main

import (
    "fmt"
    "os"

    "github.com/gin-gonic/gin"
)

func hello(c *gin.Context) {
    c.JSON(200, "world")
}

func main() {
    app := gin.New()

    formatter := func(p gin.LogFormatterParams) string {
        return fmt.Sprintf("[logger] %s %s %s %d %s\n",
            p.TimeStamp.Format("2006-01-02_15:04:05"),
            p.Path,
            p.Method,
            p.StatusCode,
            p.ClientIP,
        )
    }
    conf := gin.LoggerConfig{
        SkipPaths: []string{},
        Output:    os.Stderr,
        Formatter: formatter,
    }
    app.Use(gin.LoggerWithConfig(conf))

    app.GET("/hello", hello)

    app.Run()
}

请求接口日志输出如图：

自定义 Logger 中间件

Logger 中间件主要用于记录访问日志，默认 Logger 可配置项较少不能充分的进行自定义，这里在 logging 中实现一个与官方 Logger 用法类似的全新的日志中间件 GinLogger。

logging 包提供了大量开箱即用的方法可以快速友好的打印日志；过配置灵活设置你的 logger ，支持设置日志级别，输出日志的格式、字段等，支持在服务中动态修改日志级别；并且支持打印带有 trace id 的日志；支持自动将 Error 以上级别的日志上报 Sentry。

gin 的访问日志中间件借助 logging 包主要实现以下比较常见的功能：

• 支持打印 JSON 格式的日志到指定的输出位置；
• 记录更多的请求及响应信息；
• 日志内容支持 trace id，并通过 HTTP header 返回；
• 支持通过配置开关打印请求 body 和 响应 body 信息便于开发调试；
• 支持根据判断 gin.Context 中是否存在 error 或 HTTP 状态码来自动设置日志级别:
  • [-, 400) -> Info
  • [400, 500) -> Warn
  • [500,+] / c.Error(err) -> Error
• 支持将 error 级别的日志自动上报相关错误数据到 sentry。

使用方式如下：

package main

import (
    "github.com/axiaoxin-com/logging"
    "github.com/gin-gonic/gin"
)

func main() {
    gin.SetMode(gin.ReleaseMode)
    r := gin.New()

    // 使用 GinLogger 中间件记录访问日志和生成 trace id
    r.Use(logging.GinLogger())

    r.GET("/ping", func(c *gin.Context) {
        c.String(200, "pong")
    })

    r.Run(":8080")
}

运行 demo：

go run default.go | jq

请求 ping 接口:

curl localhost:8080/ping`

日志输出如下(注意这里使用了 jq 来格式化输出的 JSON 便于查看)：

字段说明：

• level: 当前日志级别
• time: 日志打印时间
• logger: logger 名称
• caller: 打印日志的文件位置
• msg: 日志 msg
• pid: 进程 id
• server_ip: 服务器 ip
• trace_id: 用于日志链路追踪的 trace id
• details: 请求访问的详细信息
  • timestamp: 请求处理完成时间
  • method: 请求方法
  • path: 请求 path
  • query: 请求 query string
  • proto: http 协议版本
  • content_length: 请求内容长度
  • host: 请求的 host
  • remote_addr: 请求的 remote addr (host:port）
  • request_uri: 请求 uri (path?query)
  • referer: 请求 referer
  • user_agent: 请求 user agent
  • client_ip: 真实客户端 IP
  • content_type: 请求 content type
  • handler_name: 处理请求的 gin.HandlerFunc 名称
  • status_code: 响应 http 状态码
  • body_size: 响应 body 字节数
  • latency: 请求处理耗时（秒）
  • context_keys: 开启 DetailsWithContextKeys 配置时展示 gin.Context 中的 keys 信息
  • context_errors: handler 中使用 c.Error(err) 后记录的全部错误信息
  • request_body: 开启 DetailsWithBody 配置时保存请求体信息
  • response_body: 开启 DetailsWithBody 配置时保存响应体信息

自定义选项

跟随官方 Logger 用法，这里提供了使用默认配置的 GinLogger() 和可配置的 GinLoggerWithConfig 来生成中间件，配置项如下：

// GinLoggerConfig GinLogger 支持的配置项字段定义
type GinLoggerConfig struct {
    // Optional. Default value is logging.defaultGinLogFormatter
    Formatter func(GinLogMsg) string
    // SkipPaths is a url path array which logs are not written.
    // Optional.
    SkipPaths []string
    // DisableDetails 是否关闭输出 details 字段信息
    // Optional.
    DisableDetails bool
    // DetailsWithContextKeys 打印 details 时，是否实例 context keys，只在 DisableDetails 为 false 时 生效
    DetailsWithContextKeys bool
    // DetailsWithBody 打印 details 时，是否记录请求 body 和 响应 body，只在 DisableDetails 为 false 时生效
    // 开启后对性能影响严重，适用于接口调试，慎用。
    // Optional.
    DetailsWithBody bool
    // TraceIDFunc 获取或生成 trace id 的函数
    // Optional.
    TraceIDFunc func(*gin.Context) string
}

• Formatter 是指定日志内容中 msg 字段的内容格式，可选项，不设置时使用默认的格式输出。
• SkipPaths 配置项与官方 Logger 功能相同，其中设置的 path 将不打印访问日志。
• DisableDetails 指定是否不打印 details 字段信息，其中记录了访问的详细信息，默认关闭此选项。
• DetailsWithContextKeys 你可以通过该选项设置 details 字段信息中是否记录 gin.Context 中的 keys（只当打印 details 字段时才生效）。
• DetailsWithBody 通过该选项设置 details 字段信息中是否记录请求体和响应体，对性能影响严重，生产环境慎用。
• TraceIDFunc 可通过自定义该方法来设置实际业务中的 trace id 的生成/获取方法，trace id 会被保存到 gin.Context 和 logger 中；默认会分别尝试从请求头，post form 和 querystring 获取，获取不到则生成新的 trace id 。

示例用法：

package main

import (
    "fmt"

    "github.com/axiaoxin-com/logging"
    "github.com/gin-gonic/gin"
)

func main() {

    gin.SetMode(gin.ReleaseMode)
    app := gin.New()
    conf := logging.GinLoggerConfig{
        Formatter: func(m logging.GinLogMsg) string {
            return fmt.Sprintf("%s use %s request %s, handler %s use %f seconds to respond it with %d at %v",
                m.ClientIP, m.Method, m.RequestURI, m.HandlerName, m.Latency, m.StatusCode, m.Timestamp)
        },
        SkipPaths:              []string{},
        DisableDetails:         false,
        DetailsWithContextKeys: true,
        DetailsWithBody:        true,
        TraceIDFunc:            func(c *gin.Context) string { return "fake-uuid" },
    }
    app.Use(logging.GinLoggerWithConfig(conf))
    app.POST("/ping", func(c *gin.Context) {
        c.JSON(200, "pong")
    })
    app.Run(":8888")
}

运行服务：

go run custom.go | jq

请求 ping 接口：

curl localhost:8888/ping -d "this is my request body"

访问日志如下：