context canceled，谁是罪魁祸首？

Golang
843
0
0
2022-08-09
24_map的基本使用.go
上一篇
go swagger 使用
下一篇

灵魂三问：

  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. 首先是三次握手，client和server1建立链接（好基友，来牵牵手）
  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 context在client超时之后立即被cancel掉了，从而导致server 1请求server 2的http请求被迫停止。

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 context被cancel掉
  • 服务端业务可以继续执行业务代码，如果有绑定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()）
  • 如果业务代码执行时间长、占用资源多，那么去感知context 被cancel，从而中断执行是很有意义的。（快速失败，节省资源）
24_map的基本使用.go
上一篇
go swagger 使用
下一篇