Gin框架日志重复？一份变两份？快速排查解决方法！

本文针对Gin框架中间件日志重复记录问题进行分析和解决。 在使用Gin框架开发Web应用时，开发者可能会遇到日志重复的问题，这并非总是代码缺陷导致，而是由并发请求或日志库缓冲机制引起。文章分析了日志重复的两个主要原因：高并发请求导致的多次写入以及日志库的缓冲延迟。并提供了相应的解决方案，包括使用异步日志写入、日志聚合以及优化日志库配置等方法，最终确保日志记录的准确性和可靠性，提升应用的稳定性和可维护性。 文章还对代码进行了改进建议，提升代码质量。

Gin框架日志重复记录分析及解决方案

在使用Gin框架开发Web应用时，有时会遇到日志重复记录的问题，这通常并非由日志记录中间件本身的代码缺陷引起，而是由其他因素导致的。本文将分析Gin中间件日志重复的常见原因，并提供相应的解决方案。

以下是一个自定义Gin中间件的示例，用于将日志写入文件：

// 日志记录到文件
func loggerMiddleware() gin.HandlerFunc {
    dir := file.GetPwd() // 使用GetPwd()
    logFilePath := fmt.Sprintf("%s/%s%s", dir, setting.AppSetting.RunTimeRootPath, setting.AppSetting.LogSavePath) // 使用AppSetting
    logFileName := "gin"

    // 日志文件路径
    filePath := path.Join(logFilePath, logFileName)
    fmt.Println("loggerMiddleware: " + filePath)

    // 创建文件，追加写入
    file, err := os.OpenFile(filePath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0777)
    if err != nil {
        fmt.Println("err", err)
        return func(c *gin.Context) {
            c.Next() // 确保请求继续处理
        }
    }
    defer file.Close() // 添加defer关闭文件

    logger := logrus.New()
    logger.SetLevel(logrus.DebugLevel)
    logger.Out = file

    // 使用rotatelogs进行日志分割
    logWriter, err := rotatelogs.New(
        filePath+".%Y-%m-%d.log",
        rotatelogs.WithLinkName(filePath),
        rotatelogs.WithMaxAge(7*24*time.Hour),
        rotatelogs.WithRotationTime(24*time.Hour),
    )
    if err != nil {
        fmt.Println("rotatelogs err:", err)
        return func(c *gin.Context) {
            c.Next()
        }
    }

    writeMap := lfshook.WriterMap{
        logrus.InfoLevel:  logWriter,
        logrus.FatalLevel: logWriter,
        logrus.DebugLevel: logWriter,
        logrus.WarnLevel:  logWriter,
        logrus.ErrorLevel: logWriter,
        logrus.PanicLevel: logWriter,
    }

    logger.AddHook(lfshook.NewHook(writeMap, &logrus.TextFormatter{
        TimestampFormat: "15:04:05",
    }))

    return func(c *gin.Context) {
        startTime := time.Now()
        c.Next()
        endTime := time.Now()
        logger.Infof("%3d | %8v | %13s | %s | %s | %s | %s | %s |",
            c.Writer.Status(),
            endTime.Sub(startTime),
            c.ClientIP(),
            c.Request.Method,
            c.Request.RequestURI,
            c.Request.Proto,
            c.Request.UserAgent(),
            c.Request.Referer(),
        )
    }
}

日志重复原因分析:

观察到的日志重复现象，例如：

time="16:48:31" level=info msg="..."
time="2020-04-03T16:48:31+08:00" level=info msg="..."

虽然时间戳略有不同，但日志内容完全一致，这并非代码本身导致的重复写入。 更可能的原因是：

• 并发请求: 多个请求同时到达服务器，每个请求都触发了中间件，导致日志被多次写入。 时间戳的微小差异正是由于并发请求导致的。
• 日志库的缓冲: logrus 或 rotatelogs 本身可能存在缓冲机制，导致日志写入存在延迟，在短时间内出现看似重复的记录。

解决方案:

1. 确认并发请求: 使用性能测试工具（如wrk, k6）模拟高并发请求，观察日志是否仍然重复。如果重复现象在高并发下加剧，则确认是并发请求导致的问题。

2. 优化日志库配置: 如果确认是并发请求导致的问题，则需要考虑以下优化：

   • 异步日志写入: 使用异步日志库或在中间件中使用 goroutine 异步写入日志，避免阻塞主线程。

   • 日志聚合: 使用集中式日志管理系统（如ELK, Fluentd）来收集和处理日志，可以更有效地处理高并发下的日志写入。

3. 检查日志库的缓冲设置: 检查 logrus 和 rotatelogs 的配置，确保缓冲区大小合理，避免过大的缓冲区导致日志写入延迟。

代码改进建议:

• 使用 defer file.Close() 来确保文件被正确关闭，避免资源泄漏。
• 使用更规范的命名，例如 AppSetting 而不是 appsetting。
• 添加错误处理，在 os.OpenFile 和 rotatelogs.New 失败时，优雅地处理错误，例如记录错误日志并继续处理请求。

通过以上分析和改进，可以有效解决Gin框架中间件日志重复记录的问题，确保日志记录的准确性和可靠性。 关键在于理解日志重复并非一定是代码错误，而是高并发环境下可能出现的正常现象，需要针对性地进行优化。

好了，本文到此结束，带大家了解了《Gin框架日志重复？一份变两份？快速排查解决方法！》，希望本文对你有所帮助！关注golang学习网公众号，给大家分享更多Golang知识！