分享一次排查CLOSE_WAIT過多的經驗
關鍵詞：TCP、CLOSE_WAIT
問題背景
某日下午有測試人員急匆匆的跑來跟我反饋：「有客戶反饋供應商附件預覽不了，流程阻塞，需要緊急處理」，我立馬精神起來，畢竟都是付費客戶（目前做B端業務，客戶都是付費用戶，不像C端，出了問題發個道歉聲明也就過去了）。
等她說完，我第一時間用測試賬號登上去驗證，瀏覽器一直在轉圈，差不多一分鐘以後出了nginx的504錯誤頁。
初步排查
也許有人對504這個錯誤碼不熟悉，這裡借用百度百科的內容簡單介紹下這個錯誤碼。
504 Gateway Timeout
作為網關或者代理工作的服務器嘗試執行請求時，未能及時從上游服務器（URI標識出的服務器，例如HTTP、FTP、LDAP）或者輔助服務器（例如DNS）收到響應。
(內容來源於百度百科)
看到這個錯誤碼第一反應就是下游服務太慢，導致nginx請求超時了，這裡的下游服務是自研的附件預覽服務，採用SpringBoot開發，整體的請求鏈路如下圖所示：
在線預覽的處理流程如下：
1.用戶在業務方站點發起預覽請求；
2.業務方拼接相關參數重定向到預覽服務；
3.預覽服務通過業務方傳遞的附件鏈接調用業務方接口下載附件到本地；
4.預覽服務將下載的附件轉換成html供用戶在線預覽；
結合上面的處理流程和請求鏈路，初步得到以下兩點猜測：
1.預覽服務調用業務方下載接口過慢；
2.預覽服務本身處理過慢；
帶着這兩點猜測我立馬去查看日誌，結果卻大跌眼鏡，從昨天14點以後就沒有日誌輸出了。
請求進不來了？假死？掛了？
我首先確認進程是否存在，進程跑的好好的，為什麼會沒有請求呢，我第一反應是業務代碼有問題，導致線程被hang佔滿了tomcat的線程池，所以立即使用jstack查看線程情況，意外的是一切正常，線程數不多，更沒有發現死鎖、socket read0等可能導致線程hang住的情況。
自身沒問題，難道是被其他任務影響了，我繼續使用top查看系統負載、cpu佔用等情況
顯而易見，負載、cpu佔用都不高，似乎陷入了僵局。
我猜測可能不是業務代碼的問題，需要跳出業務代碼去查問題，既然沒有請求，那就先從網絡開始查起。
漸入佳境
先確認下服務端監聽端口是不是正常。
第一步：netstat 查看網絡狀態
netstat -aonp Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name Timer tcp 81 0 0.0.0.0:8080 0.0.0.0:* LISTEN 1/java off (0.00/0/0) tcp 0 0 127.0.0.1:8100 0.0.0.0:* LISTEN 24/soffice.bin off (0.00/0/0) tcp 936 0 172.20.4.203:8080 172.20.5.59:40576 CLOSE_WAIT - off (0.00/0/0) tcp 867 0 172.20.4.203:8080 172.20.4.172:57166 CLOSE_WAIT - off (0.00/0/0) tcp 964 0 172.20.4.203:8080 172.20.5.59:50106 CLOSE_WAIT - off (0.00/0/0) tcp 1701 0 172.20.4.203:8080 172.20.4.172:45428 CLOSE_WAIT - off (0.00/0/0) tcp 1169 0 172.20.4.203:8080 172.20.4.172:61582 CLOSE_WAIT - off (0.00/0/0) tcp 963 0 172.20.4.203:8080 172.20.4.172:64474 CLOSE_WAIT - off (0.00/0/0) tcp 1058 0 172.20.4.203:8080 172.20.5.59:44564 CLOSE_WAIT - off (0.00/0/0) tcp 962 0 172.20.4.203:8080 172.20.4.172:64160 CLOSE_WAIT - off (0.00/0/0) tcp 1733 0 172.20.4.203:8080 172.20.4.172:46810 CLOSE_WAIT - off (0.00/0/0) tcp 1587 0 172.20.4.203:8080 172.20.5.59:40032 CLOSE_WAIT - off (0.00/0/0) tcp 994 0 172.20.4.203:8080 172.20.4.172:47474 CLOSE_WAIT - off (0.00/0/0) tcp 867 0 172.20.4.203:8080 172.20.5.59:47134 CLOSE_WAIT - off (0.00/0/0)
netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
CLOSE_WAIT 103
ESTABLISHED 2
從輸出結果中可以確認預覽服務的監聽端口（8080）雖然是存活的，但有大量的CLOSE_WAIT出現，這顯然是不正常的，難道是CLOSE_WAIT過多導致超過了文件描述符的限制，但是我在日誌中沒有找到「Too manay open files」，這個猜想隨之破滅，有沒有可能是tcp隊列溢出了？
linux中一切皆文件，ServerSocket每次accept一個socket意味着需要開啟一個文件描述符，這個數量並不是無限的，系統中有限制，如果超過限制了就會報Too manay open files。
第二步：查看tcp隊列是否溢出
netstat -s | egrep "listen|LISTEN"
243 times the listen queue of a socket overflowed
243 SYNs to LISTEN sockets dropped
上面看到的 243 times ，表示全連接隊列溢出的次數，隔一陣刷新一下，發現這個數字還在漲。
既然tcp隊列有溢出，自然是有部分請求到不了預覽服務了，在tcp層就被扔了，但是從昨天14點到現在一點日誌也沒有，難道都被扔了，繼續確認當前tcp隊列的情況。
關於tcp隊列的知識，這裡推薦去閱讀淘寶技術團隊寫的一篇文章，通俗易懂。//jm.taobao.org/2017/05/25/525-1/
第三步：查看tcp隊列當前情況
ss -lnt State Recv-Q Send-Q Local Address:Port Peer Address:Port LISTEN 101 100
Recv-Q代表當前全連接隊列的大小，也就是三次握手完成，目前在全連接隊列中等待被應用程序accept的socket個數。
Send-Q代表全連接隊列的最大值，應用程序可以在創建ServerSocket的時候指定，tomcat默認為100，但是這個值不能超過系統的/proc/sys/net/core/somaxconn，看看jdk中關於這個值的解釋，專業名詞叫backlog。
The maximum queue length for incoming connection indications (a
request to connect) is set to the {@code backlog} parameter. If
a connection indication arrives when the queue is full, the
connection is refused.
public ServerSocket(int port, int backlog) throws IOException {
this(port, backlog, null);
}
從上面的輸出可以發現Recv-Q已經大於Send-Q，而且這個數量長時間不變，可以得出兩個結論：
1.部分socket一直堆積在隊列中沒有被accept；
2.由於tcp全連接隊列已滿，所以新的socket自然是進不來了。
至此可以初步解釋為什麼從昨天14點開始就一直沒有請求進來了。
深入分析
截止現在可以確定是由於tcp隊列滿導致一直沒有請求進來，但tcp隊列怎麼能從昨天14點一直滿到現在呢，jstack查看當前線程並沒有什麼異常、top查看系統負載、cpu都不高，是什麼讓tomcat不去tcp隊列中accept新的socket呢？
另一方面，通過tcp隊列滿這個現象也可以分析出為什麼那麼多的CLOSE_WAIT，因為socket在tcp的隊列中一直堆積着，還沒等到應用程序處理呢，就達到了nginx的超時時間，nginx主動關閉了連接，這裡貼一張經典的四次握手的圖。
左邊的Initiator（發起者）就是nginx，右邊的Receiver（接受者）就是tomcat，nginx和tomcat通過三次握手已經建立了tcp連接，此時連接暫存在全連接隊列中，等待着tomcat去accept，但是tomcat遲遲不accept，一分鐘過後，nginx等不住了，主動發起了FIN開始關閉連接，此時tomcat側的tcp連接就處在CLOSE_WAIT狀態，理論上來講，tomcat收到nginx的FIN接着就應該close socket，CLOSE_WAIT狀態不會持續太久，難道是tomcat出bug了，沒有響應？
截止現在有兩個疑問：
1.為什麼tomcat不去tcp隊列中accept新的socket呢？
2.為什麼tomcat不響應nginx的關閉socket請求呢？
我們先看第一個疑問「為什麼tomcat不去tcp隊列中accept新的socket呢？」
要揭開這個疑問我們先看一張圖來感受下TCP握手過程中建連接的流程和隊列
（圖片來源於//tech.ebayinc.com/engineering/a-vip-connection-timeout-issue-caused-by-snat-and-tcp-tw-recycle/）
接下來的任務就是搞清楚tomcat是如何處理上圖中的accept邏輯的，我之前看過一部分tomcat源碼，所以這裡直接拋個答案出來吧，就不延伸了，tomcat是通過一個單獨的Acceptor線程去accept socket的，accept之後扔給IO多路復用模塊進行後續的業務處理，在這裡只需要關注處理accept那段邏輯就好，貼一下源碼：
protected class Acceptor extends AbstractEndpoint.Acceptor {
@Override
public void run() {
int errorDelay = 0;
// Loop until we receive a shutdown command
while (running) {
// Loop if endpoint is paused
while (paused && running) {
state = AcceptorState.PAUSED;
try {
Thread.sleep(50);
} catch (InterruptedException e) {
// Ignore
}
}
if (!running) {
break;
}
state = AcceptorState.RUNNING;
try {
//if we have reached max connections, wait
countUpOrAwaitConnection();
SocketChannel socket = null;
try {
// Accept the next incoming connection from the server
// socket
socket = serverSock.accept();
} catch (IOException ioe) {
// We didn't get a socket
countDownConnection();
if (running) {
// Introduce delay if necessary
errorDelay = handleExceptionWithDelay(errorDelay);
// re-throw
throw ioe;
} else {
break;
}
}
// Successful accept, reset the error delay
errorDelay = 0;
// Configure the socket
if (running && !paused) {
// setSocketOptions() will hand the socket off to
// an appropriate processor if successful
if (!setSocketOptions(socket)) {
closeSocket(socket);
}
} else {
closeSocket(socket);
}
} catch (Throwable t) {
ExceptionUtils.handleThrowable(t);
log.error(sm.getString("endpoint.accept.fail"), t);
}
}
state = AcceptorState.ENDED;
}
邏輯比較簡單，就是一直從ServerSocket中accept socket然後扔給IO多路復用模塊，重點關注下60行，ExceptionUtils.handleThrowable(t)。
如果accept過程中拋了一個異常會怎樣？接着看下ExceptionUtils.handleThrowable(t)的處理邏輯：
/**
* Checks whether the supplied Throwable is one that needs to be
* rethrown and swallows all others.
* @param t the Throwable to check
*/
public static void handleThrowable(Throwable t) {
if (t instanceof ThreadDeath) {
throw (ThreadDeath) t;
}
if (t instanceof StackOverflowError) {
// Swallow silently - it should be recoverable
return;
}
if (t instanceof VirtualMachineError) {
throw (VirtualMachineError) t;
}
// All other instances of Throwable will be silently swallowed
}
如果是ThreadDeath和VirtualMachineError這兩類異常就繼續往上拋了，拋出去意味着什麼呢？
思考三秒鐘
如果繼續往上拋說明Acceptor線程意外退出運行，自然就不會去tcp隊列中accept連接，隊列不堆積才怪呢，想到這兒我立馬去翻一下預覽服務的日誌，看會不會有什麼發現，其中有一條日誌引起了我的關注。
Exception in thread "http-nio-8080-Acceptor" java.lang.OutOfMemoryError: Java heap space
“http-nio-8080-Acceptor” 正是Acceptor線程的名字，說明Acceptor拋了一個OutOfMemoryError。
OutOfMemoryError和Acceptor退出有什麼關係呢，想想前面提到的handleThrowable邏輯「如果是ThreadDeath和VirtualMachineError這兩類異常就繼續拋出」，這裡的OutOfMemoryError正是VirtualMachineError的一個子類。
public class OutOfMemoryError extends VirtualMachineError
到這裡可以說真相大白，是因為內存不足導致Acceptor線程在accept的時候拋了OutOfMemoryError，線程直接退出，所以導致大量連接堆積在tcp隊列中。
其實到這兒第二個疑問「為什麼tomcat不響應nginx的關閉socket請求呢？」也就很好解釋了，因為Acceptor的退出，堆積在tcp隊列中的連接tomcat消費不到，自然沒有機會去響應nginx的關閉socket請求了，這裡留個思考題，如果Acceptor不意外退出，那tomcat在拿到一個處於CLOSE_WAIT狀態的連接會怎麼處理？
寫在最後
通過一系列的分析最終得出是由於內存不足導致tomct的Acceptor線程異常退出，進而導致連接堆積在tcp隊列中無法消費，最終引發了兩個問題：
1.新請求一直進不去；
2.大量CLOSE_WAIT狀態的連接存在，而且不會消失。
也許有人會問究竟是什麼導致了內存不足呢，這裡簡單提一下，之前在提到在線預覽處理流程的時候說過，預覽服務會將附件轉化為html提供給用戶在線預覽，轉化這一步是比較耗內存的，有些客戶的附件會達到百兆以上。
文中提到了一些非常有用的命令，比如jstack，top，netstat，ss等，之所以沒有花太多篇幅去詳細解釋，一是我對命令的使用經驗有限，二是網絡上不乏鋪天蓋地的說明，講的已經很好。
通過這篇文章，只是想分享一種排查此類問題的思路，希望你在遇到相似問題的時候帶來些許幫助。
推薦閱讀
服務端close-wait或者time-wait狀態過多會導致什麼樣的後果？
