https://mp.weixin.qq.com/s/sqBdycaClUixZQPgKy52Pw

1 背景

線上有一個高并發(fā)的 HTTP Go 服務(wù)部署在 A 區(qū)域，能夠正常提供服務(wù)。我們有天將 B 區(qū)域的流量也準備切到這個服務(wù)的時候，發(fā)生了一個很詭異的事情。從 A 區(qū)域來的流量全部 200，但是從 B 區(qū)域來的流量全部都 502、504。

2 排查過程

2.1 懷疑網(wǎng)絡(luò)問題

這種從不同區(qū)域一部分流量正常，一部分流量異常，第一直覺覺得是異常流量那塊應(yīng)該是網(wǎng)絡(luò)問題。所以我們讓運維去異常流量 nginx 機器上，發(fā) telnet 和 curl 到服務(wù)上。如圖所示

可以看到 telnet 這個 ip port 端口是通的，說明四層以下網(wǎng)絡(luò)是通的。但是當我們 curl 到對應(yīng)服務(wù)的時候，發(fā)現(xiàn)服務(wù)被連接重置。這時候我們就獻出我們的重啟大法，對該實例進行重啟。發(fā)現(xiàn)該實例的 curl 請求恢復(fù)。所以就可以直接排除我們的網(wǎng)絡(luò)問題。這個時候，我們就要思考了，是啥問題讓我們程序出現(xiàn)這種詭異問題。因為我們還留了一臺問題機器。我們開始著手對他進行分析。

2.2 分析問題機器

2.2.1 查看網(wǎng)絡(luò)問題

我們在出問題的機器上，查看網(wǎng)絡(luò)情況。我們發(fā)現(xiàn)有大量的 CLOSE WAIT 現(xiàn)象。

然后我們查看下 CLOSE WAIT 詳細信息。

可以看到上面有以下情況

• 第二列是 RECVQ，可以看到有很多都大于 1

• Close Wait，來自于探活的客戶端和 nginx 客戶端

• Close Wait 沒有 pid 號（我這里有 root 權(quán)限，不要懷疑我是沒權(quán)限看不到 pid 信息）

第一個說明了 RECVQ 大于 1 的都是 nginx 客戶端，1 的都是探活的客戶端。這一塊說明了 nginx 是被堵住了。

第二個說明了里面探活的客戶端有 8000 條信息，nginx 的 close wait 大概 100 多條

第三個說明了沒有 pid 問題，我們待會在后面分析中會提及。

看到這么多 Close Wait。我們首先要拿出這個四次揮手圖。

這里要注意，客戶端和服務(wù)端是個相對概念。在我們這個問題里，我們的客戶端是探活服務(wù)，服務(wù)端是我們的業(yè)務(wù)服務(wù)。通過這個圖，可以知道我們的客戶端是發(fā)了 close 包，我們的服務(wù)端可能沒有正常響應(yīng) ack 或者 fin 包，導(dǎo)致 server 端出現(xiàn) close wait。

這個 close wait 是沒有 pid 的，并且是探活客戶端導(dǎo)致的，

2.2.2 詭異問題

那不是業(yè)務(wù)導(dǎo)致，那為什么會產(chǎn)生這種現(xiàn)象。排查的時候一堆問號，并且還發(fā)生很多詭異的事情。

• 我們發(fā)現(xiàn) CLOSE WAIT 的客戶端的端口號，在服務(wù)端機器上有，但在客戶端機器上早就消失。CLOSE WAIT 就死在了這臺機器上。

• RECVQ 這么大，為什么服務(wù)還能正常響應(yīng) 200

• 為什么上面 curl 會超時，但是 telnet 可以成功

• 為什么 CLOSE WAIT 沒有 pid

2.2.3 線上調(diào)試

我們使用了sudo strace -p pid，發(fā)現(xiàn)主進程卡住了，想當然的認為自己發(fā)現(xiàn)了問題。但實際過程中，這是正?，F(xiàn)象，我們框架使用了?golang.org/x/net/netutil?里的?LimitListener?，當你的 goroutine 達到最大值，那么就會出現(xiàn)這個阻塞現(xiàn)象，因為沒有可用的 goroutine 了，主進程就卡住了。其他線程會提供服務(wù)，查看全部線程 trace 指令為sudo strace -f -p pid?，當然也可以查看單個線程的?ps -T -p pid?，然后拿到 spid，在執(zhí)行?sudo strace -p spid?。這個調(diào)試還是沒有太大用處，所以就想怎么在線下進行復(fù)現(xiàn)。

3 線下復(fù)現(xiàn)

復(fù)現(xiàn)這個是經(jīng)過線下抓包，調(diào)試出來的。以下我們寫個簡單代碼進行復(fù)現(xiàn)

3.1 server 端代碼

3.2 client 端代碼

3.3 描述

我們將服務(wù)端代碼的?server.Serve(netutil.LimitListener(listener, 1))?里面的限制設(shè)置為 1。然后客戶端代碼的 http 長連接開啟，先做 http 請求，然后再做 tcp 請求?？梢缘玫揭韵陆Y(jié)果。

3.3.1 輸出顯示

3.3.2 命令行顯示

3.3.3 wireshark 顯示

全部請求報文

一個 http 請求報文

一個 tcp 請求報文

3.4 分析

當我們在服務(wù)端設(shè)置了 limit 為 1 的時候，意味這我們服務(wù)端的最大連接數(shù)只能為 1。我們客戶端在使用 http keepalive，會將這個連接占滿，如果這個時候又進行了 tcp 探活，那么這個探活的請求就會被堵到 backlog 里，也就是上面我們看到 3.3.2 中第一個圖，里面的 RECVQ 為 513。

我們先分析 3.3.3 中的前兩個圖。
黑色部分是 http keepalive，其客戶端端口號為 43340，如圖所示
![image.png]

灰色都是 tcp dial 操作，如圖所示

http keepalive 的 close 報文，如圖所示

紅色的是客戶端發(fā)現(xiàn)服務(wù)端有問題（客戶端端口為 43346），進行了連接 RST 操作，如圖所示

可以看到我們的 tcp 的 dial 操作，最后都是返回的 RST 操作，而且這個時間點剛好在 http keepalive 之后。接下來我們就看下 http keepalive 和 tcp dial 的詳細報文。

3.3.3 第三個圖，說明 http keepalive 是在他創(chuàng)建連接后，90s 后客戶端發(fā)的 close 包。
3.3.3 第四個圖，說明 tcp dial 發(fā)送了三次握手后，一次揮手后，客戶端并沒有立即收到接下來的兩次揮手，而是過了 90s 后，才收到后兩次揮手，導(dǎo)致了客戶端 RST 操作。之所以等待 90s 的時間，是之前 tcp keepalive 的操作剛好進行了 close，goroutine 得到釋放，可以使得 connection 被服務(wù) accept，因此這個時候才能發(fā)送 fin 包。

我們這個時候如果在 RECVQ 不多的情況下。就可以復(fù)現(xiàn)一個場景，就是 curl 無法成功，但是 telnet 可以成功，如下所示。

這個和線上情況一樣。

然后我們再來看下為什么線上 CLOSE_WAIT 在服務(wù)端上產(chǎn)生的過程。我們先抓了一個端口為 57688 的請求。可以看到 57688 揮手的時候發(fā)給 8880 的 fin 包，但是 8880 只響應(yīng)了 ack。

所以現(xiàn)場抓包這兩個狀態(tài)變?yōu)?FIN_WAIT2 和 CLOSE_WAIT

我機器上 linux 配置了 FIN_TIMEOUT 為 40s

過 40s 后，可以看到客戶端的 FIN_WAIT 被回收，只留下了服務(wù)端的 CLOSE_WAIT

再過 50s，http 的 keepalive 關(guān)閉連接，釋放出 goroutine，tcp 的 fin 包就會發(fā)出。最終 CLOSE_WAIT 消失

以上我們把線上大部分場景都復(fù)現(xiàn)了，如下所示：

• （復(fù)現(xiàn)了）服務(wù)端監(jiān)聽的 RECVQ 比較大

• （復(fù)現(xiàn)了）服務(wù)端出現(xiàn)了 CLOSE WAIT，帶沒有 pid

• （復(fù)現(xiàn)了）服務(wù)端出現(xiàn)了 CLOSE WAIT 的端口號，在客戶端找不到

• （復(fù)現(xiàn)了）服務(wù)端出現(xiàn)了 CLOSE WAIT，telnet 可以成功，但是沒辦法 curl 成功

• （未復(fù)現(xiàn)）服務(wù)端的 CLOSE WAIT 一直不消失，下文中會解釋，但并不確定

3.5 CLOSE WAIT 不消失的情況

出現(xiàn)這個情況比較極端，而且跟我們業(yè)務(wù)結(jié)合起來，有點麻煩，所以不在處理，請大家仔細閱讀這個文章。https://blog.cloudflare.com/this-is-strictly-a-violation-of-the-tcp-specification/

以上是 CLOSE WAIT 出現(xiàn)的一種場景。并沒有完全驗證這種情況。

4 產(chǎn)生線上問題的可能原因

線上的 nginx 到后端 go 配置的 keepalive，當 GO 的 HTTP 連接數(shù)達到系統(tǒng)默認 1024 值，那么就會出現(xiàn) Goroutine 無法讓出，這個時候使用 TCP 的探活，將會堵在隊列里，服務(wù)端出現(xiàn) CLOSE WAIT 情況，然后由于一直沒有釋放 goroutine，導(dǎo)致服務(wù)端無法發(fā)出 fin 包，一直保持 CLOSE WAIT。而客戶端的端口在此期間可能會被重用，一旦重用后，就造成了混亂。（如果在混亂后，Goroutine 恢復(fù)后，服務(wù)端過了好久響應(yīng)了 fin 包，客戶端被重用的端口收到這個包是返回 RST，還是丟棄？這個太不好驗證）。個人猜測是丟棄了，導(dǎo)致服務(wù)端的 CLOSE WAIT 一直無法關(guān)閉，造成 RECVQ 的一直阻塞。

5 其他問題

• 1. 因為 GO 服務(wù)端的 HTTP Keepalive 是使用的客戶端的 Keepalive 的時間，如果客戶端的 Keepalive 存在問題，比如客戶端的 http keepalive 泄露，也會導(dǎo)致服務(wù)端無法關(guān)閉 Keepalive，從而無法回收 goroutine，當然 go 前面擋了一層 nginx，所以應(yīng)該不會有這種泄露問題。但保險起見，go 的服務(wù)端應(yīng)該加一個 keepalive 的最大值。例如 120s，避免這種問題。

• 2.GO 服務(wù)端的 HTTP chucked 編碼時候，如果客戶端沒有正確將 response 的 body 內(nèi)容取走，會導(dǎo)致數(shù)據(jù)仍然在服務(wù)端的緩沖區(qū)，從而導(dǎo)致無法響應(yīng) fin 包，但這個理論上不會出現(xiàn)，并且客戶端會自動的進行 rst，不會影響業(yè)務(wù)。不過最好避免這種編碼。

• 3 linux keepalive 參數(shù)可能需要配置，但不敢完全確信他的作用，如下所示。

6 其他 CLOSE WAIT 延伸

• 如過寫的 http 服務(wù)存在業(yè)務(wù)問題，例如里面有個死循環(huán)，無法響應(yīng)客戶端，也會導(dǎo)致 http 服務(wù)出現(xiàn) CLOSE WAIT 問題，但這個是有 pid 號的。

• 如果我們的業(yè)務(wù)調(diào)用某個服務(wù)的時候，由于沒發(fā)心跳包給服務(wù)，會被服務(wù)關(guān)閉，但我們這個時候沒正確處理這個場景，那么我們的業(yè)務(wù)處就會出現(xiàn) CLOSE WAIT。

資料

• 線上大量 close wait 問題?

• 網(wǎng)絡(luò)編程 tcp 鏈接?

• tcp close wait 問題?

• tcp keepalive 設(shè)置