context canceled，谁是罪魁祸首？

灵魂三问： 1. 客户端请求超时，取消了请求，服务端还会继续执行么？ 2. 客户端请求超时，取消了请求，服务端还会返回结果么？ 3. 客户端请求超时，取消了请求，服务端会报错么？ # 问题现象 告警群里有告警，定位到报错的微服务看到如下报错：`Post http://ms-user-go.mp.online/user/listByIDs: context canceled`。  项目中没有发现`cancel context`的代码，那么`context canceled`的错误是哪里来的？ > 特别说明，这里讨论的`context`是指`gin Context`中的`Request Context`  # 问题复现  - `client`请求`server1`时设置5s超时 - `server1`收到请求时先`sleep` 3秒，然后请求`server2`并设置5s超时 - `server2`收到请求时`sleep5`秒 画个时序图看的更直观（看完文章你会发现这是错的）：  代码如下： 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的服务端口）  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：交易早已取消，滚！）  > `server1`取消了请求，`server 2`居然还在继续sleep **`server 2`好像有点笨，`server 1`都取消了请求，server 2还在`sleep`** ## 报错信息 - `client`在第5秒报错`context deadline exceeded` - `server 1`在第5秒报错`context canceled` - `server 2`没有报错 # 事件回顾 ## 正确的时序图 通过抓包分析发现刚开始画的时序图有问题： 错误的：  正确的：  两个时序图的差别就在于`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报文。   从业务代码中看到的`context`就是`context canceled` 状态  # 总结 ## 客户端超时 客户端超时场景总结如下 - 客户端本身会收到`context deadline exceeded`错误 - 服务端对应的请求中的`request context`被`cancel`掉 - 服务端业务可以继续执行业务代码，如果有绑定`request context`（比如`http`请求），那么会收到context canceled错误 - **尽管客户端请求取消了，服务端依然会返回结果** ## context 生命周期 下面再来看看`request context`的生命周期  - 大多数情况下，`context`一直能持续到请求结束 - 当请求发生错误的时候，`context`会立刻被`cancel`掉 ## ctx避坑 - http请求中不要使用`gin.Context`，而要使用c.Request.Context()（其他框架类似） - http请求中如果启动了协程，并且在`response`之前不能结束的，不能使用`request context`（因为`response`之后`context`就会被`cancel`掉了），应当使用独立的`context`（比如`context.Background()`） - 如果业务代码执行时间长、占用资源多，那么去感知`context` 被`cancel`，从而中断执行是很有意义的。（快速失败，节省资源）