Go http client 連接池不復用的問題
當 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 被回收，但通過歷史監控圖分析到連接依然很少。????
按照對 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 更不可能。???? 大概率就一個可能，關閉未清空讀緩沖區的連接。
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 裡的。????
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 的代碼，結果不是這樣的。????
分析源碼
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 方法，關閉連接和清理連接池。
// 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 http client 連接池不復用的問題的文章就介紹到這瞭,更多相關Go http client 連接池內容請搜索WalkonNet以前的文章或繼續瀏覽下面的相關文章希望大傢以後多多支持WalkonNet！