前言

G行某平臺(tái)類應(yīng)用系統(tǒng)提供高并發(fā)、低延遲的服務(wù)請(qǐng)求，該系統(tǒng)的的響應(yīng)時(shí)間在1毫秒左右，目前最大TPS在2.5萬(wàn)左右，為保證該系統(tǒng)的快速響應(yīng)，系統(tǒng)設(shè)置的超時(shí)時(shí)間為30毫秒。在一次巡檢中發(fā)現(xiàn)，該系統(tǒng)的幾臺(tái)服務(wù)器超時(shí)交易筆數(shù)在逐漸增加，為避免系統(tǒng)運(yùn)行風(fēng)險(xiǎn)，協(xié)調(diào)網(wǎng)絡(luò)、操作系統(tǒng)等專家一同分析，在分析過程中補(bǔ)充學(xué)習(xí)了大量Linux操作系統(tǒng)內(nèi)核的知識(shí)，現(xiàn)將分析過程及其中用到的知識(shí)點(diǎn)記錄下來，以便為解決類似的問題提供一個(gè)通用的解決思路。

一、應(yīng)用系統(tǒng)超時(shí)現(xiàn)象

外部系統(tǒng)將請(qǐng)求發(fā)送到前端服務(wù)，前端服務(wù)進(jìn)行業(yè)務(wù)邏輯后重新組裝報(bào)文，將請(qǐng)求發(fā)送到后端服務(wù)。交易處理超時(shí)體現(xiàn)在前端服務(wù)對(duì)后臺(tái)服務(wù)的請(qǐng)求上，但是根據(jù)網(wǎng)絡(luò)設(shè)備的鏡像網(wǎng)絡(luò)包分析，后端服務(wù)的處置時(shí)間沒有異常，前端發(fā)送給后端的請(qǐng)求，后端都可以快速的處理。因此問題還是出現(xiàn)在前端服務(wù)上。

圖1 系統(tǒng)邏輯架構(gòu)

由于該系統(tǒng)的交易量大、響應(yīng)時(shí)間低，所以對(duì)處理過程的日志記錄較少，根據(jù)前端服務(wù)的應(yīng)用日志無(wú)法定位根本原因。針對(duì)前端服務(wù)到后臺(tái)服務(wù)的請(qǐng)求，選一段超時(shí)交易較多的時(shí)間段的網(wǎng)絡(luò)鏡像包進(jìn)行分析。發(fā)現(xiàn)超時(shí)交易集中在兩個(gè)固定的時(shí)間點(diǎn)，分別為：11:29:4.200，超時(shí)9筆，平均TCPack_rtt為5毫秒；11:29:54.100，超時(shí)2筆，平均TCPack_rtt為6毫秒，在這兩個(gè)時(shí)間段超時(shí)交易的rtt都大于30毫秒，沒有超時(shí)的交易也有部分ack的rtt相對(duì)較長(zhǎng)。其他正常交易時(shí)間段的ack_rtt在0.06毫秒左右。

圖2 網(wǎng)絡(luò)鏡像包異?，F(xiàn)象

根據(jù)這個(gè)現(xiàn)象初步懷疑在網(wǎng)絡(luò)收發(fā)包上出現(xiàn)了擁堵問題，操作系統(tǒng)網(wǎng)絡(luò)協(xié)議棧對(duì)收到的網(wǎng)絡(luò)包沒有及時(shí)處理。具體處理過程為前端發(fā)送請(qǐng)求到后端服務(wù)，后端服務(wù)立即進(jìn)行了響應(yīng)并返回響應(yīng)包，由于協(xié)議棧沒有及時(shí)處理響應(yīng)包，導(dǎo)致相應(yīng)的ack包沒有及時(shí)返回，同時(shí)導(dǎo)致前端服務(wù)沒有及時(shí)收到后端服務(wù)的返回，從而出現(xiàn)超時(shí)的現(xiàn)象。

為驗(yàn)證懷疑的方向，將一臺(tái)服務(wù)器進(jìn)行物理重啟，重啟后超時(shí)現(xiàn)象消失；同時(shí)將另外一臺(tái)服務(wù)器只重啟應(yīng)用系統(tǒng)，超時(shí)現(xiàn)象沒有出現(xiàn)緩解。因此可以確定交易的超時(shí)現(xiàn)象是由于操作系統(tǒng)的原因?qū)е拢蛻?yīng)用系統(tǒng)的處理性能無(wú)關(guān)。

二、問題排查

由于懷疑和操作系統(tǒng)的協(xié)議棧處理有關(guān)，為便于問題排查，同時(shí)避免對(duì)生產(chǎn)的穩(wěn)定運(yùn)行造成影響，我們使用perf和hping3進(jìn)行異常的復(fù)現(xiàn)和問題分析。perf是Linux的一款性能分析工具，能夠進(jìn)行系統(tǒng)內(nèi)核函數(shù)級(jí)和指令級(jí)的熱點(diǎn)查找，可以用來分析程序中熱點(diǎn)函數(shù)的CPU占用率，從而定位性能瓶頸。Hping3是一個(gè)開源網(wǎng)絡(luò)工具，通過rawSocket直接組裝icmp、udp、tcp報(bào)文，并記錄對(duì)方服務(wù)器的ack響應(yīng)時(shí)間。

圖3 問題排查方案

分析方案是找同子網(wǎng)的另外一臺(tái)服務(wù)器部署hping3工具，向異常服務(wù)器不停的發(fā)送tcp報(bào)文，并記錄ack返回出現(xiàn)延遲的時(shí)間點(diǎn)。在異常的服務(wù)器上部署perf工具，跟蹤操作系統(tǒng)的內(nèi)核調(diào)用，以便發(fā)現(xiàn)異常點(diǎn)。通過hping3每1毫秒發(fā)送一個(gè)網(wǎng)絡(luò)包，記錄其收到ack包的時(shí)間，可以發(fā)現(xiàn)在1650140557這個(gè)時(shí)間點(diǎn)出現(xiàn)大量rtt時(shí)間較長(zhǎng)的情況，分析perf工具采集的內(nèi)核調(diào)用數(shù)據(jù)，可以發(fā)現(xiàn)在相同的時(shí)間點(diǎn)存在大量ss進(jìn)程發(fā)起的請(qǐng)求，當(dāng)時(shí)正在執(zhí)行的系統(tǒng)調(diào)用函數(shù)為read，根據(jù)調(diào)用棧proc_reg_read可以定位為程序正在讀取/proc目錄下的文件內(nèi)容。

圖4 內(nèi)核系統(tǒng)異常調(diào)用棧

由于生產(chǎn)服務(wù)器上部署了各種代理和大量的監(jiān)控腳本，因此懷疑是由這些代理、監(jiān)控腳本發(fā)起的ss命令調(diào)用，在系統(tǒng)中查找使用ss命令的腳本，可以發(fā)現(xiàn)調(diào)用ss的命令行為圖5所示。

圖5 觸發(fā)異常的shell調(diào)用

通過strace跟蹤ss 調(diào)用過程，如圖6所示。

圖6 trace跟蹤ss調(diào)用過程

關(guān)注read處理較慢的系統(tǒng)調(diào)用，可以發(fā)現(xiàn)read處理時(shí)間超過10ms的地方共有5處，最長(zhǎng)的處理時(shí)間在189ms；根據(jù)文件句柄號(hào)3，可以確認(rèn)正在讀取的文件為”/proc/slabinfo”。

圖7 ss命令系統(tǒng)調(diào)用的異常

至此可以確認(rèn)網(wǎng)絡(luò)包接收卡頓，是由于監(jiān)控周期性調(diào)用ss命令導(dǎo)致。ss命令會(huì)讀取/proc/slabinfo，而在讀取的時(shí)候有部分read函數(shù)的系統(tǒng)調(diào)用處理較慢，從而影響了網(wǎng)絡(luò)接收包的處理。

為進(jìn)一步驗(yàn)證上述結(jié)論，我們將異常服務(wù)器上使用ss命令的監(jiān)控腳本停止，并啟動(dòng)前端服務(wù)將其加入生產(chǎn)隊(duì)列，經(jīng)過長(zhǎng)時(shí)間觀察，未再發(fā)現(xiàn)超時(shí)現(xiàn)象。然后手工在服務(wù)器上連續(xù)執(zhí)行幾次cat /proc/slabinfo，可以發(fā)現(xiàn)超時(shí)現(xiàn)象再次出現(xiàn)。

三、深入分析原因

1.第一個(gè)疑問：為什么讀取/proc/slabinfo會(huì)導(dǎo)致網(wǎng)絡(luò)包接收卡頓？

網(wǎng)絡(luò)協(xié)議棧接收tcp報(bào)文并自動(dòng)返回ack，是操作系統(tǒng)在中斷中處理的，優(yōu)先級(jí)別較高，而用戶讀取/proc/slabinfo是一般的系統(tǒng)調(diào)用，為什么會(huì)影響內(nèi)核的中斷處理呢？首先需要了解一下Linux操作系統(tǒng)代碼執(zhí)行的幾個(gè)上下文場(chǎng)景。

硬件中斷上下文：優(yōu)先級(jí)別最高，只要有硬件中斷發(fā)生就會(huì)被立即執(zhí)行，這里包括時(shí)鐘中斷、網(wǎng)卡中斷；

軟件中斷上下文：在硬件中斷執(zhí)行完成或系統(tǒng)調(diào)用完成時(shí)執(zhí)行，這個(gè)是操作系統(tǒng)內(nèi)核核心代碼執(zhí)行的主要環(huán)境，包括進(jìn)程調(diào)度，網(wǎng)絡(luò)協(xié)議棧處理等等；

內(nèi)核進(jìn)程上下文：運(yùn)行在內(nèi)核態(tài)，但是受進(jìn)程調(diào)度管理，按進(jìn)程調(diào)度分配的時(shí)間片執(zhí)行，超過執(zhí)行的時(shí)間片就有可能被別的進(jìn)程搶占而暫停執(zhí)行；

用戶進(jìn)程上下文：這個(gè)是大部分應(yīng)用程序執(zhí)行的環(huán)境，受進(jìn)程調(diào)度管理，按進(jìn)程調(diào)度分配的時(shí)間片執(zhí)行，超過執(zhí)行的時(shí)間片會(huì)強(qiáng)制進(jìn)行進(jìn)程切換。

那他們的執(zhí)行優(yōu)先級(jí)是不是就是：硬件中斷> 軟件中斷> 內(nèi)核進(jìn)程>  用戶進(jìn)程。實(shí)際并不完全是這樣，由于硬件中斷、軟件中斷、內(nèi)核進(jìn)程都運(yùn)行在內(nèi)核態(tài)，運(yùn)行在相同的地址空間，所有的數(shù)據(jù)都是共享的，如果硬件中斷強(qiáng)制中斷軟件中斷的執(zhí)行，軟件中斷強(qiáng)制中斷內(nèi)核進(jìn)程的執(zhí)行，那么有可能會(huì)導(dǎo)致內(nèi)核數(shù)據(jù)的混亂或者導(dǎo)致各種死鎖，為了保護(hù)臨界數(shù)據(jù)的安全和完整性，軟件中斷可以關(guān)硬件中斷，內(nèi)核進(jìn)程可以關(guān)閉硬件中斷和軟件中斷。

在執(zhí)行cat/proc/slabinfo時(shí)，首先程序運(yùn)行在用戶進(jìn)程上下文，然后執(zhí)行系統(tǒng)調(diào)用read被切換到內(nèi)核進(jìn)程上下文，由于slabinfo中存儲(chǔ)的是內(nèi)核的內(nèi)存分配信息，在讀取內(nèi)存分配信息時(shí)為了保證數(shù)據(jù)的一致性，在內(nèi)核進(jìn)程上下文中關(guān)閉了硬件中斷和軟件中斷。由于進(jìn)程調(diào)度也是通過硬件中斷中的時(shí)鐘中斷觸發(fā)的，所以如果長(zhǎng)時(shí)間的關(guān)閉硬件中斷、軟件中斷，進(jìn)程調(diào)度也不會(huì)被執(zhí)行。如果read執(zhí)行時(shí)間較長(zhǎng)，關(guān)閉中斷的時(shí)間就會(huì)比較長(zhǎng)，該進(jìn)程就會(huì)長(zhǎng)時(shí)間占用CPU不釋放，阻止了內(nèi)核協(xié)議棧對(duì)網(wǎng)絡(luò)收包的處理。

查看Linux內(nèi)核代碼/linux-3.0.101/mm/slab.c中的s_show函數(shù)，可看到如下關(guān)閉中斷的代碼

圖8 讀取slabinfo時(shí)關(guān)閉中斷的內(nèi)核代碼

2.第二個(gè)疑問：服務(wù)器具有40CPU，為什么一個(gè)ss命令就會(huì)阻止網(wǎng)絡(luò)包的處理呢，理論上應(yīng)還有另外39個(gè)CPU來處理?

這個(gè)涉及RPS（ReceivePacket Steering）和RFS（ReceiveFlowSteering）技術(shù)，其主要功能就將高速網(wǎng)卡產(chǎn)生的大量網(wǎng)絡(luò)包分配到多核CPU分別進(jìn)行處理，但是這個(gè)分配是預(yù)分配，根據(jù)socket四元組（源IP、源端口、目的IP、目的端口）分配到不同的CPU進(jìn)行處理。ss命令在哪個(gè)CPU上執(zhí)行，那么分配到這個(gè)CPU上的網(wǎng)絡(luò)包處理就會(huì)出現(xiàn)卡頓。因此在生產(chǎn)環(huán)境的表現(xiàn)上也是只有部分網(wǎng)絡(luò)包出現(xiàn)了卡頓，而不是所有的網(wǎng)絡(luò)包都會(huì)產(chǎn)生卡頓。

3.第三個(gè)疑問：讀取/proc/slabinfo為什么會(huì)慢？

Slab算法是以字節(jié)為單位管理內(nèi)存，是內(nèi)核的小內(nèi)存管理算法。特點(diǎn)是基于對(duì)象進(jìn)行管理。slab分配算法采用cache存儲(chǔ)內(nèi)核對(duì)象，把相同類型的對(duì)象歸為一類，每當(dāng)要申請(qǐng)這樣一個(gè)對(duì)象，slab分配器就從一個(gè)slab列表中分配一個(gè)這樣大小的單元出去，而當(dāng)要釋放時(shí)，將其重新保存在該列表中，而不是直接返回給伙伴系統(tǒng)，從而避免這些內(nèi)碎片。slab分配器并不丟棄已分配的對(duì)象，而是釋放并把它們保存在內(nèi)存中。當(dāng)以后又要請(qǐng)求新的對(duì)象時(shí)，就可以從內(nèi)存直接獲取而不用重復(fù)初始化。

通過cat /proc/slabinfo可以查看slab分配的內(nèi)存情況，其中包含的信息主要為統(tǒng)計(jì)信息，包括每種對(duì)象內(nèi)存的總個(gè)數(shù)、已分配的個(gè)數(shù)、每頁(yè)內(nèi)存的對(duì)象個(gè)數(shù)、占用的內(nèi)存頁(yè)數(shù)等等。這些統(tǒng)計(jì)信息是怎么來的呢？是內(nèi)核中現(xiàn)成的統(tǒng)計(jì)數(shù)據(jù)嗎？通過查看代碼可以發(fā)現(xiàn)，是一個(gè)個(gè)累加匯總來的，如果內(nèi)存對(duì)象的個(gè)數(shù)較多，那將是一個(gè)非常耗時(shí)的大循環(huán)。其內(nèi)核代碼如下：

通過cat /proc/slabinfo | sort -n-k3的輸出，查看一下哪些內(nèi)存對(duì)象的個(gè)數(shù)較多。

圖9 slab內(nèi)存對(duì)象數(shù)量

如圖9所示占用比較高的幾項(xiàng)是dentry、buffer_head、proc_inode_cache。dentry 是文件目錄對(duì)inode映射的緩存；Buffer_head 是硬盤的塊緩存；proc_inode_cache 是/proc目錄下inode節(jié)點(diǎn)信息的緩存。dentry、proc_inode_cache分別達(dá)到了797萬(wàn)和388萬(wàn)，這個(gè)數(shù)據(jù)量非常大，導(dǎo)致在輸出/proc/slabinfo時(shí)耗時(shí)較長(zhǎng)。

4.第四個(gè)疑問：為什么重啟服務(wù)器后網(wǎng)絡(luò)包卡頓現(xiàn)象就消失，其后為什么會(huì)變慢呢？

重啟后卡頓現(xiàn)象消失這個(gè)問題現(xiàn)在很容易回答，那就是由于重啟后slab中的緩存信息全部釋放了，對(duì)象個(gè)數(shù)較少，再統(tǒng)計(jì)slabinfo時(shí)處理較快，不會(huì)影響網(wǎng)絡(luò)包的接收了。重啟運(yùn)行一段時(shí)間后會(huì)再出現(xiàn)卡頓現(xiàn)象，是由于slab中緩存的信息又變多了，那是誰(shuí)導(dǎo)致slab緩存了大量信息呢？

slab中個(gè)數(shù)較多的內(nèi)存對(duì)象是dentry和proc_inode_cache，在查看/proc目錄下的文件時(shí)，操作系統(tǒng)會(huì)自動(dòng)將目錄信息和inode信息緩存到這兩個(gè)對(duì)象。因此是有程序周期性的讀取/proc目錄下的文件導(dǎo)致這兩個(gè)內(nèi)存對(duì)象緩存?zhèn)€數(shù)增多的。再次跟蹤一下ss命令可以發(fā)現(xiàn)ss命會(huì)掃描/proc下所有進(jìn)程打開的文件句柄，包括socket鏈接。我們這臺(tái)服務(wù)器經(jīng)常保持?jǐn)?shù)萬(wàn)的鏈接數(shù)，這些鏈接的存活時(shí)間最短只有幾秒鐘，最長(zhǎng)也就幾個(gè)小時(shí)。因此執(zhí)行一次ss-lntp命令會(huì)緩存數(shù)萬(wàn)的proc_inode_cache和dentry，如果周期性的執(zhí)行這個(gè)命令，打開的socket句柄又不停的發(fā)生變化，就會(huì)導(dǎo)致slab緩存的數(shù)量不斷增長(zhǎng)。

四、問題解決

通過上面的分析可以確認(rèn)導(dǎo)致網(wǎng)絡(luò)包卡頓的原因是：周期性的調(diào)用ss-lntp命令，同時(shí)這臺(tái)服務(wù)器上的網(wǎng)絡(luò)鏈接不斷發(fā)生變化，使得slab中緩存了大量的內(nèi)存對(duì)象，并且ss會(huì)讀取/proc/slabinfo中的匯總信息，而slabinfo中的匯總信息是每次通過效率不高的一個(gè)個(gè)累加的方式獲得，且累加時(shí)關(guān)閉了操作系統(tǒng)的中斷處理，導(dǎo)致接收到的網(wǎng)絡(luò)包無(wú)法及時(shí)處理。

因此可采取的解決方案：

（1）執(zhí)行echo "2" > /proc/sys/vm/drop_caches ，強(qiáng)制操作系統(tǒng)回收inode和dentry中的緩存信息。這個(gè)命令執(zhí)行期間會(huì)造成系統(tǒng)卡頓，卡頓時(shí)間為幾秒到幾分鐘，關(guān)鍵業(yè)務(wù)運(yùn)行期間需慎用；

（2）周期性重啟服務(wù)器，釋放slab中的緩存信息；

（3）停止周期性調(diào)用ss -lntp；

（4）對(duì)于ss命令，可以去掉 -p 參數(shù)，去掉這個(gè)參數(shù)后，ss將不再掃描/proc目錄下的進(jìn)程信息，不會(huì)導(dǎo)致slab中內(nèi)存對(duì)象個(gè)數(shù)的增長(zhǎng)。另外也可以升級(jí)到高版本的ss命令，在高版本的ss命令中已不再讀取 /proc/slabinfo,因?yàn)檫@里面已沒有可以獲取的有效信息。下面是github中的commit信息。

圖10 GitHub中commit信息

總結(jié)

針對(duì)這個(gè)問題的分析持續(xù)了大約一、兩個(gè)月的時(shí)間，期間也曾一度陷入迷惑而毫無(wú)進(jìn)展，有初步分析思路后補(bǔ)充了操作系統(tǒng)內(nèi)核的各種知識(shí)，主要包括進(jìn)程調(diào)度、調(diào)度優(yōu)先級(jí)、中斷處理、網(wǎng)絡(luò)協(xié)議棧處理、虛擬文件系統(tǒng)等等，最終可以將整個(gè)問題的來龍去脈解釋清楚。

參考資料：

《如何調(diào)試Kubernetes集群中的網(wǎng)絡(luò)延遲問題？》Theo Julienne 分布式實(shí)驗(yàn)室

《網(wǎng)卡多隊(duì)列：RPS、RFS、RSS、FlowDirector（DPDK支持）》rtoax CSDN

https://rtoax.blog.csdn.net/article/details/108987658

https://github.com/shemminger/iproute2/commit/10f687736b8dd538fb5e2bdacf6bef2c690ee99d