Go http client 连接池不复用的问题
(编辑：jimmy 日期: 2024/11/13 浏览：3 次 )
当 http client 返回值为不为空，只读取 response header，但不读 body 内容就执行 response.Body.Close()，那么连接会被主动关闭，得不到复用。
测试代码如下：
// xiaorui.cc
func HttpGet() {
for {
fmt.Println("new")
resp, err := http.Get("http://www.baidu.com")
if err != nil {
fmt.Println(err)
continue
}
if resp.StatusCode == http.StatusOK {
continue
}
resp.Body.Close()
fmt.Println("go num", runtime.NumGoroutine())
}
}
正如大家所想，除了 HEAD Method 外，很少会有只读取 header 的需求吧。
话说，golang httpclient 需要注意的地方着实不少。
- 如没有 response.Body.Close()，有些小场景造成 persistConn 的 writeLoop 泄露。
- 如 header 和 body 都不管，那么会造成泄露的连接干满连接池，后面的请求只能是短连接。
上下文
由于某几个业务系统会疯狂调用各区域不同的 k8s 集群，为减少跨机房带来的时延、兼容新老 k8s 集群 api、减少k8s api-server 的负载，故而开发了 k8scache 服务。在部署运行后开始对该服务进行监控，发现 metrics 呈现的 QPS 跟连接数不成正比，qps 为 1500，连接数为 10 个。开始以为触发 idle timeout 被回收，但通过历史监控图分析到连接依然很少。"htmlcode">
22:11:01.790573 IP (tos 0x0, ttl 64, id 29826, offset 0, flags [DF], proto TCP (6), length 60) host-46.54550 > 110.242.68.3.http: Flags [S], cksum 0x5f62 (incorrect -> 0xb894), seq 1633933317, win 29200, options [mss 1460,sackOK,TS val 47230087 ecr 0,nop,wscale 7], length 0 22:11:01.801715 IP (tos 0x0, ttl 43, id 0, offset 0, flags [DF], proto TCP (6), length 52) 110.242.68.3.http > host-46.54550: Flags [S.], cksum 0x00a0 (correct), seq 1871454056, ack 1633933318, win 29040, options [mss 1452,nop,nop,sackOK,nop,wscale 7], length 0 22:11:01.801757 IP (tos 0x0, ttl 64, id 29827, offset 0, flags [DF], proto TCP (6), length 40) host-46.54550 > 110.242.68.3.http: Flags [.], cksum 0x5f4e (incorrect -> 0xb1f5), seq 1, ack 1, win 229, length 0 22:11:01.801937 IP (tos 0x0, ttl 64, id 29828, offset 0, flags [DF], proto TCP (6), length 134) host-46.54550 > 110.242.68.3.http: Flags [P.], cksum 0x5fac (incorrect -> 0xb4d6), seq 1:95, ack 1, win 229, length 94: HTTP, length: 94 GET / HTTP/1.1 Host: www.baidu.com User-Agent: Go-http-client/1.1 22:11:01.814122 IP (tos 0x0, ttl 43, id 657, offset 0, flags [DF], proto TCP (6), length 40) 110.242.68.3.http > host-46.54550: Flags [.], cksum 0xb199 (correct), seq 1, ack 95, win 227, length 0 22:11:01.815179 IP (tos 0x0, ttl 43, id 658, offset 0, flags [DF], proto TCP (6), length 4136) 110.242.68.3.http > host-46.54550: Flags [P.], cksum 0x6f4e (incorrect -> 0x0e70), seq 1:4097, ack 95, win 227, length 4096: HTTP, length: 4096 HTTP/1.1 200 OK Bdpagetype: 1 Bdqid: 0x8b3b62c400142f77 Cache-Control: private Connection: keep-alive Content-Encoding: gzip Content-Type: text/html;charset=utf-8 Date: Wed, 09 Dec 2020 14:11:01 GMT ... 22:11:01.815214 IP (tos 0x0, ttl 64, id 29829, offset 0, flags [DF], proto TCP (6), length 40) host-46.54550 > 110.242.68.3.http: Flags [.], cksum 0x5f4e (incorrect -> 0xa157), seq 95, ack 4097, win 293, length 0 22:11:01.815222 IP (tos 0x0, ttl 43, id 661, offset 0, flags [DF], proto TCP (6), length 4136) 110.242.68.3.http > host-46.54550: Flags [P.], cksum 0x6f4e (incorrect -> 0x07fa), seq 4097:8193, ack 95, win 227, length 4096: HTTP 22:11:01.815236 IP (tos 0x0, ttl 64, id 29830, offset 0, flags [DF], proto TCP (6), length 40) host-46.54550 > 110.242.68.3.http: Flags [.], cksum 0x5f4e (incorrect -> 0x9117), seq 95, ack 8193, win 357, length 0 22:11:01.815243 IP (tos 0x0, ttl 43, id 664, offset 0, flags [DF], proto TCP (6), length 5848) ... host-46.54550 > 110.242.68.3.http: Flags [.], cksum 0x5f4e (incorrect -> 0x51ba), seq 95, ack 24165, win 606, length 0 22:11:01.815369 IP (tos 0x0, ttl 64, id 29834, offset 0, flags [DF], proto TCP (6), length 40) host-46.54550 > 110.242.68.3.http: Flags [R.], cksum 0x5f4e (incorrect -> 0x51b6), seq 95, ack 24165, win 606, length 0
通过 lsof 找到进程关联的 TCP 连接，然后使用 ss 或 netstat 查看读写缓冲区。信息如下，recv-q 读缓冲区确实是存在数据。这个缓冲区字节一直未读，直到连接关闭引发了 rst。
$ lsof -p 54330 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME ... aaa 54330 root 1u CHR 136,0 0t0 3 /dev/pts/0 aaa 54330 root 2u CHR 136,0 0t0 3 /dev/pts/0 aaa 54330 root 3u a_inode 0,10 0 8838 [eventpoll] aaa 54330 root 4r FIFO 0,9 0t0 223586913 pipe aaa 54330 root 5w FIFO 0,9 0t0 223586913 pipe aaa 54330 root 6u IPv4 223596521 0t0 TCP host-46:60626->110.242.68.3:http (ESTABLISHED) $ ss -an|egrep "68.3:80" State Recv-Q Send-Q Local Address:Port Peer Address:Port ESTAB 72480 0 172.16.0.46:60626 110.242.68.3:80
strace 跟踪系统调用
通过系统调用可分析出，貌似只是读取了 header 部分了，还未读到 body 的数据。
[pid 8311] connect(6, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("110.242.68.3")}, 16 <unfinished ...>
[pid 195519] epoll_pwait(3, <unfinished ...>
[pid 8311] <... connect resumed>) = -1 EINPROGRESS (操作现在正在进行)
[pid 8311] epoll_ctl(3, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=2350546712, u64=140370471714584}} <unfinished ...>
[pid 195519] getsockopt(6, SOL_SOCKET, SO_ERROR, <unfinished ...>
[pid 192592] nanosleep({tv_sec=0, tv_nsec=20000}, <unfinished ...>
[pid 195519] getpeername(6, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("110.242.68.3")}, [112->16]) = 0
[pid 195519] getsockname(6, <unfinished ...>
[pid 195519] <... getsockname resumed>{sa_family=AF_INET, sin_port=htons(47746), sin_addr=inet_addr("172.16.0.46")}, [112->16]) = 0
[pid 195519] setsockopt(6, SOL_TCP, TCP_KEEPINTVL, [15], 4) = 0
[pid 195519] setsockopt(6, SOL_TCP, TCP_KEEPIDLE, [15], 4 <unfinished ...>
[pid 8311] write(6, "GET / HTTP/1.1\r\nHost: www.baidu.com\r\nUser-Agent: Go-http-client/1.1\r\nAccept-Encoding: gzip\r\n\r\n", 94 <unfinished ...>
[pid 192595] read(6, <unfinished ...>
[pid 192595] <... read resumed>"HTTP/1.1 200 OK\r\nBdpagetype: 1\r\nBdqid: 0xc43c9f460008101b\r\nCache-Control: private\r\nConnection: keep-alive\r\nContent-Encoding: gzip\r\nContent-Type: text/html;charset=utf-8\r\nDate: Wed, 09 Dec 2020 13:46:30 GMT\r\nExpires: Wed, 09 Dec 2020 13:45:33 GMT\r\nP3p: CP=\" OTI DSP COR IVA OUR IND COM \"\r\nP3p: CP=\" OTI DSP COR IVA OUR IND COM \"\r\nServer: BWS/1.1\r\nSet-Cookie: BAIDUID=996EE645C83622DF7343923BF96EA1A1:FG=1; expires=Thu, 31-Dec-37 23:55:55 GMT; max-age=2147483647; path=/; domain=.baidu.com\r\nSet-Cookie: BIDUPSID=99"..., 4096) = 4096
[pid 192595] close(6 <unfinished ...>
逻辑代码
那么到这里，可以大概猜测问题所在，找到业务方涉及到 httpclient 的逻辑代码。伪代码如下，跟上面的结论一样，只是读取了header，但并未读取完response body数据。
还以为是特殊的场景，结果是使用不当，把请求投递过去后只判断 http code？真正的业务 code 是在 body 里的。"htmlcode">
urls := []string{...}
for _, url := range urls {
resp, err := http.Post(url, ...)
if err != nil {
// ...
}
if resp.StatusCode == http.StatusOK {
continue
}
// handle redis cache
// handle mongodb
// handle rocketmq
// ...
resp.Body.Close()
}
如何解决
不细说了，把 header length 长度的数据读完就可以了。
分析问题
先不管别人使用不当，再分析下为何出现短连接，连接不能复用的问题。
为什么不读取 body 就出问题？其实 http.Response 字段描述中已经有说明了。当 Body 未读完时，连接可能不能复用。
// The http Client and Transport guarantee that Body is always // non-nil, even on responses without a body or responses with // a zero-length body. It is the caller's responsibility to // close Body. The default HTTP client's Transport may not // reuse HTTP/1.x "keep-alive" TCP connections if the Body is // not read to completion and closed. // // The Body is automatically dechunked if the server replied // with a "chunked" Transfer-Encoding. // // As of Go 1.12, the Body will also implement io.Writer // on a successful "101 Switching Protocols" response, // as used by WebSockets and HTTP/2's "h2c" mode. Body io.ReadCloser
众所周知，golang httpclient 要注意 response Body 关闭问题，但上面的 case 确实有关了 body，只是非常规地没去读取 reponse body 数据。这样会造成连接异常关闭，继而引起连接池不能复用。
一般 http 协议解释器是要先解析 header，再解析 body，结合当前的问题开始是这么推测的，连接的 readLoop 收到一个新请求，然后尝试解析 header 后，返回给调用方等待读取 body，但调用方没去读取，而选择了直接关闭 body。那么后面当一个新请求被 transport roundTrip 再调度请求时，readLoop 的 header 读取和解析会失败，因为他的读缓冲区里有前面未读的数据，必然无法解析 header。按照常见的网络编程原则，协议解析失败，直接关闭连接。
想是这么想的，但还是看了 golang net/http 的代码，结果不是这样的。"htmlcode">
// xiaorui.cc
func (pc *persistConn) readLoop() {
closeErr := errReadLoopExiting // default value, if not changed below
defer func() {
pc.close(closeErr) // 关闭连接
pc.t.removeIdleConn(pc) // 从连接池中删除
}()
...
alive := true
for alive {
...
rc := <-pc.reqch // 从管道中拿到请求，roundTrip 对该管道进行输入
trace := httptrace.ContextClientTrace(rc.req.Context())
var resp *Response
if err == nil {
resp, err = pc.readResponse(rc, trace) // 更多的是解析 header
} else {
err = transportReadFromServerError{err}
closeErr = err
}
...
waitForBodyRead := make(chan bool, 2)
body := &bodyEOFSignal{
body: resp.Body,
// 提前关闭 !!! 输出false
earlyCloseFn: func() error {
waitForBodyRead <- false
...
},
// 正常收尾 !!!
fn: func(err error) error {
isEOF := err == io.EOF
waitForBodyRead <- isEOF
...
},
}
resp.Body = body
select {
case rc.ch <- responseAndError{res: resp}:
case <-rc.callerGone:
return
}
select {
case bodyEOF := <-waitForBodyRead:
replaced := pc.t.replaceReqCanceler(rc.cancelKey, nil) // before pc might return to idle pool
// alive 为 false, 不能继续 continue
alive = alive &&
bodyEOF &&
!pc.sawEOF &&
pc.wroteRequest() &&
replaced && tryPutIdleConn(trace)
...
case <-rc.req.Cancel:
alive = false
pc.t.CancelRequest(rc.req)
case <-rc.req.Context().Done():
alive = false
pc.t.cancelRequest(rc.cancelKey, rc.req.Context().Err())
case <-pc.closech:
alive = false
}
}
}
bodyEOFSignal 的 Close()：
// xiaorui.cc
func (es *bodyEOFSignal) Close() error {
es.mu.Lock()
defer es.mu.Unlock()
if es.closed {
return nil
}
es.closed = true
if es.earlyCloseFn != nil && es.rerr != io.EOF {
return es.earlyCloseFn()
}
err := es.body.Close()
return es.condfn(err)
}
最终会调用 persistConn 的 close(), 连接关闭并关闭closech：
// xiaorui.cc
func (pc *persistConn) close(err error) {
pc.mu.Lock()
defer pc.mu.Unlock()
pc.closeLocked(err)
}
func (pc *persistConn) closeLocked(err error) {
if err == nil {
panic("nil error")
}
pc.broken = true
if pc.closed == nil {
pc.closed = err
pc.t.decConnsPerHost(pc.cacheKey)
if pc.alt == nil {
if err != errCallerOwnsConn {
pc.conn.Close() // 关闭连接
}
close(pc.closech) // 通知读写协程
}
}
}
总之
同事的 httpclient 使用方法有些奇怪，除了 head method 之外，还真想不到有不读取 body 的请求。所以，大家知道 httpclient 有这么一回事就行了。
另外，一直觉得 net/http 的代码太绕，没看过一些介绍直接看代码很容易陷进去，有时间专门讲讲 http client 的实现。
下一篇：GO语言开发环境搭建过程图文详解