Categories
程式開發

驚魂48小時,阿里工程師如何緊急定位線上內存洩露?


1、問題初現

該風險隱患在2019年10月下旬某天開始浮現,不到24小時的時間裡,值班同學陸續收到多個線上電話報警,顯示某業務集群中分佈式協調服務進程異常:

  • 14:04:28,報警顯示一台Follower意外退出當前Quorum,通過選舉重新加入Quorum;
  • 16:06:35,報警顯示一台Follower發生意外重啟,守護進程拉起後,重新加入Quorum;
  • 02:56:42,報警顯示一台Follower發生意外重啟,守護進程拉起後,重新加入Quorum;
  • 12:21:04,報警顯示一台Follower意外退出當前Quorum,通過選舉重新加入Quorum;
  • ……

下圖展示了該分佈式協調服務的系統架構,後端是基於Paxos實現的一致性維護功能模塊,前端代理客戶端與一致性服務單元的通信,支持服務能力水平擴展性。由於後端分佈式一致性服務單元由5台Master機器組成,可以容忍同時2台機器掛掉,因此上述報警均沒有發現對服務可用性產生影響。但是,在短時間之內頻繁發生單個Master服務進程異常,這個對於服務穩定性是個極大隱患,特別是對於作業調度強依賴分佈式協調服務的某業務。由此,我們開始集中人力重點調查這個問題。

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 1

我們首先排除了網絡問題,通過tsar命令查看機器上網絡各項指標正常,通過內部的網絡平台查看機器上聯網絡設備以及網絡鏈路也均是健康狀態。回到日誌來分析,我們從Leader日誌中找到了線索,上述報警時間點,均有“Leader主動關閉了與Follower的通信通道”這麼一個事件。

很自然地,我們想知道為什麼會頻繁發生Leader關閉與Follower通信通道的事件,答案同樣在日誌中:Follower長時間沒有發送請求給Leader,包括Leader發給過來的心跳包的回复,因此被Leader認定為異常Follower,進而關閉與之通信通道,將其踢出當前Quorum。

好了,現在可以直觀地解釋觸發報警原因了:Follower長時間與Leader失聯,觸發了退出Quorum邏輯(如果退出Quorum過程比較慢的話,進一步會觸發直接退出進程邏輯,快速恢復)。

那麼新的問題來了,這些Followers為什麼不回复輕量的心跳請求呢?這次沒有直接的日誌來解答我們的疑惑,還好,有間接信息:出問題前Follower的日誌輸出發生了長時間的中斷(超過了觸發退出Quorum的閾值),這個在對分佈式協調服務有著頻繁請求訪問的某業務集群中幾乎是不可想像的!我們更願意相信後端進程hang住了,而不是壓根沒有用戶請求打過來。

在沒有其它更多調查思路的情況下,基於後端分佈式一致性服務單元是基於java實現的事實,我們查看了Follower發生問題時間段的gc日誌,結果找到了原因:java gc相關的ParNew耗時太久(當天日誌已經被清理,下圖是該機器上的類似日誌),我們知道java gc過程是有個STW(Stop-The-World)機制的,除了垃圾收集器,其餘線程全部掛起,這個就能夠解釋為什麼後端Follower線程會短時hang住。

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 2

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

按照這個思路,我們進一步在Follower機器上使用top命令查看進程內存佔用情況,結果發現機器上混合部署的前端Proxy進程使用的內存已經達到整機66%+(此時後端一致性進程實際佔用的物理內存也已經達到30%左右)。

進一步查看系統日誌,發現部分機器上前端Proxy進程已經發生過因為內存不足的OOM錯誤而被系統KILL的事件,至此問題初步定位,我們開始轉向調查前端Proxy內存洩露的問題。

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 3

2、業務風險

該業務對分佈式協調服務的服務發現功能是重度依賴的。以本次調查的業務集群為例,單集群註冊的服務地址數達到240K,解析地址的活躍會話數總量達到450W,因此,分佈式協調服務的穩定性直接影響著集群內業務作業的健康運行。

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 4

在明確了分佈式協調服務Proxy進程存在內存洩露風險之後,我們緊急巡檢了線上其它集群,發現該問題並非個例。大促在即,這個風險隱患不能夠留到雙十一的時間點,在gcore了前端Proxy現場之後,我們做了緊急變更,逐台重啟了上述風險集群的前端Proxy進程,暫且先緩解了線上風險。

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 5

3、深入調查

繼續回來調查問題,我們在重啟Proxy進程之前,gcore保留了現場(這裡要強調一下,線上gcore一定要謹慎,特別是內存佔用如此大的進程,很容易造成請求處理hang住,我們基於的考慮是該分佈式協調服務的客戶端是有超時重試機制的,因此可以承受一定時長的gcore操作)。

因為前端Proxy最主要的內存開銷是基於訂閱實現的高效地址緩存,因此,我們首先通過gdb查看了維護了緩存的unordered_map大小,結果這個大小是符合預期的(正如監控指標顯示的,估算下來這個空間佔用不會超過1GB),遠遠達不到能夠撐起如此內存洩漏的地步。這點我們進一步通過strings core文件也得到了證實,string對象空間佔據並不多,一時間,我們的調查陷入了困境。

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 6

這時我們想到了兄弟團隊某大神的大作,介紹了在線上環境調查C/C++應用程序內存洩露問題(可能會有同學提到valgrind這個工具幹嘛不用?首先這個神器在測試環境是必備的,但是終究是可能存在一些漏掉的場景發布上線了導致線上內存洩露。另外,大型項目中會暴露valgrind運行太慢的問題,甚至導致程序不能正常工作),這裡提供了另一個角度來調查內存洩露:虛表。每個有虛函數的類都有個虛表,同一個類的所有對像都會指針指向同一個虛表(通常是每個對象的前8個字節),因此統計每個虛表指針出現的頻度就可以知道這樣的對像被分配了有多少,數量異常的話那麼就存在內存洩露的可能。

大神提供了一個內存洩露排查工具(說明一下,這個工具基於規整的tcmalloc的內存管理方式來分析的),通過符號表找到每個vtable,因此可以知道虛表地址,即每個虛函數類的對象前8字節的內容,這個工具厲害的地方在於擺脫了gdb依賴,直接根據應用程序申請的所有內存塊分析,找到所有洩露內存塊地址,進一步統計出每個虛表對應類的對像數目。具體這個工具實現細節不再贅述,最終我們統計出來的所有出現頻率超過10W的虛表信息,找到了罪魁禍首:這個common::closure的對象洩露了高達16億+。

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 7

根據closure的參數類型信息,我們很快定位到了具體的類CheckCall:

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

有關這個對象的大面積洩露,定位到最終原因其實是跟我們對Proxy日誌分析有關,我們在日誌中發現了大量非法訪問請求:客戶端嘗試解析某個角色註冊的服務地址,但是卻使用錯誤的集群名參數。在單個Proxy機器上1s時間裡最多刷出4000+這樣的錯誤日誌,那麼會不會是因為持續走到這樣錯誤路徑導致的對象內存洩露呢?

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 8

對照這塊的代碼,我們仔細研究了一下,果然,CheckCall對象正常是會走到執行邏輯的(common::closure在執行之後自動會析構掉,釋放內存),但是在異常路徑下,譬如上面的非法集群名,那麼這個函數會直接return掉,相應的CheckCall對像不會被析構,隨著業務持續訪問,也就持續產生內存洩露。

4、風險修復

這個問題的rootcause定位之後,擺在我們面前的修復方法有兩個:

1)業務方停止錯誤訪問行為,避免分佈式協調服務前端Proxy持續走到錯誤路徑,觸發內存洩露;

2)從前端Proxy代碼層面徹底修復掉這個bug,然後對線上分佈式協調服務Proxy做一輪升級;

方案二的動靜比較大,大促之前已經沒有足夠的升級、灰度窗口,最終我們選擇了方案一,根據日誌中持續出現的這個非法訪問路徑,我們聯繫了業務方,協助調查確認業務哪些客戶端進程在使用錯誤集群名訪問分佈式協調服務,進一步找到了原因。最終業務方通過緊急上線hotfix,消除了錯誤集群名的訪問行為,該業務線分佈式協調服務前端Proxy進程內存洩露趨勢因此得以控制,風險解除。

驚魂48小時,阿里工程師如何緊急定位線上內存洩露? 9

當然,根本的修復方式還是要從前端Proxy針對CheckCall的異常路徑下的處理,我們的修復方式是遵循函數實現單一出口原則,在異常路徑下也同樣執行該closure,在執行邏輯裡面判斷錯誤碼直接return,即不執行實際的CheckCall邏輯,只觸發自我析構的行為。該修復在雙十一之後將發布上線。

5、問題小結

穩定性工作需要從細節處入手,需要我們針對線上服務的每一條報警或者是服務指標的一絲異常,能夠追根溯源,找到root cause,並持續跟進風險修復,這樣一定可以錘煉出更加穩定的分佈式系統。 “路漫漫其修遠兮,吾將上下而求索”,與諸君共勉。

本文轉載自公眾號阿里技術(ID:ali_tech)。

原文鏈接

https://mp.weixin.qq.com/s/FMYimnxcAya6bhvdGD5LUw