Gin框架中间件导致日志重复记录：如何排查两次相同请求的根源？

Gin框架日志重复：排查重复请求的根本原因

在使用Gin框架开发Web应用时，开发者可能会遇到日志重复记录的问题。本文分析一个Gin中间件导致日志重复写入的案例，并解释其根本原因。

问题描述： 自定义Gin中间件logermiddleware负责将请求日志写入文件。然而，运行程序后，观察到相同的请求日志被记录了两次，且时间戳略有差异。日志示例如下：

time="16:48:31" level=info msg="200 | 4.000226207s |     127.0.0.1 | GET | /gapi/MenuGoods/login | HTTP/1.0 | Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.149 Safari/537.36 Edg/80.0.361.69 |  |"
time="2020-04-03T16:48:31+08:00" level=info msg="200 | 4.000226207s |     127.0.0.1 | GET | /gapi/MenuGoods/login | HTTP/1.0 | Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.149 Safari/537.36 Edg/80.0.361.69 |  |"
time="16:54:12" level=info msg="200 | 4.000376069s |     127.0.0.1 | GET | /gapi/MenuGoods/login | HTTP/1.0 | Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.149 Safari/537.36 Edg/80.0.361.69 |  |"
time="2020-04-03T16:54:12+08:00" level=info msg="200 | 4.000376069s |     127.0.0.1 | GET | /gapi/MenuGoods/login | HTTP/1.0 | Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.149 Safari/537.36 Edg/80.0.361.69 |  |"

问题分析： 时间戳的细微差异表明并非中间件本身导致重复写入，而是收到了两次相同的请求。 这可能是由于客户端重复发送请求，或者服务器端存在某种机制导致请求被处理了两次。 日志记录由不同的日志库实例（例如logrus）处理，导致时间戳不同。

奇布塔

基于AI生成技术的一站式有声绘本创作平台

下载

代码分析： logermiddleware 中间件使用 rotatelogs 进行日志文件切割，logrus 进行日志输出。代码逻辑上没有直接导致日志重复写入的缺陷。

结论： 日志重复并非代码错误，而是由于两次独立的请求导致。需要检查应用的业务逻辑，例如前端代码、后端路由配置、中间件顺序等，找出导致重复请求的根本原因。 这可能涉及到客户端的重复提交、服务器端的请求重试机制，或者其他意外的请求触发。