Java 內(nèi)存泄漏調試錯誤怎么辦?Adventory,我們的 PPC
(以點擊次數(shù)收費)廣告系統(tǒng)中一個負責索引廣告的應用,很明顯連續(xù)重啟了好幾次。在云端的環(huán)境里,實例的重啟是很正常的,也不會觸發(fā)報警,但這次實例重啟的次數(shù)在短時間內(nèi)超過了閾值。我打開了筆記本電腦,一頭扎進項目的日志里。
Java 內(nèi)存泄漏調試錯誤怎么辦?一定是網(wǎng)絡的問題
我看到服務在連接 ZooKeeper 時發(fā)生了數(shù)次超時。我們使用 ZooKeeper(ZK)協(xié)調多個實例間的索引操作,并依賴它實現(xiàn)魯棒性。很顯然,一次
Zookeeper 失敗會阻止索引操作的繼續(xù)運行,不過它應該不會導致整個系統(tǒng)掛掉。而且,這種情況非常罕見(這是我第一次遇到 ZK
在生產(chǎn)環(huán)境掛掉),我覺得這個問題可能不太容易搞定。于是我把 ZooKeeper 的值班人員喊醒了,讓他們看看發(fā)生了什么。
同時,我檢查了我們的配置,發(fā)現(xiàn) ZooKeeper 連接的超時時間是秒級的。很明顯,ZooKeeper
全掛了,由于其他服務也在使用它,這意味著問題非常嚴重。我給其他幾個團隊發(fā)了消息,他們顯然還不知道這事兒。
ZooKeeper 團隊的同事回復我了,在他看來,系統(tǒng)運行一切正常。由于其他用戶看起來沒有受到影響,我慢慢意識到不是 ZooKeeper
的問題。日志里明顯是網(wǎng)絡超時,于是我把負責網(wǎng)絡的同事叫醒了。
負責網(wǎng)絡的團隊檢查了他們的監(jiān)控,沒有發(fā)現(xiàn)任何異常。由于單個網(wǎng)段,甚至單個節(jié)點,都有可能和剩余的其他節(jié)點斷開連接,他們檢查了我們系統(tǒng)實例所在的幾臺機器,沒有發(fā)現(xiàn)異常。其間,我嘗試了其他幾種思路,不過都行不通,我也到了自己智力的極限。
時間已經(jīng)很晚了(或者說很早了),同時,跟我的嘗試沒有任何關系,重啟變得不那么頻繁了。由于這個服務僅僅負責數(shù)據(jù)的刷新,并不會影響到數(shù)據(jù)的可用性,我們決定把問題放到上午再說。
Java 內(nèi)存泄漏調試錯誤怎么辦?一定是 GC 的問題
有時候把難題放一放,睡一覺,等腦子清醒了再去解決是一個好主意。沒人知道當時發(fā)生了什么,服務表現(xiàn)的非常怪異。突然間,我想到了什么。Java
服務表現(xiàn)怪異的主要根源是什么?當然是垃圾回收。
為了應對目前這種情況的發(fā)生,我們一直打印著 GC 的日志。我馬上把 GC 日志下載了下來,然后打開
Censum開始分析日志。我還沒仔細看,就發(fā)現(xiàn)了一個恐怖的情況:每15分鐘發(fā)生一次 full GC,每次 GC 引發(fā)長達 20 秒的服務停頓。怪不得連接
ZooKeeper 超時了,即使 ZooKeeper 和網(wǎng)絡都沒有問題。
這些停頓也解釋了為什么整個服務一直是死掉的,而不是超時之后只打一條錯誤日志。我們的服務運行在 Marathon
上,它定時檢查每個實例的健康狀態(tài),如果某個端點在一段時間內(nèi)沒有響應,Marathon 就重啟那個服務。
知道原因之后,問題就解決一半了,因此我相信這個問題很快就能解決。為了解釋后面的推理,我需要說明一下 Adventory
是如何工作的,它不像你們那種標準的微服務。
Adventory 是用來把我們的廣告索引到 ElasticSearch (ES)
的。這需要兩個步驟。第一步是獲取所需的數(shù)據(jù)。到目前為止,這個服務從其他幾個系統(tǒng)中接收通過 Hermes 發(fā)來的事件。數(shù)據(jù)保存到 MongoDB 集群中。
數(shù)據(jù)量最多每秒幾百個請求,每個操作都特別輕量,因此即便觸發(fā)一些內(nèi)存的回收,也耗費不了多少資源。第二步就是數(shù)據(jù)的索引。這個操作定時執(zhí)行(大概兩分鐘執(zhí)行一次),把所有
MongoDB 集群存儲的數(shù)據(jù)通過 RxJava 收集到一個流中,組合為非范式的記錄,發(fā)送給
ElasticSearch。這部分操作類似離線的批處理任務,而不是一個服務。
由于經(jīng)常需要對數(shù)據(jù)做大量的更新,維護索引就不太值得,所以每執(zhí)行一次定時任務,整個索引都會重建一次。這意味著一整塊數(shù)據(jù)都要經(jīng)過這個系統(tǒng),從而引發(fā)大量的內(nèi)存回收。盡管使用了流的方式,我們也被迫把堆加到了
12 GB 這么大。由于堆是如此巨大(而且目前被全力支持),我們的 GC 選擇了 G1。
我以前處理過的服務中,也會回收大量生命周期很短的對象。有了那些經(jīng)驗,我同時增加了 -XX:G1NewSizePercent 和
-XX:G1MaxNewSizePercent 的默認值,這樣新生代會變得更大,young GC 就可以處理更多的數(shù)據(jù),而不用把它們送到老年代。Censum
也顯示有很多過早提升。這和一段時間之后發(fā)生的 full GC 也是一致的。不幸的是,這些設置沒有起到任何作用。
接下來我想,或許生產(chǎn)者制造數(shù)據(jù)太快了,消費者來不及消費,導致這些記錄在它們被處理前就被回收了。我嘗試減小生產(chǎn)數(shù)據(jù)的線程數(shù)量,降低數(shù)據(jù)產(chǎn)生的速度,同時保持消費者發(fā)送給
ES 的數(shù)據(jù)池大小不變。這主要是使用背壓(backpressure)機制,不過它也沒有起到作用。
一定是內(nèi)存泄漏
這時,一個當時頭腦還保持冷靜的同事,建議我們應該做一開始就做的事情:檢查堆中的數(shù)據(jù)。我們準備了一個開發(fā)環(huán)境的實例,擁有和線上實例相同的數(shù)據(jù)量,堆的大小也大致相同。把它連接到
jnisualvm ,分析內(nèi)存的樣本,我們可以看到堆中對象的大致數(shù)量和大小。
打眼一看,可以發(fā)現(xiàn)我們域中Ad對象的數(shù)量高的不正常,并且在索引的過程中一直在增長,一直增長到我們處理的廣告的數(shù)量級別。但是……這不應該啊。畢竟,我們通過
RX 把這些數(shù)據(jù)整理成流,就是為了防止把所有的數(shù)據(jù)都加載到內(nèi)存里。
隨著懷疑越來越強,我檢查了這部分代碼。它們是兩年前寫的,之后就沒有再被仔細的檢查過。果不其然,我們實際上把所有的數(shù)據(jù)都加載到了內(nèi)存里。這當然不是故意的。由于當時對
RxJava 的理解不夠全面,我們想讓代碼以一種特殊的方式并行運行。為了從 RX 的主工作流中剝離出來一些工作,我們決定用一個單獨的 executor 跑
CompetableFuture。
但是,我們因此就需要等待所有的 CompetableFuture 都工作完……通過存儲他們的引用,然后調用 join()。這導致一直到索引完成,所有的
future 的引用,以及它們引用到的數(shù)據(jù),都保持著生存的狀態(tài)。這阻止了垃圾收集器及時的把它們清理掉。
真有這么糟糕嗎?
當然這是一個很愚蠢的錯誤,對于發(fā)現(xiàn)得這么晚,我們也很惡心。我甚至想起很久之前,關于這個應用需要 12 GB 的堆的問題,曾有個簡短的討論。12 GB
的堆,確實有點大了。
但是另一方面,這些代碼已經(jīng)運行了將近兩年了,沒有發(fā)生過任何問題。我們可以在當時相對容易的修復它,然而如果是兩年前,這可能需要我們花費更多的時間,而且相對于節(jié)省幾個
G 的內(nèi)存,當時我們有很多更重要的工作。
因此,雖然從純技術的角度來說,這個問題如此長時間沒解決確實很丟人,然而從戰(zhàn)略性的角度來看,或許留著這個浪費內(nèi)存的問題不管,是更務實的選擇。當然,另一個考慮就是這個問題一旦發(fā)生,會造成什么影響。我們幾乎沒有對用戶造成任何影響,不過結果有可能更糟糕。軟件工程就是權衡利弊,決定不同任務的優(yōu)先級也不例外。
還是不行
有了更多使用 RX 的經(jīng)驗之后,我們可以很簡單的解決 ComplerableFurue 的問題。重寫代碼,只使用 RX;在重寫的過程中,升級到
RX2;真正的流式處理數(shù)據(jù),而不是在內(nèi)存里收集它們。這些改動通過 code review
之后,部署到開發(fā)環(huán)境進行測試。讓我們吃驚的是,應用所需的內(nèi)存絲毫沒有減少。
內(nèi)存抽樣顯示,相較之前,內(nèi)存中廣告對象的數(shù)量有所減少。而且對象的數(shù)量現(xiàn)在不會一直增長,有時也會下降,因此他們不是全部在內(nèi)存里收集的。還是老問題,看起來這些數(shù)據(jù)仍然沒有真正的被歸集成流。
那現(xiàn)在是怎么回事?
相關的關鍵詞剛才已經(jīng)提到了:背壓。當數(shù)據(jù)被流式處理,生產(chǎn)者和消費者的速度不同是很正常的。如果生產(chǎn)者比消費者快,并且不能把速度降下來,它就會一直生產(chǎn)越來越多的數(shù)據(jù),消費者無法以同樣的速度處理掉他們?,F(xiàn)象就是未處理數(shù)據(jù)的緩存不斷增長,而這就是我們應用中真正發(fā)生的。背壓就是一套機制,它允許一個較慢的消費者告訴較快的生產(chǎn)者去降速。
我們的索引系統(tǒng)沒有背壓的概念,這在之前沒什么問題,反正我們把整個索引都保存到內(nèi)存里了。一旦我們解決了之前的問題,開始真正的流式處理數(shù)據(jù),缺少背壓的問題就變得很明顯了。
這個模式我在解決性能問題時見過很多次了:解決一個問題時會浮現(xiàn)另一個你甚至沒有聽說過的問題,因為其他問題把它隱藏起來了。如果你的房子經(jīng)常被淹,你不會注意到它有火災隱患。
修復由修復引起的問題
在 RxJava 2 里,原來的 Observable 類被拆成了不支持背壓的 Observable 和支持背壓的
Flowable。幸運的是,有一些簡單的辦法,可以開箱即用的把不支持背壓的 Observable 改造成支持背壓的
Flowable。其中包含從非響應式的資源比如 Iterable 創(chuàng)建 Flowable。把這些 Flowable 融合起來可以生成同樣支持背壓的
Flowable,因此只要快速解決一個點,整個系統(tǒng)就有了背壓的支持。
有了這個改動之后,我們把堆從 12 GB 減少到了 3 GB ,同時讓系統(tǒng)保持和之前同樣的速度。我們?nèi)匀幻扛魯?shù)小時就會有一次暫停長達 2 秒的
full GC,不過這比我們之前見到的 20 秒的暫停(還有系統(tǒng)崩潰)要好多了。
再次優(yōu)化 GC
但是,故事到此還沒有結束。檢查 GC 的日志,我們注意到大量的過早提升,占到
70%。盡管性能已經(jīng)可以接受了,我們也嘗試去解決這個問題,希望也許可以同時解決 full GC 的問題。
如果一個對象的生命周期很短,但是它仍然晉升到了老年代,我們就把這種現(xiàn)象叫做過早提升(premature
tenuring)(或者叫過早升級)。老年代里的對象通常都比較大,使用與新生代不同的 GC 算法,而這些過早提升的對象占據(jù)了老年代的空間,所以它們會影響 GC
的性能。因此,我們想竭力避免過早提升。
我們的應用在索引的過程中會產(chǎn)生大量短生命周期的對象,因此一些過早提升是正常的,但是不應該如此嚴重。當應用產(chǎn)生大量短生命周期的對象時,能想到的第一件事就是簡單的增加新生代的空間。默認情況下,G1
的 GC 可以自動的調整新生代的空間,允許新生代使用堆內(nèi)存的 5% 至 60%。
我注意到運行的應用里,新生代和老年代的比例一直在一個很寬的幅度里變化,不過我依然動手修改了兩個參數(shù):-XX:G1NewSizePercent=40 和
-XX:G1MaxNewSizePercent=90看看會發(fā)生什么。這沒起作用,甚至讓事情變得更糟糕了,應用一啟動就觸發(fā)了 full
GC。我也嘗試了其他的比例,不過最好的情況就是只增加
G1MaxNewSizePercent而不修改最小值。這起了作用,大概和默認值的表現(xiàn)差不多,也沒有變好。
嘗試了很多辦法后,也沒有取得什么成就,我就放棄了,然后給 Kirk Pepperdine 發(fā)了封郵件。他是位很知名的 Java 性能專家,我碰巧在
Allegro 舉辦的 Devoxx 會議的訓練課程里認識了他。通過查看 GC 的日志以及幾封郵件的交流,Kirk 建議試試設置
-XX:G1MixedGCLiveThresholdPercent=100。這個設置應該會強制 G1 GC 在 mixed GC
時不去考慮它們被填充了多少,而是強制清理所有的老年代,因此也同時清理了從新生代過早提升的對象。這應該會阻止老年代被填滿從而產(chǎn)生一次 full GC。
然而,在運行一段時間以后,我們再次驚訝的發(fā)現(xiàn)了一次 full GC。Kirk 推斷說他在其他應用里也見到過這種情況,它是 G1 GC 的一個
bug:mixed GC 顯然沒有清理所有的垃圾,讓它們一直堆積直到產(chǎn)生 full GC。他說他已經(jīng)把這個問題通知了
Oracle,不過他們堅稱我們觀察到的這個現(xiàn)象不是一個 bug,而是正常的。
我們最后做的就是把應用的內(nèi)存調大了一點點(從 3 GB 到 4 GB),然后 full GC
就消失了。我們?nèi)匀挥^察到大量的過早提升,不過既然性能是沒問題的,我們就不在乎這些了。一個我們可以嘗試的選項是轉換到 GMS(Concurrent Mark
Sweep)GC,不過由于它已經(jīng)被廢棄了,我們還是盡量不去使用它。
那么這個故事的寓意是什么呢?
首先,性能問題很容易讓你誤入歧途。一開始看起來是 ZooKeeper 或者
網(wǎng)絡的問題,最后發(fā)現(xiàn)是我們代碼的問題。即使意識到了這一點,我首先采取的措施也沒有考慮周全。為了防止 full GC,我在檢查到底發(fā)生了什么之前就開始調優(yōu)
GC。這是一個常見的陷阱,因此記?。杭词鼓阌幸粋€直覺去做什么,先檢查一下到底發(fā)生了什么,再檢查一遍,防止浪費時間去錯誤的問題。
第二條,性能問題太難解決了。我們的代碼有良好的測試覆蓋率,而且運行的特別好,但是它也沒有滿足性能的要求,它在開始的時候就沒有清晰的定義好。性能問題直到部署之后很久才浮現(xiàn)出來。由于通常很難真實的再現(xiàn)你的生產(chǎn)環(huán)境,你經(jīng)常被迫在生產(chǎn)環(huán)境測試性能,即使那聽起來非常糟糕。
第三條,解決一個問題有可能引發(fā)另一個潛在問題的浮現(xiàn),強迫你不斷挖的比你預想的更深。我們沒有背壓的事實足以中斷這個系統(tǒng),但是直到我們解決了內(nèi)存泄漏的問題后,它才浮現(xiàn)。
感謝大家閱讀由java問答分享的“Java 內(nèi)存泄漏調試錯誤怎么辦?”希望對大家有所幫助,想了解更多培訓信息請關注java培訓機構官網(wǎng)
免責聲明:以上內(nèi)容僅作為信息傳播,文中部分信息來源于互聯(lián)網(wǎng),僅供閱讀參考。