
阿裡妹導讀:雲計算場景下的大規模分布式系統中,網絡異常、磁盤IO異常、時鐘跳變、作業系統異常乃至軟體本身可能存在bugs等,均給分布式系統正确運作帶來了挑戰。持續的監控報警完善是打造穩定高可用分布式系統過程中非常重要的工作,這個也就要求我們研發同學從細節處入手,本文将介紹的場景是針對線上報警的一絲異常,抽絲剝繭找到記憶體洩露的root cause,全程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服務程序異常,這個對于服務穩定性是個極大隐患,特别是對于作業排程強依賴分布式協調服務的某業務。由此,我們開始集中人力重點調查這個問題。
我們首先排除了網絡問題,通過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住。
雖然我們的java程式申請的初始記憶體較大,但是實際配置設定的是虛拟記憶體,ParNew耗時太久一個很大可能性是機器上實際實體記憶體不足了。
按照這個思路,我們進一步在Follower機器上使用top指令檢視程序記憶體占用情況,結果發現機器上混合部署的前端Proxy程序使用的記憶體已經達到整機66%+(此時後端一緻性程序實際占用的實體記憶體也已經達到30%左右)。
進一步檢視系統日志,發現部分機器上前端Proxy程序已經發生過因為記憶體不足的OOM錯誤而被系統KILL的事件,至此問題初步定位,我們開始轉向調查前端Proxy記憶體洩露的問題。
2、業務風險
該業務對分布式協調服務的服務發現功能是重度依賴的。以本次調查的業務叢集為例,單叢集注冊的服務位址數達到240K,解析位址的活躍會話數總量達到450W,是以,分布式協調服務的穩定性直接影響着叢集内業務作業的健康運作。
在明确了分布式協調服務Proxy程序存在記憶體洩露風險之後,我們緊急巡檢了線上其它叢集,發現該問題并非個例。大促在即,這個風險隐患不能夠留到雙十一的時間點,在gcore了前端Proxy現場之後,我們做了緊急變更,逐台重新開機了上述風險叢集的前端Proxy程序,暫且先緩解了線上風險。
3、深入調查
繼續回來調查問題,我們在重新開機Proxy程序之前,gcore保留了現場(這裡要強調一下,線上gcore一定要謹慎,特别是記憶體占用如此大的程序,很容易造成請求處理hang住,我們基于的考慮是該分布式協調服務的用戶端是有逾時重試機制的,是以可以承受一定時長的gcore操作)。
因為前端Proxy最主要的記憶體開銷是基于訂閱實作的高效位址緩存,是以,我們首先通過gdb檢視了維護了緩存的unordered_map大小,結果這個大小是符合預期的(正如監控名額顯示的,估算下來這個空間占用不會超過1GB),遠遠達不到能夠撐起如此記憶體洩漏的地步。這點我們進一步通過strings core檔案也得到了證明,string對象空間占據并不多,一時間,我們的調查陷入了困境。
這時我們想到了兄弟團隊某大神的大作,介紹了線上上環境調查C/C++應用程式記憶體洩露問題(可能會有同學提到valgrind這個工具幹嘛不用?首先這個神器在測試環境是必備的,但是終究是可能存在一些漏掉的場景釋出上線了導緻線上記憶體洩露。另外,大型項目中會暴露valgrind運作太慢的問題,甚至導緻程式不能正常工作),這裡提供了另一個角度來調查記憶體洩露:虛表。每個有虛函數的類都有個虛表,同一個類的所有對象都會指針指向同一個虛表(通常是每個對象的前8個位元組),是以統計每個虛表指針出現的頻度就可以知道這樣的對象被配置設定了有多少,數量異常的話那麼就存在記憶體洩露的可能。
大神提供了一個記憶體洩露排查工具(說明一下,這個工具基于規整的tcmalloc的記憶體管理方式來分析的),通過符号表找到每個vtable,是以可以知道虛表位址,即每個虛函數類的對象前8位元組的内容,這個工具厲害的地方在于擺脫了gdb依賴,直接根據應用程式申請的所有記憶體塊分析,找到所有洩露記憶體塊位址,進一步統計出每個虛表對應類的對象數目。具體這個工具實作細節不再贅述,最終我們統計出來的所有出現頻率超過10W的虛表資訊,找到了罪魁禍首:這個common::closure的對象洩露了高達16億+。
根據closure的參數類型資訊,我們很快定位到了具體的類CheckCall:
$grep Closure -r proxy | grep Env
proxy/io_handler.h: typedef common::Closure<void, Env*> CheckCall;
有關這個對象的大面積洩露,定位到最終原因其實是跟我們對Proxy日志分析有關,我們在日志中發現了大量非法通路請求:用戶端嘗試解析某個角色注冊的服務位址,但是卻使用錯誤的叢集名參數。在單個Proxy機器上1s時間裡最多刷出4000+這樣的錯誤日志,那麼會不會是因為持續走到這樣錯誤路徑導緻的對象記憶體洩露呢?
對照這塊的代碼,我們仔細研究了一下,果然,CheckCall對象正常是會走到執行邏輯的(common::closure在執行之後自動會析構掉,釋放記憶體),但是在異常路徑下,譬如上面的非法叢集名,那麼這個函數會直接return掉,相應的CheckCall對象不會被析構,随着業務持續通路,也就持續産生記憶體洩露。
4、風險修複
這個問題的rootcause定位之後,擺在我們面前的修複方法有兩個:
1)業務方停止錯誤通路行為,避免分布式協調服務前端Proxy持續走到錯誤路徑,觸發記憶體洩露;
2)從前端Proxy代碼層面徹底修複掉這個bug,然後對線上分布式協調服務Proxy做一輪更新;
方案二的動靜比較大,大促之前已經沒有足夠的更新、灰階視窗,最終我們選擇了方案一,根據日志中持續出現的這個非法通路路徑,我們聯系了業務方,協助調查确認業務哪些用戶端程序在使用錯誤叢集名通路分布式協調服務,進一步找到了原因。最終業務方通過緊急上線hotfix,消除了錯誤叢集名的通路行為,該業務線分布式協調服務前端Proxy程序記憶體洩露趨勢是以得以控制,風險解除。
當然,根本的修複方式還是要從前端Proxy針對CheckCall的異常路徑下的處理,我們的修複方式是遵循函數實作單一出口原則,在異常路徑下也同樣執行該closure,在執行邏輯裡面判斷錯誤碼直接return,即不執行實際的CheckCall邏輯,隻觸發自我析構的行為。該修複在雙十一之後将釋出上線。
5、問題小結
穩定性工作需要從細節處入手,需要我們針對線上服務的每一條報警或者是服務名額的一絲異常,能夠追根溯源,找到root cause,并持續跟進風險修複,這樣一定可以錘煉出更加穩定的分布式系統。“路漫漫其修遠兮,吾将上下而求索”,與諸君共勉。
原文釋出時間:2019-12-20
作者:朱雲鋒
本文來自阿裡雲合作夥伴“
阿裡技術”,了解相關資訊可以關注“
”。