context canceled,谁是罪魁祸首?

Golang
590
0
0
2022-08-09

灵魂三问:

  1. 客户端请求超时,取消了请求,服务端还会继续执行么?
  2. 客户端请求超时,取消了请求,服务端还会返回结果么?
  3. 客户端请求超时,取消了请求,服务端会报错么?

问题现象

告警群里有告警,定位到报错的微服务看到如下报错:Post http://ms-user-go.mp.online/user/listByIDs: context canceled

image-20211223104344170

项目中没有发现cancel context的代码,那么context canceled的错误是哪里来的?

特别说明,这里讨论的context是指gin Context中的Request Context

image-20211223164714302

问题复现

image-20211223120759735

  • client请求server1时设置5s超时
  • server1收到请求时先sleep 3秒,然后请求server2并设置5s超时
  • server2收到请求时sleep5

画个时序图看的更直观(看完文章你会发现这是错的):

image-20211223121138694

代码如下:

client:

// client
func main() {
    ctx, cancelFun := context.WithTimeout(context.Background(), time.Second*5)
    defer cancelFun()
    req, err := http.NewRequestWithContext(ctx, http.MethodGet, "http://127.0.0.1:8887/sleep/3", nil)
    if err != nil {
          panic(err)
    }
    do, err := http.DefaultClient.Do(req)
    spew.Dump(do, err)
}

server 1:

// server 1
func main() {
    server := gin.New()
    server.GET("/sleep/:time", func(c *gin.Context) {
        t := c.Param("time")
        t1, _ := strconv.Atoi(t)
        time.Sleep(time.Duration(t1) * time.Second)

        ctx, cancelFun := context.WithTimeout(c.Request.Context(), time.Second*5)
        defer cancelFun()
        req, err := http.NewRequestWithContext(ctx, http.MethodGet, "http://127.0.0.1:8888/sleep/5", nil)
        if err != nil {
              panic(err)
        }
        do, err := http.DefaultClient.Do(req)
        spew.Dump(do, err)

        c.String(http.StatusOK, "sleep "+t)
    })
    server.Run(":8887")
}

Server 2:

func main() {
    server := gin.New()
    server.GET("/sleep/:time", func(context *gin.Context) {
        t := context.Param("time")
        t1, _ := strconv.Atoi(t)
        time.Sleep(time.Duration(t1) * time.Second)
        context.String(http.StatusOK, "sleep "+t)
    })
    server.Run(":8888")
}

抓包分析

client请求server 1

过程:(58533是客户端请求时的随机端口,8887是server 1的服务端口)

image-20211223131051156

  1. 首先是三次握手,clientserver1建立链接(好基友,来牵牵手)
  2. 客户端请求接口(5s超时),服务端返回了ACK(client:我有5s时间,但是只睡你3秒,server 1:好嘞!)
  3. 客户端设置的超时间(5s)时间到了,发送FIN取消请求(client:服务还没好?等不了了,我走了,server 1:好嘞!)
  4. 服务端返回response,但是客户端返回FIN(server 1:我好了,client:我都已经走了,👋)
客户端取消请求之后,服务端居然还返回了结果!

简单总结下:第5秒客户端因为超时时间到,取消了请求。而随后服务端立即返回了结果。重点是服务端结果是在客户端请求之后返回的

server 1请求server 2

过程:(58535是server 1请求时的随机端口,8888是server 2的服务端口)

  1. server 1 sleep3秒之后,开始对server 2发起请求(server1:我要睡你5s,server2:好嘞!)
  2. 2秒过后,因为client取消了请求,server1也取消了对server2的请求(server1:client不要我了,我们的交易也取消,server2:好嘞!)
  3. 又过了3秒,server2终于完成了睡眠,返回了结果(server2:您的服务已完成,server 1:交易早已取消,滚!)

image-20211223131332123

server1取消了请求,server 2居然还在继续sleep

server 2好像有点笨,server 1都取消了请求,server 2还在sleep

报错信息

  • client在第5秒报错context deadline exceeded
  • server 1在第5秒报错context canceled
  • server 2没有报错

事件回顾

正确的时序图

通过抓包分析发现刚开始画的时序图有问题:

错误的:

image-20211223140510937

正确的:

image-20211223120948836

两个时序图的差别就在于server 1处理请求所花费的时间。

server 1提前返回是因为server 1请求的时候绑定了request context。而reqeust contextclient超时之后立即被cancel掉了,从而导致server 1请求server 2http请求被迫停止。

context什么时候cancel的

接下来看下源代码:(go.1.17 & gin.1.3.0,可以跳过代码看小结部分)

server端接受新请求时会起一个协程go c.serve(connCtx)

func (srv *Server) Serve(l net.Listener) error {
 // ... 
    for {
        rw, err := l.Accept()
        connCtx := ctx
     // ... 
        go c.serve(connCtx)
    }
}

协程里面for循环从链接中读取请求,重点是这里每次读取到请求的时候都会启动后台协程(w.conn.r.startBackgroundRead())继续从链接中读取。

// Serve a new connection.
func (c *conn) serve(ctx context.Context) {
                // ... 
   // HTTP/1.x from here on.

   ctx, cancelCtx := context.WithCancel(ctx)
   c.cancelCtx = cancelCtx
   defer cancelCtx()

             // ...
   for {
      // 从链接中读取请求
      w, err := c.readRequest(ctx)
      if c.r.remain != c.server.initialReadLimitSize() {
         // If we read any bytes off the wire, we're active.
         c.setState(c.rwc, StateActive, runHooks)
      }

                            // ....

      // 启动协程后台读取链接
      if requestBodyRemains(req.Body) {
         registerOnHitEOF(req.Body, w.conn.r.startBackgroundRead)
      } else {
         w.conn.r.startBackgroundRead()
      }

      // ... 
      // 这里转到gin里面的serverHttp方法
      serverHandler{c.server}.ServeHTTP(w, w.req)

      // 请求结束之后cancel掉context
      w.cancelCtx()
      // ...
   }
}

gin中执行ServeHttp方法

// ServeHTTP conforms to the http.Handler interface.
func (engine *Engine) ServeHTTP(w http.ResponseWriter, req *http.Request) {
    // ... 
    // 执行我们写的handle方法
          engine.handleHTTPRequest(c)
    // ...
}

目前为止,我们看到是请求结束之后才会cancel掉context,而不是cancel掉context导致的请求结束。

那是什么时候cancel掉context的呢?

秘密就在w.conn.r.startBackgroundRead()这个后台读取的协程里了。

func (cr *connReader) startBackgroundRead() {
    // ... 
    go cr.backgroundRead()
}

func (cr *connReader) backgroundRead() {
    n, err := cr.conn.rwc.Read(cr.byteBuf[:])
 // ... 
    if ne, ok := err.(net.Error); ok && cr.aborted && ne.Timeout() {
        // Ignore this error. It's the expected error from 
        // another goroutine calling abortPendingRead.
    } else if err != nil {
                    cr.handleReadError(err)
    }
    // ...
}

func (cr *connReader) handleReadError(_ error) {
       // 这里cancel了context
    cr.conn.cancelCtx()
    cr.closeNotify()
}

startBackgroundRead -> backgroundRead -> handleReadError。代码一顿跟踪,最终发现在handleReadError函数里面会把context cancel掉。

原来如此,当服务端在处理业务的同时,后台有个协程监控链接的状态,如果链接有问题就会把context cancel掉。(cancel的目的就是快速失败——业务不用处理了,就算服务端返回结果,客户端也不会处理了)

那当客户端超时的时候,backgroundRead协程序会收到EOF的错误。抓包看对应的就是FIN报文。

image-20211223160513420

image-20211223160602783

从业务代码中看到的context就是context canceled 状态

image-20211223160824497

总结

客户端超时

客户端超时场景总结如下

  • 客户端本身会收到context deadline exceeded错误
  • 服务端对应的请求中的request contextcancel
  • 服务端业务可以继续执行业务代码,如果有绑定request context(比如http请求),那么会收到context canceled错误
  • 尽管客户端请求取消了,服务端依然会返回结果

context 生命周期

下面再来看看request context的生命周期

image-20211223162851921

  • 大多数情况下,context一直能持续到请求结束
  • 当请求发生错误的时候,context会立刻被cancel

ctx避坑

  • http请求中不要使用gin.Context,而要使用c.Request.Context()(其他框架类似)
  • http请求中如果启动了协程,并且在response之前不能结束的,不能使用request context(因为response之后context就会被cancel掉了),应当使用独立的context(比如context.Background()
  • 如果业务代码执行时间长、占用资源多,那么去感知contextcancel,从而中断执行是很有意义的。(快速失败,节省资源)