[[286173]]

云計算場景下的大規(guī)模分布式系統(tǒng)中，網(wǎng)絡(luò)異常、磁盤IO異常、時鐘跳變、操作系統(tǒng)異常乃至軟件本身可能存在bugs等，均給分布式系統(tǒng)正確運(yùn)行帶來了挑戰(zhàn)。持續(xù)的監(jiān)控報警完善是打造穩(wěn)定高可用分布式系統(tǒng)過程中非常重要的工作，這個也就要求我們研發(fā)同學(xué)從細(xì)節(jié)處入手，本文將介紹的場景是針對線上報警的一絲異常，抽絲剝繭找到內(nèi)存泄露的root cause，全程48小時，跟進(jìn)修復(fù)了潛在風(fēng)險隱患，并進(jìn)一步豐富完善監(jiān)控報警體系的過程。

1、問題初現(xiàn)

該風(fēng)險隱患在2019年10月下旬某天開始浮現(xiàn)，不到24小時的時間里，值班同學(xué)陸續(xù)收到多個線上電話報警，顯示某業(yè)務(wù)集群中分布式協(xié)調(diào)服務(wù)進(jìn)程異常：

• 14:04:28，報警顯示一臺Follower意外退出當(dāng)前Quorum，通過選舉重新加入Quorum;
• 16:06:35，報警顯示一臺Follower發(fā)生意外重啟，守護(hù)進(jìn)程拉起后，重新加入Quorum;
• 02:56:42，報警顯示一臺Follower發(fā)生意外重啟，守護(hù)進(jìn)程拉起后，重新加入Quorum;
• 12:21:04，報警顯示一臺Follower意外退出當(dāng)前Quorum，通過選舉重新加入Quorum;
• ……

下圖展示了該分布式協(xié)調(diào)服務(wù)的系統(tǒng)架構(gòu)，后端是基于Paxos實(shí)現(xiàn)的一致性維護(hù)功能模塊，前端代理客戶端與一致性服務(wù)單元的通信，支持服務(wù)能力水平擴(kuò)展性。由于后端分布式一致性服務(wù)單元由5臺Master機(jī)器組成，可以容忍同時2臺機(jī)器掛掉，因此上述報警均沒有發(fā)現(xiàn)對服務(wù)可用性產(chǎn)生影響。但是，在短時間之內(nèi)頻繁發(fā)生單個Master服務(wù)進(jìn)程異常，這個對于服務(wù)穩(wěn)定性是個極大隱患，特別是對于作業(yè)調(diào)度強(qiáng)依賴分布式協(xié)調(diào)服務(wù)的某業(yè)務(wù)。由此，我們開始集中人力重點(diǎn)調(diào)查這個問題。

我們首先排除了網(wǎng)絡(luò)問題，通過tsar命令查看機(jī)器上網(wǎng)絡(luò)各項指標(biāo)正常，通過內(nèi)部的網(wǎng)絡(luò)平臺查看機(jī)器上聯(lián)網(wǎng)絡(luò)設(shè)備以及網(wǎng)絡(luò)鏈路也均是健康狀態(tài)?；氐饺罩緛矸治觯覀儚腖eader日志中找到了線索，上述報警時間點(diǎn)，均有“Leader主動關(guān)閉了與Follower的通信通道”這么一個事件。

很自然地，我們想知道為什么會頻繁發(fā)生Leader關(guān)閉與Follower通信通道的事件，答案同樣在日志中：Follower長時間沒有發(fā)送請求給Leader，包括Leader發(fā)給過來的心跳包的回復(fù)，因此被Leader認(rèn)定為異常Follower，進(jìn)而關(guān)閉與之通信通道，將其踢出當(dāng)前Quorum。

好了，現(xiàn)在可以直觀地解釋觸發(fā)報警原因了：Follower長時間與Leader失聯(lián)，觸發(fā)了退出Quorum邏輯(如果退出Quorum過程比較慢的話，進(jìn)一步會觸發(fā)直接退出進(jìn)程邏輯，快速恢復(fù))。

那么新的問題來了，這些Followers為什么不回復(fù)輕量的心跳請求呢?這次沒有直接的日志來解答我們的疑惑，還好，有間接信息：出問題前Follower的日志輸出發(fā)生了長時間的中斷(超過了觸發(fā)退出Quorum的閾值)，這個在對分布式協(xié)調(diào)服務(wù)有著頻繁請求訪問的某業(yè)務(wù)集群中幾乎是不可想象的!我們更愿意相信后端進(jìn)程hang住了，而不是壓根沒有用戶請求打過來。

在沒有其它更多調(diào)查思路的情況下，基于后端分布式一致性服務(wù)單元是基于java實(shí)現(xiàn)的事實(shí)，我們查看了Follower發(fā)生問題時間段的gc日志，結(jié)果找到了原因：java gc相關(guān)的ParNew耗時太久(當(dāng)天日志已經(jīng)被清理，下圖是該機(jī)器上的類似日志)，我們知道java gc過程是有個STW(Stop-The-World)機(jī)制的，除了垃圾收集器，其余線程全部掛起，這個就能夠解釋為什么后端Follower線程會短時hang住。

雖然我們的java程序申請的初始內(nèi)存較大，但是實(shí)際分配的是虛擬內(nèi)存，ParNew耗時太久一個很大可能性是機(jī)器上實(shí)際物理內(nèi)存不足了。

按照這個思路，我們進(jìn)一步在Follower機(jī)器上使用top命令查看進(jìn)程內(nèi)存占用情況，結(jié)果發(fā)現(xiàn)機(jī)器上混合部署的前端Proxy進(jìn)程使用的內(nèi)存已經(jīng)達(dá)到整機(jī)66%+(此時后端一致性進(jìn)程實(shí)際占用的物理內(nèi)存也已經(jīng)達(dá)到30%左右)。

進(jìn)一步查看系統(tǒng)日志，發(fā)現(xiàn)部分機(jī)器上前端Proxy進(jìn)程已經(jīng)發(fā)生過因?yàn)閮?nèi)存不足的OOM錯誤而被系統(tǒng)KILL的事件，至此問題初步定位，我們開始轉(zhuǎn)向調(diào)查前端Proxy內(nèi)存泄露的問題。

2、業(yè)務(wù)風(fēng)險

該業(yè)務(wù)對分布式協(xié)調(diào)服務(wù)的服務(wù)發(fā)現(xiàn)功能是重度依賴的。以本次調(diào)查的業(yè)務(wù)集群為例，單集群注冊的服務(wù)地址數(shù)達(dá)到240K，解析地址的活躍會話數(shù)總量達(dá)到450W，因此，分布式協(xié)調(diào)服務(wù)的穩(wěn)定性直接影響著集群內(nèi)業(yè)務(wù)作業(yè)的健康運(yùn)行。

在明確了分布式協(xié)調(diào)服務(wù)Proxy進(jìn)程存在內(nèi)存泄露風(fēng)險之后，我們緊急巡檢了線上其它集群，發(fā)現(xiàn)該問題并非個例。大促在即，這個風(fēng)險隱患不能夠留到雙十一的時間點(diǎn)，在gcore了前端Proxy現(xiàn)場之后，我們做了緊急變更，逐臺重啟了上述風(fēng)險集群的前端Proxy進(jìn)程，暫且先緩解了線上風(fēng)險。

3、深入調(diào)查

繼續(xù)回來調(diào)查問題，我們在重啟Proxy進(jìn)程之前，gcore保留了現(xiàn)場(這里要強(qiáng)調(diào)一下，線上gcore一定要謹(jǐn)慎，特別是內(nèi)存占用如此大的進(jìn)程，很容易造成請求處理hang住，我們基于的考慮是該分布式協(xié)調(diào)服務(wù)的客戶端是有超時重試機(jī)制的，因此可以承受一定時長的gcore操作)。

因?yàn)榍岸薖roxy最主要的內(nèi)存開銷是基于訂閱實(shí)現(xiàn)的高效地址緩存，因此，我們首先通過gdb查看了維護(hù)了緩存的unordered_map大小，結(jié)果這個大小是符合預(yù)期的(正如監(jiān)控指標(biāo)顯示的，估算下來這個空間占用不會超過1GB)，遠(yuǎn)遠(yuǎn)達(dá)不到能夠撐起如此內(nèi)存泄漏的地步。這點(diǎn)我們進(jìn)一步通過strings core文件也得到了證實(shí)，string對象空間占據(jù)并不多，一時間，我們的調(diào)查陷入了困境。 

這時我們想到了兄弟團(tuán)隊某大神的大作，介紹了在線上環(huán)境調(diào)查C/C++應(yīng)用程序內(nèi)存泄露問題(可能會有同學(xué)提到valgrind這個工具干嘛不用?首先這個神器在測試環(huán)境是必備的，但是終究是可能存在一些漏掉的場景發(fā)布上線了導(dǎo)致線上內(nèi)存泄露。另外，大型項目中會暴露valgrind運(yùn)行太慢的問題，甚至導(dǎo)致程序不能正常工作)，這里提供了另一個角度來調(diào)查內(nèi)存泄露：虛表。每個有虛函數(shù)的類都有個虛表，同一個類的所有對象都會指針指向同一個虛表(通常是每個對象的前8個字節(jié))，因此統(tǒng)計每個虛表指針出現(xiàn)的頻度就可以知道這樣的對象被分配了有多少，數(shù)量異常的話那么就存在內(nèi)存泄露的可能。

大神提供了一個內(nèi)存泄露排查工具(說明一下，這個工具基于規(guī)整的tcmalloc的內(nèi)存管理方式來分析的)，通過符號表找到每個vtable，因此可以知道虛表地址，即每個虛函數(shù)類的對象前8字節(jié)的內(nèi)容，這個工具厲害的地方在于擺脫了gdb依賴，直接根據(jù)應(yīng)用程序申請的所有內(nèi)存塊分析，找到所有泄露內(nèi)存塊地址，進(jìn)一步統(tǒng)計出每個虛表對應(yīng)類的對象數(shù)目。具體這個工具實(shí)現(xiàn)細(xì)節(jié)不再贅述，最終我們統(tǒng)計出來的所有出現(xiàn)頻率超過10W的虛表信息，找到了罪魁禍?zhǔn)祝哼@個common::closure的對象泄露了高達(dá)16億+。

根據(jù)closure的參數(shù)類型信息，我們很快定位到了具體的類CheckCall：

$grep Closure -r proxy | grep Env  
proxy/io_handler.h: typedef common::Closure CheckCall; 

有關(guān)這個對象的大面積泄露，定位到最終原因其實(shí)是跟我們對Proxy日志分析有關(guān)，我們在日志中發(fā)現(xiàn)了大量非法訪問請求：客戶端嘗試解析某個角色注冊的服務(wù)地址，但是卻使用錯誤的集群名參數(shù)。在單個Proxy機(jī)器上1s時間里最多刷出4000+這樣的錯誤日志，那么會不會是因?yàn)槌掷m(xù)走到這樣錯誤路徑導(dǎo)致的對象內(nèi)存泄露呢?

對照這塊的代碼，我們仔細(xì)研究了一下，果然，CheckCall對象正常是會走到執(zhí)行邏輯的(common::closure在執(zhí)行之后自動會析構(gòu)掉，釋放內(nèi)存)，但是在異常路徑下，譬如上面的非法集群名，那么這個函數(shù)會直接return掉，相應(yīng)的CheckCall對象不會被析構(gòu)，隨著業(yè)務(wù)持續(xù)訪問，也就持續(xù)產(chǎn)生內(nèi)存泄露。

4、風(fēng)險修復(fù)

這個問題的rootcause定位之后，擺在我們面前的修復(fù)方法有兩個：

1)業(yè)務(wù)方停止錯誤訪問行為，避免分布式協(xié)調(diào)服務(wù)前端Proxy持續(xù)走到錯誤路徑，觸發(fā)內(nèi)存泄露;

2)從前端Proxy代碼層面徹底修復(fù)掉這個bug，然后對線上分布式協(xié)調(diào)服務(wù)Proxy做一輪升級;

方案二的動靜比較大，大促之前已經(jīng)沒有足夠的升級、灰度窗口，最終我們選擇了方案一，根據(jù)日志中持續(xù)出現(xiàn)的這個非法訪問路徑，我們聯(lián)系了業(yè)務(wù)方，協(xié)助調(diào)查確認(rèn)業(yè)務(wù)哪些客戶端進(jìn)程在使用錯誤集群名訪問分布式協(xié)調(diào)服務(wù)，進(jìn)一步找到了原因。最終業(yè)務(wù)方通過緊急上線hotfix，消除了錯誤集群名的訪問行為，該業(yè)務(wù)線分布式協(xié)調(diào)服務(wù)前端Proxy進(jìn)程內(nèi)存泄露趨勢因此得以控制，風(fēng)險解除。

當(dāng)然，根本的修復(fù)方式還是要從前端Proxy針對CheckCall的異常路徑下的處理，我們的修復(fù)方式是遵循函數(shù)實(shí)現(xiàn)單一出口原則，在異常路徑下也同樣執(zhí)行該closure，在執(zhí)行邏輯里面判斷錯誤碼直接return，即不執(zhí)行實(shí)際的CheckCall邏輯，只觸發(fā)自我析構(gòu)的行為。該修復(fù)在雙十一之后將發(fā)布上線。

5、問題小結(jié)

穩(wěn)定性工作需要從細(xì)節(jié)處入手，需要我們針對線上服務(wù)的每一條報警或者是服務(wù)指標(biāo)的一絲異常，能夠追根溯源，找到root cause，并持續(xù)跟進(jìn)風(fēng)險修復(fù)，這樣一定可以錘煉出更加穩(wěn)定的分布式系統(tǒng)。“路漫漫其修遠(yuǎn)兮，吾將上下而求索”，與諸君共勉。

【本文為51CTO專欄作者“阿里巴巴官方技術(shù)”原創(chuàng)稿件，轉(zhuǎn)載請聯(lián)系原作者】 

戳這里，看該作者更多好文