天天看點

分享一次排查CLOSE_WAIT過多的經驗

某日下午有測試人員急匆匆的跑來跟我回報:“有客戶回報供應商附件預覽不了,流程阻塞,需要緊急處理”,我立馬精神起來,畢竟都是付費客戶(目前做B端業務,客戶都是付費使用者,不像C端,出了問題發個道歉聲明也就過去了)。

等她說完,我第一時間用測試賬号登上去驗證,浏覽器一直在轉圈,差不多一分鐘以後出了nginx的504錯誤頁。

分享一次排查CLOSE_WAIT過多的經驗

也許有人對504這個錯誤碼不熟悉,這裡借用百度百科的内容簡單介紹下這個錯誤碼。

作為網關或者代理工作的伺服器嘗試執行請求時,未能及時從上遊伺服器(URI辨別出的伺服器,例如HTTP、FTP、LDAP)或者輔助伺服器(例如DNS)收到響應。

                                                                                                             (内容來源于百度百科)

看到這個錯誤碼第一反應就是下遊服務太慢,導緻nginx請求逾時了,這裡的下遊服務是自研的附件預覽服務,采用SpringBoot開發,整體的請求鍊路如下圖所示:

分享一次排查CLOSE_WAIT過多的經驗

線上預覽的處理流程如下:

1.使用者在業務方站點發起預覽請求;

2.業務方拼接相關參數重定向到預覽服務;

3.預覽服務通過業務方傳遞的附件連結調用業務方接口下載下傳附件到本地;

4.預覽服務将下載下傳的附件轉換成html供使用者線上預覽;

結合上面的處理流程和請求鍊路,初步得到以下兩點猜測:

1.預覽服務調用業務方下載下傳接口過慢;

2.預覽服務本身處理過慢;

帶着這兩點猜測我立馬去檢視日志,結果卻大跌眼鏡,從昨天14點以後就沒有日志輸出了。

請求進不來了?假死?挂了?

我首先确認程序是否存在,程序跑的好好的,為什麼會沒有請求呢,我第一反應是業務代碼有問題,導緻線程被hang占滿了tomcat的線程池,是以立即使用jstack檢視線程情況,意外的是一切正常,線程數不多,更沒有發現死鎖、socket read0等可能導緻線程hang住的情況。

自身沒問題,難道是被其他任務影響了,我繼續使用top檢視系統負載、cpu占用等情況

分享一次排查CLOSE_WAIT過多的經驗

 顯而易見,負載、cpu占用都不高,似乎陷入了僵局。

分享一次排查CLOSE_WAIT過多的經驗

 我猜測可能不是業務代碼的問題,需要跳出業務代碼去查問題,既然沒有請求,那就先從網絡開始查起。

先确認下服務端監聽端口是不是正常。

  

從輸出結果中可以确認預覽服務的監聽端口(8080)雖然是存活的,但有大量的CLOSE_WAIT出現,這顯然是不正常的,難道是CLOSE_WAIT過多導緻超過了檔案描述符的限制,但是我在日志中沒有找到“Too manay open files”,這個猜想随之破滅,有沒有可能是tcp隊列溢出了?

 linux中一切皆檔案,ServerSocket每次accept一個socket意味着需要開啟一個檔案描述符,這個數量并不是無限的,系統中有限制,如果超過限制了就會報Too manay open files。

上面看到的 243 times ,表示全連接配接隊列溢出的次數,隔一陣重新整理一下,發現這個數字還在漲。

既然tcp隊列有溢出,自然是有部分請求到不了預覽服務了,在tcp層就被扔了,但是從昨天14點到現在一點日志也沒有,難道都被扔了,繼續确認目前tcp隊列的情況。

關于tcp隊列的知識,這裡推薦去閱讀淘寶技術團隊寫的一篇文章,通俗易懂。http://jm.taobao.org/2017/05/25/525-1/

Recv-Q代表目前全連接配接隊列的大小,也就是三次握手完成,目前在全連接配接隊列中等待被應用程式accept的socket個數。

Send-Q代表全連接配接隊列的最大值,應用程式可以在建立ServerSocket的時候指定,tomcat預設為100,但是這個值不能超過系統的/proc/sys/net/core/somaxconn,看看jdk中關于這個值的解釋,專業名詞叫backlog。

從上面的輸出可以發現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主動關閉了連接配接,這裡貼一張經典的四次握手的圖。

分享一次排查CLOSE_WAIT過多的經驗

 左邊的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握手過程中建連接配接的流程和隊列

分享一次排查CLOSE_WAIT過多的經驗

 (圖檔來源于https://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那段邏輯就好,貼一下源碼:

邏輯比較簡單,就是一直從ServerSocket中accept socket然後扔給IO多路複用子產品,重點關注下60行,ExceptionUtils.handleThrowable(t)。

如果accept過程中抛了一個異常會怎樣?接着看下ExceptionUtils.handleThrowable(t)的處理邏輯:

如果是ThreadDeath和VirtualMachineError這兩類異常就繼續往上抛了,抛出去意味着什麼呢?

 思考三秒鐘

分享一次排查CLOSE_WAIT過多的經驗

 如果繼續往上抛說明Acceptor線程意外退出運作,自然就不會去tcp隊列中accept連接配接,隊列不堆積才怪呢,想到這兒我立馬去翻一下預覽服務的日志,看會不會有什麼發現,其中有一條日志引起了我的關注。

"http-nio-8080-Acceptor" 正是Acceptor線程的名字,說明Acceptor抛了一個OutOfMemoryError。

OutOfMemoryError和Acceptor退出有什麼關系呢,想想前面提到的handleThrowable邏輯“如果是ThreadDeath和VirtualMachineError這兩類異常就繼續抛出”,這裡的OutOfMemoryError正是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等,之是以沒有花太多篇幅去詳細解釋,一是我對指令的使用經驗有限,二是網絡上不乏鋪天蓋地的說明,講的已經很好。

通過這篇文章,隻是想分享一種排查此類問題的思路,希望你在遇到相似問題的時候帶來些許幫助。

關于TCP 半連接配接隊列和全連接配接隊列 

服務端close-wait或者time-wait狀态過多會導緻什麼樣的後果?

PHP更新導緻系統負載過高問題分析

淺談CLOSE_WAIT

分享一次排查CLOSE_WAIT過多的經驗