飞道的博客

Go http client 连接池不复用的问题

263人阅读  评论(0)

当 http client 返回值为不为空,只读取 response header,但不读 body 内容就执行 response.Body.Close(),那么连接会被主动关闭,得不到复用。

测试代码如下:


   
  1. // xiaorui.cc
  2. func HttpGet() {
  3.   for {
  4.   fmt.Println( "new")
  5.   resp, err := http.Get( "http://www.baidu.com")
  6.    if err !=  nil {
  7.    fmt.Println(err)
  8.     continue
  9.   }
  10.    if resp.StatusCode == http.StatusOK {
  11.     continue
  12.   }
  13.   resp.Body.Close()
  14.     
  15.   fmt.Println( "go num", runtime.NumGoroutine())
  16.  }
  17. }

正如大家所想,除了 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 被回收,但通过历史监控图分析到连接依然很少。????

按照对 k8scache 调用方的理解,他们经常粗暴的开启不少协程来对 k8scache 进行访问。已知默认的 golang httpclient transport 对连接数是有默认限制的,连接池总大小为 100,每个 host 连接数为 2。当并发对某 url 进行请求时,无法归还连接池,也就是超过连接池大小的连接会被主动clsoe()。所以,我司的 golang 脚手架中会对默认的 httpclient 创建高配的 transport,不太可能出现连接池爆满被 close 的问题。

如果真的是连接池爆了?  谁主动挑起关闭,谁就有 tcp time-wait 状态,但通过 netstat 命令只发现少量跟 k8scache 相关的 time-wait。

排查问题

已知问题,  为隐藏敏感信息,索性使用简单的场景设立问题的 case

tcpdump抓包分析问题?

包信息如下,通过最后一行可以确认是由客户端主动触发 RST连接重置 。触发RST的场景有很多,但常见的有 tw_bucket 满了、tcp 连接队列爆满且开启 tcp_abort_on_overflow、配置 so_linger、读缓冲区还有数据就给 close。

通过 linux 监控和内核日志可以确认不是内核配置的问题,配置 so_linger 更不可能。???? 大概率就一个可能,关闭未清空读缓冲区的连接。


   
  1. 22: 11: 01.790573 IP (tos  0x0, ttl  64, id  29826, offset  0, flags [DF], proto TCP ( 6), length  60)
  2.     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
  3. 22: 11: 01.801715 IP (tos  0x0, ttl  43, id  0, offset  0, flags [DF], proto TCP ( 6), length  52)
  4.      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
  5. 22: 11: 01.801757 IP (tos  0x0, ttl  64, id  29827, offset  0, flags [DF], proto TCP ( 6), length  40)
  6.     host -46.54550 >  110.242 .68 .3.http: Flags [.], cksum  0x5f4e (incorrect ->  0xb1f5), seq  1, ack  1, win  229, length  0
  7. 22: 11: 01.801937 IP (tos  0x0, ttl  64, id  29828, offset  0, flags [DF], proto TCP ( 6), length  134)
  8.     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
  9.  GET / HTTP/ 1.1
  10.  Host: www.baidu.com
  11.  User-Agent: Go-http-client/ 1.1
  12. 22: 11: 01.814122 IP (tos  0x0, ttl  43, id  657, offset  0, flags [DF], proto TCP ( 6), length  40)
  13.      110.242 .68 .3.http > host -46.54550: Flags [.], cksum  0xb199 (correct), seq  1, ack  95, win  227, length  0
  14. 22: 11: 01.815179 IP (tos  0x0, ttl  43, id  658, offset  0, flags [DF], proto TCP ( 6), length  4136)
  15.      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
  16.  HTTP/ 1.1  200 OK
  17.  Bdpagetype:  1
  18.  Bdqid:  0x8b3b62c400142f77
  19.  Cache-Control: private
  20.  Connection: keep-alive
  21.  Content-Encoding: gzip
  22.  Content-Type: text/html;charset=utf -8
  23.  Date: Wed,  09 Dec  2020  14: 11: 01 GMT
  24.   ...
  25. 22: 11: 01.815214 IP (tos  0x0, ttl  64, id  29829, offset  0, flags [DF], proto TCP ( 6), length  40)
  26.     host -46.54550 >  110.242 .68 .3.http: Flags [.], cksum  0x5f4e (incorrect ->  0xa157), seq  95, ack  4097, win  293, length  0
  27. 22: 11: 01.815222 IP (tos  0x0, ttl  43, id  661, offset  0, flags [DF], proto TCP ( 6), length  4136)
  28.      110.242 .68 .3.http > host -46.54550: Flags [P.], cksum  0x6f4e (incorrect ->  0x07fa), seq  4097: 8193, ack  95, win  227, length  4096: HTTP
  29. 22: 11: 01.815236 IP (tos  0x0, ttl  64, id  29830, offset  0, flags [DF], proto TCP ( 6), length  40)
  30.     host -46.54550 >  110.242 .68 .3.http: Flags [.], cksum  0x5f4e (incorrect ->  0x9117), seq  95, ack  8193, win  357, length  0
  31. 22: 11: 01.815243 IP (tos  0x0, ttl  43, id  664, offset  0, flags [DF], proto TCP ( 6), length  5848)
  32.     ...
  33.     host -46.54550 >  110.242 .68 .3.http: Flags [.], cksum  0x5f4e (incorrect ->  0x51ba), seq  95, ack  24165, win  606, length  0
  34. 22: 11: 01.815369 IP (tos  0x0, ttl  64, id  29834, offset  0, flags [DF], proto TCP ( 6), length  40)
  35.     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。


   
  1. $ lsof -p  54330
  2. COMMAND   PID USER   FD      TYPE    DEVICE SIZE/OFF       NODE NAME
  3. ...
  4. aaa      54330 root     1u      CHR      136, 0       0t0           3 /dev/pts/ 0
  5. aaa      54330 root     2u      CHR      136, 0       0t0           3 /dev/pts/ 0
  6. aaa      54330 root     3u  a_inode       0, 10         0        8838 [eventpoll]
  7. aaa      54330 root     4r     FIFO        0, 9       0t0   223586913 pipe
  8. aaa      54330 root     5w     FIFO        0, 9       0t0   223586913 pipe
  9. aaa      54330 root     6u     IPv4  223596521       0t0        TCP host -46: 60626-> 110.242 .68 .3:http (ESTABLISHED)
  10. $ ss -an|egrep  "68.3:80"
  11. State      Recv-Q      Send-Q       Local Address:Port        Peer Address:Port 
  12. ESTAB       72480        0             172.16 .0 .46: 60626          110.242 .68 .3: 80 

strace 跟踪系统调用

通过系统调用可分析出,貌似只是读取了 header 部分了,还未读到 body 的数据。


   
  1. [pid   8311] connect( 6, {sa_family=AF_INET, sin_port=htons( 80), sin_addr=inet_addr( "110.242.68.3")},  16 <unfinished ...>
  2. [pid  195519] epoll_pwait( 3,  <unfinished ...>
  3. [pid   8311] <... connect resumed>)      =  -1 EINPROGRESS (操作现在正在进行)
  4. [pid   8311] epoll_ctl( 3, EPOLL_CTL_ADD,  6, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32= 2350546712, u64= 140370471714584}} <unfinished ...>
  5. [pid  195519] getsockopt( 6, SOL_SOCKET, SO_ERROR,  <unfinished ...>
  6. [pid  192592] nanosleep({tv_sec= 0, tv_nsec= 20000},  <unfinished ...>
  7. [pid  195519] getpeername( 6, {sa_family=AF_INET, sin_port=htons( 80), sin_addr=inet_addr( "110.242.68.3")}, [ 112-> 16]) =  0
  8. [pid  195519] getsockname( 6,  <unfinished ...>
  9. [pid  195519] <... getsockname resumed>{sa_family=AF_INET, sin_port=htons( 47746), sin_addr=inet_addr( "172.16.0.46")}, [ 112-> 16]) =  0
  10. [pid  195519] setsockopt( 6, SOL_TCP, TCP_KEEPINTVL, [ 15],  4) =  0
  11. [pid  195519] setsockopt( 6, SOL_TCP, TCP_KEEPIDLE, [ 15],  4 <unfinished ...>
  12. [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 ...>
  13. [pid  192595] read( 6,  <unfinished ...>
  14. [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
  15. [pid  192595close( 6 <unfinished ...>

逻辑代码

那么到这里,可以大概猜测问题所在,找到业务方涉及到 httpclient 的逻辑代码。伪代码如下,跟上面的结论一样,只是读取了header,但并未读取完response body数据。

还以为是特殊的场景,结果是使用不当,把请求投递过去后只判断 http code?真正的业务 code 是在 body 里的。????


   
  1. urls := [] string{...}
  2. for _, url :=  range urls {
  3.   resp, err := http.Post(url, ...)
  4.    if err !=  nil {
  5.     // ...
  6.   }
  7.    if resp.StatusCode == http.StatusOK {
  8.     continue
  9.   }
  10.    // handle redis cache
  11.    // handle mongodb
  12.    // handle rocketmq
  13.    // ...
  14.   resp.Body.Close()
  15. }

如何解决

不细说了,把 header length 长度的数据读完就可以了。

分析问题

先不管别人使用不当,再分析下为何出现短连接,连接不能复用的问题。

为什么不读取 body 就出问题?其实 http.Response 字段描述中已经有说明了。当 Body 未读完时,连接可能不能复用。


   
  1.   // The http Client and Transport guarantee that Body is always
  2.   // non-nil, even on responses without a body or responses with
  3.   // a zero-length body. It is the caller's responsibility to
  4.   // close Body. The default HTTP client's Transport may not
  5.   // reuse HTTP/1.x "keep-alive" TCP connections if the Body is
  6.   // not read to completion and closed.
  7.   //
  8.   // The Body is automatically dechunked if the server replied
  9.   // with a "chunked" Transfer-Encoding.
  10.   //
  11.   // As of Go 1.12, the Body will also implement io.Writer
  12.   // on a successful "101 Switching Protocols" response,
  13.   // as used by WebSockets and HTTP/2's "h2c" mode.
  14.  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 的代码,结果不是这样的。????

分析源码

httpclient 每个连接会创建读写协程两个协程,分别使用 reqch 和 writech 来跟 roundTrip 通信。上层使用的response.Body 其实是经过多次封装的,一次封装的 body 是直接跟 net.conn 进行交互读取,二次封装的 body 则是加强了 close 和 eof 处理的 bodyEOFSignal。

当未读取 body 就进行 close 时,会触发 earlyCloseFn() 回调,看 earlyCloseFn 的函数定义,在 close 未见 io.EOF 时才调用。自定义的 earlyCloseFn 方法会给 readLoop 监听的 waitForBodyRead 传入 false,  这样引发 alive 为 false 不能继续循环的接收新请求,只能是退出调用注册过的 defer 方法,关闭连接和清理连接池。


   
  1. // xiaorui.cc
  2. func (pc *persistConn) readLoop() {
  3.  closeErr := errReadLoopExiting  // default value, if not changed below
  4.   defer  func() {
  5.   pc. close(closeErr)       // 关闭连接
  6.   pc.t.removeIdleConn(pc)  // 从连接池中删除
  7.  }()
  8.   ...
  9.  alive :=  true
  10.   for alive {
  11.      ...
  12.   rc := <-pc.reqch   // 从管道中拿到请求,roundTrip 对该管道进行输入
  13.   trace := httptrace.ContextClientTrace(rc.req.Context())
  14.    var resp *Response
  15.    if err ==  nil {
  16.    resp, err = pc.readResponse(rc, trace)  // 更多的是解析 header
  17.   }  else {
  18.    err = transportReadFromServerError{err}
  19.    closeErr = err
  20.   }
  21.     ...
  22.   waitForBodyRead :=  make( chan  bool2)
  23.   body := &bodyEOFSignal{
  24.    body: resp.Body,
  25.     // 提前关闭 !!! 输出false
  26.    earlyCloseFn:  func() error {
  27.     waitForBodyRead <-  false
  28.     ...
  29.    },
  30.     // 正常收尾 !!!
  31.    fn:  func(err error) error {
  32.     isEOF := err == io.EOF
  33.     waitForBodyRead <- isEOF
  34.     ...
  35.    },
  36.   }
  37.   resp.Body = body
  38.    select {
  39.    case rc.ch <- responseAndError{res: resp}:
  40.    case <-rc.callerGone:
  41.     return
  42.   }
  43.    select {
  44.    case bodyEOF := <-waitForBodyRead:
  45.    replaced := pc.t.replaceReqCanceler(rc.cancelKey,  nil// before pc might return to idle pool
  46.     // alive 为 false, 不能继续 continue
  47.    alive = alive &&
  48.     bodyEOF &&
  49.     !pc.sawEOF &&
  50.     pc.wroteRequest() &&
  51.     replaced && tryPutIdleConn(trace)
  52.     ...
  53.    case <-rc.req.Cancel:
  54.    alive =  false
  55.    pc.t.CancelRequest(rc.req)
  56.    case <-rc.req.Context().Done():
  57.    alive =  false
  58.    pc.t.cancelRequest(rc.cancelKey, rc.req.Context().Err())
  59.    case <-pc.closech:
  60.    alive =  false
  61.   }
  62.  }
  63. }

bodyEOFSignal 的 Close():


   
  1. // xiaorui.cc
  2. func (es *bodyEOFSignal) Close() error {
  3.  es.mu.Lock()
  4.   defer es.mu.Unlock()
  5.   if es.closed {
  6.    return  nil
  7.  }
  8.  es.closed =  true
  9.   if es.earlyCloseFn !=  nil && es.rerr != io.EOF {
  10.    return es.earlyCloseFn()
  11.  }
  12.  err := es.body.Close()
  13.   return es.condfn(err)
  14. }

最终会调用 persistConn 的 close(), 连接关闭并关闭closech:


   
  1. // xiaorui.cc
  2. func (pc *persistConn) close(err error) {
  3.  pc.mu.Lock()
  4.   defer pc.mu.Unlock()
  5.  pc.closeLocked(err)
  6. }
  7. func (pc *persistConn) closeLocked(err error) {
  8.   if err ==  nil {
  9.    panic( "nil error")
  10.  }
  11.  pc.broken =  true
  12.   if pc.closed ==  nil {
  13.   pc.closed = err
  14.   pc.t.decConnsPerHost(pc.cacheKey)
  15.    if pc.alt ==  nil {
  16.     if err != errCallerOwnsConn {
  17.     pc.conn.Close()  // 关闭连接
  18.    }
  19.     close(pc.closech)  // 通知读写协程
  20.   }
  21.  }
  22. }

总之

同事的 httpclient 使用方法有些奇怪,除了 head method 之外,还真想不到有不读取 body 的请求。所以,大家知道 httpclient 有这么一回事就行了。

另外,一直觉得 net/http 的代码太绕,没看过一些介绍直接看代码很容易陷进去,有时间专门讲讲 http client 的实现。


转载:https://blog.csdn.net/qcrao/article/details/111570114
查看评论
* 以上用户言论只代表其个人观点,不代表本网站的观点或立场