性能分析之壓測中 TCP 全連接隊列占滿問題分析及優化案例
前言
知識預備
壓測及分析過程
第一次壓測
調大 backlog 值為 5000 后,再次壓測
調整日志級別為 ERROR,再次壓測
前言
知識預備
壓測及分析過程
第一次壓測
調大 backlog 值為 5000 后,再次壓測
調整日志級別為 ERROR,再次壓測
小結
前言
在對一個擋板系統進行測試時,遇到一個由于 TCP 全連接隊列被占滿而影響系統性能的問題,這里記錄下如何進行分析及解決的。
知識預備
理解下 TCP 建立連接過程與隊列:
從圖中明顯可以看出建立 TCP 連接的時候,有兩個隊列:syns queue(半連接隊列)和accept queue(全連接隊列),分別在第一次握手和第三次握手。
半連接隊列: 保存 SYN_RECV 狀態的連接。
控制參數:
半連接隊列的大小:min(backlog, 內核參數 net.core.somaxconn,內核參數 tcp_max_syn_backlog)
net.ipv4.tcp_max_syn_backlog:能接受 SYN 同步包的最大客戶端數量,即半連接上限;
tcp_syncookies:當出現SYN等待隊列溢出時,啟用 cookies 來處理,可防范少量 SYN 攻擊,默認為0,表示關閉;
accept隊列-全連接隊列: 保存 ESTABLISHED 狀態的連接。
控制參數:
全連接隊列的大小:min(backlog, /proc/sys/net/core/somaxconn),意思是取 backlog 與 somaxconn 兩值的最小值,net.core.somaxconn 定義了系統級別的全連接隊列最大長度,而 backlog 只是應用層傳入的參數,所以 backlog 值盡量小于net.core.somaxconn;
net.core.somaxconn(內核態參數,系統中每一個端口最大的監聽隊列的長度);
net.core.netdev_max_backlog(每個網絡接口接收數據包的速率比內核處理這些包的速率快時,允許送到隊列的數據包的最大數目);
ServerSocket(int port, int backlog) 代碼中的backlog參數;
文件句柄;
net.ipv4.tcp_abort_on_overflow = 0,此值為 0 表示握手到第三步時全連接隊列滿時則扔掉 client 發過來的 ACK,此值為 1 則說明握手到第三步時全連接隊列滿時則返回 reset 給客戶端。
壓測及分析過程
系統的整體架構比較簡單,只有一個擋板服務,業務功能主要是接受業務數據寫入日志文件,并加了 35 ms 的延時等待,沒有復雜的運算等業務邏輯。
第一次壓測
以 6000 線程并發,加 1 秒的等待,對擋板服務發起壓力,壓測結果如下:
PS:應客戶要求,為了模擬真實業務場景,用較大并發進行測試。
通過上圖可以看出,當系統吞吐量也就是 TPS 達到 3800 左右的時候,系統開始出現部分請求失敗,繼續壓一段時間后,報錯沒有減少,且有增多的趨勢。這是什么原因導致的呢,接著我也觀察了下,系統的資源使用情況,發現 CPU 也不是很高,那可以先排除系統 CPU 資源的問題。
這時候,我們一定要記住,當出現請求事務大量失敗的時候,一定要先看以下具體的錯誤信息,在繼續往下面分析,而不是進行盲目的猜測,這里要提一下高樓老師經常強調的證據鏈,一定要根據詳細的錯誤信息指向進行下一步分析,不能根據猜測進而通過修改一些參數,或者增加系統資源來解決問題。
以下是具體的報錯信息:
看到報錯信息后,發現有大量的 “Connection reset” 錯誤,導致這種錯誤的原因就是服務端因為某種原因關閉了 Connection,而客戶端仍然在讀寫數據,此時服務器會返回復位標志 “RST”,也就是剛才提到的 `“java.net.SocketException: Connection reset”。
參考 Oracle 的相關文檔,看到這么一段話,原文如下:
By contrast, an abortive close uses the RST (Reset) message. If either side issues an RST, this means the entire connection is aborted and the TCP stack can throw away any queued data which has not been sent or received by either application.
翻譯過來也就是說:
如果任何一方發出RST,這意味著整個連接被中止,TCP棧可以丟棄任何沒有被任何應用程序發送或接收的隊列數據。
這樣的話,問題就很明顯了,接下來看下 TCP 連接隊列的溢出數據統計情況,命令為:“netstat -s”
# 查看TCP半連接隊列溢出: netstat -s | grep LISTEN # 查看TCPaccept隊列溢出: netstat -s | grep overflow
通過反復敲命令,可以看出這個 overflow 的值一直在增加,那么這個現象說明 server 的 TCP 全連接隊列的確是滿了。這時候應該想到的是,全連接隊列已經溢出了,下一步就應該看一下,全連接隊列的占用情況,命令為:
參數說明:
Recv-Q:全連接當前長度
Send-Q:如果連接不是在建立狀態,則是當前全連接最大隊列長度
從上圖第三列的 Send-Q 可以看出,5000 端口服務的全連接隊列最大為 50,而 Recv-Q 為當前使用了多少。在壓測過程中,查看指定端口的 TCP 全連接隊列使用情況,如下:
上圖可以看出,全連接隊列幾乎已經被占滿,那么最終可以確定問題所在了。找到原因后,現在只要增大全連接隊列的長度就可以了。
通過上面介紹的全連接隊列中,我們知道全連接隊列的大小為 backlog 和 somaxconn 的最小值,那么來看下 somaxconn 的取值。
可以看出 somaxconn 的值是很大的,那就只有通知開發,增加應用代碼中的 backlog 的值來加大全連接隊列的長度。
調大 backlog 值為 5000 后,再次壓測
調整后的全連接隊列如下圖所示:
繼續以 6000 并發對系統發起壓力,測試結果如下:
從上面的測試結果數據看出,已經沒有錯誤請求了,再次查看 TCP 全連接隊列的使用情況,Recv-Q 的值也變得很大,但是仍小于 5000,這也說明之前的 50 的確太小,導致全連接隊列被占滿,最終影響系統性能,出現大量請求失敗,到此,由 TCP 連接隊列滿導致的問題解決。
但是仔細看上面的 JMeter 的測試結果數據,發現當系統并發達到 4600 多后,再繼續加大線程,系統的響應時間開始大幅度的增加,TPS增加趨勢變緩,可以看出來此時系統仍存在瓶頸。
發現仍問題后,接著往下分析。系統沒有報錯,響應時間變長,導致系統吞吐量增長速度變慢。這時應該清楚的是,接下來該看什么。首先查看系統CPU使用情況,發現并不是很高,說明不是系統資源不夠用而引起的問題。因為擋板服務本身沒有什么業務邏輯,只是加了 35 ms的延時,那么如果響應時間變慢了,那么多半是由于網絡傳輸出現阻塞導致。
所以使用命令:
netstat -ano | grep 10.231.44.249:5000 | grep ESTABLISHED | more
看下網絡隊列情況:
參數說明:
Send-Q:發送隊列中沒有被遠程主機確認的 bytes 數;
Recv-Q:指收到的數據還在緩存中,還沒被進程讀取,這個值就是還沒被進程讀取的
bytes;一般是CPU處理不過來導致的。
可以看出圖中標紅列的數據不為 0,通過上面的解釋可以判斷出是系統 CPU 處理不過來了,但是CPU也沒有被充分使用,那為什么會出現這種情況呢。接下我們就該看一下,CPU 在做什么。
這里使用阿里的開源工具 arthas(arthas的安裝及使用這里不過多介紹了),看下擋板服務是否存在線程的資源爭用或者阻塞等,發現結果如下,存在大量的線程狀態為 BLOCKED
命令:thread | grep BLOCKED
命令:thread -b
看到具體的線程棧信息后,問題就比較明顯了,是一個寫日志的鎖導致出現線程阻塞,嚴重影響系統的處理能力。
調整日志級別為 ERROR,再次壓測
為了快速的驗證是寫日志導致的,調整日志級別為 ERROR,再次發起壓力,看問題是否解決,測試結果如下:
調整日志級別后,系統的響應時間保持在 37 ms左右,吞吐量有了大幅度的提升,問題解決。
小結
通過上面的分析案例,需注意以下幾點:
壓測時,如果出現請求大量失敗時,記住一定要先解決報錯,在進行下一步的分析;
進行性能分析時,一定要找到相應的證據鏈一步一步的往下分析,而不是盲目的猜測,通過修改參數及加大資源配置來解決問題;
響應時間長,TPS上不去這種問題,一定要對時間進行拆分拆解,找到時間具體慢在哪里,再進行進一步的分析優化。
TCP/IP 自動化測試 高性能計算
版權聲明:本文內容由網絡用戶投稿,版權歸原作者所有,本站不擁有其著作權,亦不承擔相應法律責任。如果您發現本站中有涉嫌抄襲或描述失實的內容,請聯系我們jiasou666@gmail.com 處理,核實后本網站將在24小時內刪除侵權內容。
版權聲明:本文內容由網絡用戶投稿,版權歸原作者所有,本站不擁有其著作權,亦不承擔相應法律責任。如果您發現本站中有涉嫌抄襲或描述失實的內容,請聯系我們jiasou666@gmail.com 處理,核實后本網站將在24小時內刪除侵權內容。