golang的Gin框架异步Context异常

引言

前两天做的数据导入功能，考虑到后端处理比较慢，所以前端上传完文件，后端开启协程异步进行处理，同时立即返回给前端一个上传成功标识及本次上传的uuid。前端拿着返回的uuid进行轮训查询后端处理状态。逻辑上没有问题，但偶现获取 ctx 中存储的信息为空。

1.分析复现

1.1操作流程

1.执行上传接口: /upload

2.紧接着执行查询状态接口：/check-status

问题：有时上传接口中的异步内部获取 tid 失败（为nil）。

1.2 简化后代码逻辑

package main

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

func main() {
 r := gin.Default()

 // 上传接口
 r.GET("/upload", func(c *gin.Context) {
  // 设置tid的值
  c.Set("tid", "abc")
  // 异步处理业务
  go func() {
   // 打印 ctx 的地址，以及tid的值
   fmt.Printf("\nupload-1------:%p, tid:%+v\n", c, c.Value("tid"))
   // 处理业务，使用sleep替代处理逻辑
   time.Sleep(time.Second * 10)
   // 再次打印 ctx 的地址，以及tid的值
   fmt.Printf("\nupload-2======:%p, tid:%+v\n", c, c.Value("tid"))
  }()
  // 立即返回给前端
  c.JSON(200, gin.H{
   "message": "upload pong",
   "uuid":    "123",
  })
 })

 // 获取上传后的处理状态
 r.GET("/check-status", func(c *gin.Context) {
  fmt.Printf("\ncheck-status ctx***********:%p\n", c)
  c.JSON(200, gin.H{
   "message": "check status pong",
   "uuid":    c.Query("uuid"),
  })
 })

 // 启动http服务
 if err := r.Run(":80"); err != nil {
  fmt.Println("listen err")
 }
}

2. 问题分析

2.1 因为子协程直接使用父协程的变量？

刚开始考虑的方向是 子协程直接使用父协程中的变量c，引起的问题？那么把c 传进协程，能否解决？于是代码改为：

// 省略前面未改到代码...

  // 异步处理业务
  go func(c context.Context) {
   // 打印 ctx 的地址，以及tid的值
   fmt.Printf("\nupload-1------:%p, tid:%+v\n", c, c.Value("tid"))
   // 处理业务，使用sleep替代处理逻辑
   time.Sleep(time.Second * 10)
   // 再次打印 ctx 的地址，以及tid的值
   fmt.Printf("\nupload-2======:%p, tid:%+v\n", c, c.Value("tid"))
  }(c)

// 省略后面未改动代码...

改动后再按1.1操作流程还是会出现此问题。分析原因是因为ctx本身就是指针类型，所以传进子协程，父协程把 ctx修改了依然后引起子协程的获取失败。但问题是现在父协程也没有修改ctx，那是什么问题？

2.2 发现Gin的问题

因为在sleep之前可以成功获取ctx中的值，sleep之后ctx中存储的值为空，可以肯定的是ctx被修改了。可查看了一下自己写的代码，根本没有地方修改ctx。那么查找一下gin包中有没有修改ctx的方法。

发现确实在gin包中的 context.go 文件中有个 reset() 方法：

// Copyright 2014 Manu Martinez-Almeida. All rights reserved.
// Use of this source code is governed by a MIT style
// license that can be found in the LICENSE file.

package gin

... 省略不相关的代码

func (c *Context) reset() {
 c.Writer = &c.writermem
 c.Params = c.Params[:0]
 c.handlers = nil
 c.index = -1

 c.fullPath = ""
 c.Keys = nil
 c.Errors = c.Errors[:0]
 c.Accepted = nil
 c.queryCache = nil
 c.formCache = nil
 c.sameSite = 0
 *c.params = (*c.params)[:0]
 *c.skippedNodes = (*c.skippedNodes)[:0]
}

这个方法中有c.Keys = nil，可能是它引起的问题。找到 gin 包中的 gin.go 文件中的 ServeHTTP() 方法：

// ServeHTTP conforms to the http.Handler interface.
func (engine *Engine) ServeHTTP(w http.ResponseWriter, req *http.Request) {
 c := engine.pool.Get().(*Context)
 c.writermem.reset(w)
 c.Request = req
 c.reset()

 engine.handleHTTPRequest(c)

 engine.pool.Put(c)
}

注意到 c.reset() 方法上面3行中的 c := engine.pool.Get().(*Context) 这是什么玩意？engine.pool 是 sync.Pool 类型，可以看出来，gin把 ctx 放在了一个缓存池中。大爷的，原因不会是我上传时使用的ctx因为异常还没有使用完，又被重新使用了吧？其实通过打印多次访问的日志可以看出来，当上传使用的 ctx 与 查询状态使用的 ctx 地址相同（证明是同一个ctx被重复使用）时 上传接口的异步sleep后是获取不到tid的。

因为是从缓冲池中获取 ctx ，不一定每次都能获取到与 上传接口相同的 ctx，下面代码就没有获取到相同的 ctx ，所以上传异步sleep后还是可以获取到 tid 的值：

// 上传接口，sleep前输出ctx地址，以及tid的值
upload-1------:0xc000163a00, tid:abc
[GIN] 2023/07/05 - 10:10:52 | 200 |       505.8µs |       127.0.0.1 | GET      "/upload"
// 获取状态，从地址可以看出来与上传是不同的ctx
check-status ctx***********:0xc00047c100
[GIN] 2023/07/05 - 10:10:57 | 200 |       992.1µs |       127.0.0.1 | GET      "/check-status?uuid=123"
// 获取状态，从地址可以看出来与上传是不同的ctx
check-status ctx***********:0xc00047c100
// 上传接口，sleep后输出的ctx地址，以及tid的值，这个是正确的
upload-2======:0xc000163a00, tid:abc

下面请求获取状态接口，（多刷几遍可能会一样）正好使用了与上传接口相同的ctx，导致问题出现：

// 上传接口，sleep前输出ctx地址，以及tid的值
upload-1------:0xc0000a0100, tid:abc
[GIN] 2023/07/05 - 10:18:34 | 200 |            0s |       127.0.0.1 | GET      "/upload"
// 获取状态，从地址可以看出来与上传使用的是相同的 ctx: 0xc0000a0100
check-status ctx***********:0xc0000a0100
[GIN] 2023/07/05 - 10:18:37 | 200 |       140.4µs |       127.0.0.1 | GET      "/check-status?uuid=123"
// 上传接口，sleep后输出的ctx地址，以及tid的值，这时获取tid就为空
upload-2======:0xc0000a0100, tid:<nil>

注：获取地址时不能使用 &c 去获取指针的地址。&c是存储指针的空间的地址，不是实际指针的地址。

这时再去看官方的文档，有一节 “在中间件中使用 Goroutine”:

当在中间件或 handler 中启动新的 Goroutine 时，不能使用原始的上下文，必须使用只读副本。

func main() {
 r := gin.Default()

 r.GET("/long_async", func(c *gin.Context) {
  // 创建在 goroutine 中使用的副本
  cCp := c.Copy()
  go func() {
   // 用 time.Sleep() 模拟一个长任务。
   time.Sleep(5 * time.Second)

   // 请注意您使用的是复制的上下文 "cCp"，这一点很重要
   log.Println("Done! in path " + cCp.Request.URL.Path)
  }()
 })

 r.GET("/long_sync", func(c *gin.Context) {
  // 用 time.Sleep() 模拟一个长任务。
  time.Sleep(5 * time.Second)

  // 因为没有使用 goroutine，不需要拷贝上下文
  log.Println("Done! in path " + c.Request.URL.Path)
 })

 // 监听并在 0.0.0.0:8080 上启动服务
 r.Run(":8080")
}

3. 解决问题

通过查看官方，我们只需要把 gin的ctx 复制一份传在协程中使用，那么协程中使用的 ctx 就不会存在与 Gin的 缓存池中了，就可以安全使用了。正确代码如下：

package main

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

func main() {
 r := gin.Default()

 // 上传接口
 r.GET("/upload", func(c *gin.Context) {
  // 设置tid的值
  c.Set("tid", "abc")
  ctx := c.Copy()
  // 异步处理业务
  go func() {
   // 打印 ctx 的地址，以及tid的值
   fmt.Printf("\nupload-1------:%p, tid:%+v\n", ctx, ctx.Value("tid"))
   // 处理业务，使用sleep替代处理逻辑
   time.Sleep(time.Second * 10)
   // 再次打印 ctx 的地址，以及tid的值
   fmt.Printf("\nupload-2======:%p, tid:%+v\n", ctx, ctx.Value("tid"))
  }()
  // 立即返回给前端
  c.JSON(200, gin.H{
   "message": "upload pong",
   "uuid":    "123",
  })
 })

 // 获取上传后的处理状态
 r.GET("/check-status", func(c *gin.Context) {
  fmt.Printf("\ncheck-status ctx***********:%p\n", c)
  c.JSON(200, gin.H{
   "message": "check status pong",
   "uuid":    c.Query("uuid"),
  })
 })

 // 启动http服务
 if err := r.Run(":80"); err != nil {
  fmt.Println("listen err")
 }
}

总结

gin使用了缓存池来提高性能。官方文档中已经提示我们正确的使用方法了，只是没有明确说明为什么要这么做，所以这也不算Gin的BUG，只是我们没有正确使用。类似的做法还有内置的包 fmt.Printf ，有兴趣的同学可以再研究一下 sync.Pool。