从一次线上问题排查发现的 fasthttp 设置问题

徐徐 in Beijing

2021-01-12

# 起因

近期由于新上的一个系统新版本出现了 bug，现象是某个 HTTP 接口会在接受一定量请求之后 hang 住，伴随着产生了大量调用方的超时报警。由于新上的系统不是面向用户的系统，所以要求运维保留现场，关掉了触发问题请求的任务，开始排查问题。

最后找到问题的原因很简单：sqlx 库使用了 Queryx 方法，查询由于只是判断记录是否存在，所以并没有读取返回的 Rows，这就导致了一个问题，就是数据库连接不会被释放回池子里，由于设置了最大连接数，所以导致接口被 hang 死。

这里也有了一个教训，无论是什么级别的系统，还是在测试环境多跑跑。

言归正传，今天要讨论的主题并不是这个低级错误。在修复完 bug 之后，由于之前的服务一直保留现场，所以修复的代码打包完成后直接在公司内部的 k8s 平台操作上线了，这时产生了一个诡异的现象，突然之间收到了大约三千多个请求，似乎是之前被 hang 住的请求被复活一样。

这就诡异了。

接下来就是搞清楚这个问题，比较担心是某些未知的 bug 导致的。

# 问题探究

我先从这三千多个请求中随机挑选了几个，由于每个请求都有 TraceId，所以直接去请求方日志中搜寻，发现这些请求的确是在故障发生时候请求的，并且还有请求超时的错误信息。在服务修复之后上线重启的时间段，并没有对应的请求日志。

由于有请求服务的代码权限，所以直接拉取代码，想直接在代码中找找线索。排查过程中发现，调用方服务 HTTP 请求是使用的 fasthttp 库，代码也很简单，核心逻辑如下：

fasthttp.DoTimeout(req, resp, time.Second)

代码中设置了超时时间，隐约的感觉这个问题应该和 fasthttp 库有关。接下来就是看一下 fasthttp 的代码，果然发现了一处重试逻辑： client.go#L1231 (opens new window)

for {
  retry, err = c.do(req, resp)
  if err == nil || !retry {
    break
  }

  if hasBodyStream {
    break
  }
  if !isRequestRetryable(req) {
    if err != io.EOF {
      break
    }
  }
  attempts++
  if attempts >= maxAttempts {
    break
  }
}

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

当服务重启的时，c.do() 返回 retry=true，err=io.EOF，fasthttp 会触发重试逻辑。当再次重试的时候，可能已经请求到重启之后的服务了，这里要说一下，这个过程在本地不是特别好复现，一般情况下，k8s 都是滚动发布，先拉起新的服务，服务探活正常，然后会把依次把旧的服务下线，旧服务下线时，调用方会收到 io.EOF。新的服务注册到负载均衡或者服务发现上，也就是平滑重启，所以这个时候 fasthttp 进行 retry 直接请求到正常服务上。

do() 函数内部产生 retry=true，err=io.EOF 返回结果的位置代码逻辑如下： client.go#L1383 (opens new window)

br := c.acquireReader(conn)
if err = resp.ReadLimitBody(br, c.MaxResponseBodySize); err != nil {
  c.releaseReader(br)
  c.closeConn(cc)
  retry := err != ErrBodyTooLarge
  return retry, err
}

1
2
3
4
5
6
7

实际上，每个请求都会阻塞在 ReadLimitBody，也就是读取服务端响应数据的这行，直到服务重启。这个时候就如上面所说的，触发重试逻辑。

之所以会阻塞直到服务端重启，是因为没有设置连接的 ReadTimeout（TCP 的超时设置），默认情况下，fasthttp 这个选项是 0，也就是没有限制，会无限等待下去。但是如果这里设置了 ReadTimeout 的时间，其实还是会重试，只是会在重试超过 maxAttempts（默认为 5）次数之后退出请求。如果不想进行重试，需要设置 fasthttp.Client 的 RetryIf 函数。

关于设置 ReadTimeout 的问题 fasthttp 在 DoTimeout 方法上也有相关的注释：

// Warning: DoTimeout does not terminate the request itself. The request will
// continue in the background and the response will be discarded.
// If requests take too long and the connection pool gets filled up please
// try using a Client and setting a ReadTimeout.

1
2
3
4

# Go HTTP 标准库的重试逻辑

之后我也简单研究了一下标准库的重试逻辑，代码位置在： transport.go#L661 (opens new window)

Go 标准库会在如下情况下进行重试：

HTTP2 相关，具体参考 issues/16582 (opens new window)
请求是可重试的 http.(*Request).isReplayable 并且 Transport 在读取 Response 第一个 byte 的时候出错
请求是可重试的 http.(*Request).isReplayable 并且 Transport 新建立的 TCP 链接或者 Keep-Alive 的链接在没有请求的情况下返回了 io.EOF 或者读取到了 HTTP 408（一般是远程服务器主动关闭链接），这部分逻辑在：transport.go#L2186 (opens new window)

上述后面两点主逻辑代码在 persistConn.readLoop 函数内，readLoop 会调用 readLoopPeekFailLocked 函数来构造上述两个类型的错误： transport.go#L2005 (opens new window)

标准库对于可重试的定义代码 http.(*Request).isReplayable： request.go#L1392 (opens new window)

# goroutine 泄漏问题

如果 HTTP 请求未设置 TCP 级别读取或者写入的超时时间，读取或者写入的 goroutine 便会永远阻塞，无法被复用，这时候如果有新请求会建立新的连接，也算是产生 goroutine 泄漏。

请求库的超时设置本质上只是库级别的一个 timer，不对下层 TCP 起作用。

但是标准库并不会产生泄漏问题，当请求超时的时候，标准库会直接关闭 TCP 链接，这部分代码在： transport.go#L2608 (opens new window)、 transport.go#L2656 (opens new window)

fasthttp 就没用这么幸运了，并没有这个机制，所以 fasthttp 只能通过设置 TCP 的超时来解决。

fasthttp 被阻塞的 goroutine：

fasthttp

# 起因

# 问题探究

# Go HTTP 标准库的重试逻辑

# goroutine 泄漏问题

# 最后