Go 超時引發(fā)大量 fin-wait2
通過grafana監(jiān)控面板，發(fā)現(xiàn)了幾個高頻的業(yè)務緩存節(jié)點出現(xiàn)了大量的fin-wait2，而且fin-wait2狀態(tài)持續(xù)了不短的時間。通過連接的ip地址和抓包數(shù)據(jù)判斷出對端的業(yè)務。除此之外，頻繁地去創(chuàng)建新連接，我們對golang net/http transport的連接池已優(yōu)化過，但established已建連的連接沒有得到復用。
另外，隨之帶來的問題是大量time-wait的出現(xiàn)，畢竟fin-wait2在拿到對端fin后會轉變?yōu)閠ime-wait狀態(tài)。但該狀態(tài)是正常的。
分析問題
通過分析業(yè)務日志發(fā)現(xiàn)了大量的接口超時問題，連接的地址跟netstat中fin-wait2目的地址是一致的。那么問題已經(jīng)明確了，當http的請求觸發(fā)超時，定時器對連接對象進行了關閉。這邊都close了，那么連接自然無法復用，所以就需要創(chuàng)建新連接，但由于對端的API接口出現(xiàn)邏輯阻塞，自然就又觸發(fā)了超時，continue。
// xiaorui.cc
Get "http://xxxx": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
Get "http://xxxx": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
Get "http://xxxx": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
通過strace追蹤socket的系統(tǒng)調(diào)用，發(fā)現(xiàn)golang的socket讀寫超時沒有使用setsockopt so_sndtimeo so_revtimeo參數(shù)。
[pid 34262] epoll_ctl(3, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=1310076696, u64=140244877192984}}) = 0
[pid 34265] epoll_pwait(3, <unfinished ...>
[pid 34262] <... getsockname resumed>{sa_family=AF_INET, sin_port=htons(45242), sin_addr=inet_addr("127.0.0.1")}, [112->16]) = 0
[pid 34264] epoll_pwait(3, <unfinished ...>
[pid 34262] setsockopt(6, SOL_TCP, TCP_NODELAY, [1], 4 <unfinished ...>
[pid 34262] setsockopt(6, SOL_SOCKET, SO_KEEPALIVE, [1], 4 <unfinished ...>
[pid 34264] read(4, <unfinished ...>
[pid 34262] setsockopt(6, SOL_TCP, TCP_KEEPINTVL, [30], 4 <unfinished ...>
...
代碼分析
通過net/http源碼可以看到socket的超時控制是通過定時器來實現(xiàn)的，在連接的roundTrip方法里有超時引發(fā)關閉連接的邏輯。由于http的語義不支持多路復用，所以為了規(guī)避超時后再回來的數(shù)據(jù)造成混亂，索性直接關閉連接。
當觸發(fā)超時會主動關閉連接，這里涉及到了四次揮手，作為關閉方會發(fā)送fin，對端內(nèi)核會回應ack，這時候客戶端從fin-wait1到fin-wait2，而服務端在close-wait狀態(tài)，等待觸發(fā)close syscall系統(tǒng)調(diào)用。服務端什么時候觸發(fā)close動作？需要等待net/http handler業(yè)務邏輯執(zhí)行完畢。
// xiaorui.cc
var errTimeout error = &httpError{err: "net/http: timeout awaiting response headers", timeout: true}
func (pc *persistConn) roundTrip(req *transportRequest) (resp *Response, err error) {
for {
testHookWaitResLoop()
select {
case err := <-writeErrCh:
if debugRoundTrip {
req.logf("writeErrCh resv: %T/%#v", err, err)
}
if err != nil {
pc.close(fmt.Errorf("write error: %v", err))
return nil, pc.mapRoundTripError(req, startBytesWritten, err)
}
if d := pc.t.ResponseHeaderTimeout; d > 0 {
if debugRoundTrip {
req.logf("starting timer for %v", d)
}
timer := time.NewTimer(d)
defer timer.Stop() // prevent leaks
respHeaderTimer = timer.C
}
case <-pc.closech:
...
case <-respHeaderTimer:
if debugRoundTrip {
req.logf("timeout waiting for response headers.")
}
pc.close(errTimeout)
return nil, errTimeout
如何解決
要么加大客戶端的超時時間，要么優(yōu)化對端的獲取數(shù)據(jù)的邏輯，總之減少超時的觸發(fā)。這個問題其實跟 Go 沒有關系，換成openresyt和python同樣有這個問題。