由于JVM的內(nèi)存管理采用GC垃圾自動(dòng)回收機(jī)制,這使得Java程序員在編程的時(shí)候確實(shí)可以從內(nèi)存管理中釋放出來,但這也引發(fā)了另外一個(gè)大問題,一旦Java應(yīng)用出現(xiàn)內(nèi)存泄漏的時(shí)候,常常讓人措手不及,陷入無從下手的尷尬境地,我們總不能一句話重啟吧(苦笑)。
內(nèi)存問題可能是大多數(shù)Java程序員心中都曾有過的傷,因?yàn)樘菀子鲆娏?/b>。
下面這篇文章是我去年寫在個(gè)人微信公眾號(hào)上的,今天早上回頭再看心中不免有些噓噓感慨,于是決定重新整理把它發(fā)到簡(jiǎn)書上來,以下為正文:
前2天負(fù)責(zé)的一個(gè)線上系統(tǒng)在早上9點(diǎn)20分接到大量用戶反饋系統(tǒng)很卡,頁面無響應(yīng)。我聯(lián)系運(yùn)維及時(shí)查看后臺(tái)服務(wù)器,發(fā)現(xiàn)WAS(Websphere) server bin目錄下生成了javacore 和heapdump,這個(gè)消息讓我整個(gè)人都不好了,項(xiàng)目推廣關(guān)鍵時(shí)期居然來這么一出,可謂多事之秋,搞事情?。?/p>
?好吧,既然程序運(yùn)行時(shí)遇到了坑,那我們就先來找到這個(gè)坑,再把坑填好(圍笑)。
?簡(jiǎn)單介紹下,線上應(yīng)用運(yùn)行在power linux OS平臺(tái)之上,web容器為IBM WebSphere ,JDK ?ibm j9vm 64 位。
?首先開始通過ibm ha456.jar 分析線上dump 文件
?上圖Heap usage,堆內(nèi)存已使用約3.7G,且41.95%的內(nèi)存都被rootobject 和它的引用吃掉了,接下來我再查看rootobject ,如下圖:
內(nèi)存主要是被2個(gè)LinkedHashMap吃掉了,于是仔細(xì)查找項(xiàng)目源碼中會(huì)用到LinkedHashMap的地方,無果。
接下來再來看一下這些LinkedHashMap當(dāng)中都包含什么對(duì)象,看看它們會(huì)指向哪些東西呢,如下圖:
這里發(fā)現(xiàn)有一個(gè)org.xhtmlrender.resource.ImageResource類,且點(diǎn)開所有節(jié)點(diǎn)LinkedHashMap 都有此類的實(shí)例及強(qiáng)引用,如下圖顯示第一個(gè)root? LinkedHashMap 有178個(gè)此類實(shí)例
于是繼續(xù)分析下ImageResource 類節(jié)點(diǎn),如下圖:
此對(duì)象節(jié)點(diǎn)只有一個(gè)parentes node,且這個(gè)parentes node 對(duì)象就是LinkedHashMap
接著我查看項(xiàng)目源碼,發(fā)現(xiàn) org.xhtmlrender.resource.ImageResource類屬于如下圖:
Maven 引用如下:
分析項(xiàng)目代碼,上面3個(gè)jar包是用來將html文件轉(zhuǎn)成pdf文件,目前能推斷出的結(jié)論是此功能模塊耗用盡了jvm 堆內(nèi)存,由此導(dǎo)致線上應(yīng)用崩潰了。。。
仔細(xì)檢查這一功能塊區(qū)域的代碼發(fā)現(xiàn)不存在有大規(guī)模瞬時(shí)加載大量數(shù)據(jù)到內(nèi)存中的潛在代碼,由此判斷不是瞬時(shí)某個(gè)交易功能導(dǎo)致,應(yīng)該是此功能區(qū)域的某個(gè)方法執(zhí)行時(shí)存在內(nèi)存泄漏的可能。
線上應(yīng)用架構(gòu)是集群 F5部署,因此有另外一臺(tái)尚沒有生成javacore 的was服務(wù)做對(duì)比,于是在當(dāng)晚非作業(yè)時(shí)間,kill -3 [pid]生成dump 文件進(jìn)一步分析,發(fā)現(xiàn)這臺(tái)應(yīng)用的堆內(nèi)存也用到3.6G,只是還沒有到崩潰的臨界點(diǎn)而已,且都是被同樣的LinkedHashMap 吃掉大半以上。
內(nèi)存泄漏點(diǎn)幾乎已確定在此處了,于是讓同事寫了一個(gè)客戶端測(cè)試小程序并發(fā)的對(duì)此功能區(qū)方法Action發(fā)起請(qǐng)求,以下為測(cè)試環(huán)境請(qǐng)求我自己本地服務(wù)JVM監(jiān)控圖示:
上部左邊圖可看出垃圾回收活動(dòng)越來越頻繁,上部右邊圖堆內(nèi)存的已使用占比也在緩慢遞增,典型的內(nèi)存有泄漏,GC每次回收都不完全,導(dǎo)致GC回收的復(fù)雜度越來越高,離out of memory?只是時(shí)間問題。
再對(duì)測(cè)試環(huán)境中的was服務(wù)器進(jìn)行壓測(cè),以進(jìn)一步驗(yàn)證此問題點(diǎn),發(fā)現(xiàn)was體系內(nèi)存的開銷更明顯,如下圖,看到內(nèi)存呈現(xiàn)階梯式遞增
對(duì)比上面2圖,在客戶端測(cè)試程序壓力一定情況下,was服務(wù)器(1.6jdk)的表現(xiàn)比我本機(jī)還要糟糕,這可能是我本機(jī)Mac用的1.8 jdk JVM GC相對(duì)于1.6有優(yōu)化吧。
服務(wù)端在運(yùn)行4小時(shí)之后,內(nèi)存耗盡,程序Over,且在was應(yīng)用目錄下生成了javacore(這期間暫停過很多次客戶端壓力程序,但服務(wù)端JVM堆內(nèi)存的占用一直是居高不下,無法回收)。

同樣使用ha456分析javacore,發(fā)現(xiàn)堆內(nèi)存的耗用情況與生產(chǎn)幾乎一致,堆內(nèi)存大部分都是耗用在LinkedHashMap和commons pool中

至此斷定問題一定是出在html轉(zhuǎn)pdf方法體中,查閱項(xiàng)目源碼及用到的開源jar包說明文檔,定位到出問題的關(guān)鍵代碼塊如下:
初步分析應(yīng)該是ITextRenderObjctFactory中ObjctPool池的ITextRender對(duì)象資源不釋放導(dǎo)致的,對(duì)象池Factory關(guān)鍵配置如下:
查閱相關(guān)資料說明,我分析應(yīng)該是ITextRende對(duì)象一直活躍在對(duì)象池pool中(pool默認(rèn)配置:空閑對(duì)象可存活30分鐘),應(yīng)用在白天作業(yè)期間對(duì)htmlToPdf方法的調(diào)用幾乎不會(huì)有空閑時(shí)間,所以render一直處于被外圍重復(fù)調(diào)用的情況,導(dǎo)致render持有的資源一直無法得到釋放的機(jī)會(huì),進(jìn)而使程序內(nèi)存耗盡。
調(diào)研過其他項(xiàng)目組源碼也有類似實(shí)現(xiàn)的寫法,但是未出現(xiàn)內(nèi)存耗盡的情況,對(duì)比源碼分析區(qū)別在于其他項(xiàng)目組render渲染html為pdf 時(shí)并未涉及到html文件中有可變圖片url引用的鏈入,而我們項(xiàng)目組每次html轉(zhuǎn)pdf 時(shí)存在可變路徑的圖片引用,導(dǎo)致render需要每次動(dòng)態(tài)創(chuàng)建ImageResource類來動(dòng)態(tài)加載外部圖片URL鏈接,而動(dòng)態(tài)創(chuàng)建的ImageResource 實(shí)例并未能釋放。
因此對(duì)以上關(guān)鍵代碼進(jìn)行優(yōu)化如下:
第一個(gè)紅色箭頭修改部分改為document 由原來的url加載方式改為file
第二個(gè)紅色箭頭為新添加代碼,用于把ITextRender共享上下文Context內(nèi)容重置,以便于單個(gè)render對(duì)象中的資源及時(shí)釋放;
同時(shí)對(duì)于ObjectPool池config配置優(yōu)化如下,關(guān)鍵代碼:
修改參數(shù)說明如下:
1、空閑對(duì)象獲取策略修改為FIFO,先進(jìn)先出,便于對(duì)象池中的對(duì)象公平共享使用,便于空閑未使用到的對(duì)象及時(shí)釋放
2、timeBetweenEvictionRunsMillis為每間隔5秒檢查一下是否存在空閑Idle對(duì)象
3、minEvictableIdleTimeMillis空閑對(duì)象存在1分鐘未被調(diào)用即銷毀
OK,優(yōu)化之后,更新was服務(wù),使用之前的客戶端測(cè)試程序發(fā)起壓力測(cè)試,將堆內(nèi)存上限設(shè)定為1G,結(jié)果表現(xiàn)如下:

持續(xù)壓測(cè)2小時(shí),內(nèi)存耗用穩(wěn)定在1G以內(nèi),當(dāng)客戶端壓力撤去,3分鐘之后內(nèi)存穩(wěn)穩(wěn)回收到200M左右,如下:

接下來穩(wěn)定性測(cè)試6小時(shí),持續(xù)壓測(cè),壓力撤去之后,內(nèi)存占用逐漸回歸到600M左右

更新線上應(yīng)用程序不再出現(xiàn)問題,至此,總算把此問題解決。在這期間收集用于分析的javacore和dump文件約5G(包含測(cè)試環(huán)境was、生產(chǎn)環(huán)境was、本機(jī)tomcat)
以上從定為問題、找到原因、測(cè)試復(fù)現(xiàn)、解決問題到復(fù)測(cè)通過我斷斷續(xù)續(xù)用了2天時(shí)間,這2天放下了手頭一切工作上相對(duì)來說優(yōu)先級(jí)沒有此問題高的事情,可能有的朋友會(huì)感覺我最近工作不走心了呢,其實(shí)不然,不會(huì)了(圍笑)。
軟件系統(tǒng)最常見的就是系統(tǒng)故障,人非圣賢孰能無過,程序員都是人,是人就會(huì)寫B(tài)ug,寫了Bug系統(tǒng)就會(huì)出問題,出了問題系統(tǒng)就可能宕機(jī)。即使你什么事都沒干正在家里陪老丈人喝酒,人家在微博上說,大家好,給大家介紹一下,這是我的女盆友。哐當(dāng),系統(tǒng)掛了,這特么能怪誰呢?真出了問題,慌,罵人,處罰都是后話,沒用的,重要的是解決問題,梳理流程,增加監(jiān)控,減少損失,最后復(fù)盤問題才是牛批。
現(xiàn)在我們的項(xiàng)目正處于大力推廣前的關(guān)鍵時(shí)期,軟件將迎來最終用戶的快速增長(zhǎng),保持服務(wù)的穩(wěn)定是重中之重。
前段時(shí)間看到Mac Talk公眾號(hào)池建強(qiáng)老師發(fā)的一篇原創(chuàng)文章,大意講的是我們每個(gè)人在臨大戰(zhàn)前應(yīng)有靜氣,何意?就是你面臨壓力和挑戰(zhàn)的時(shí)候,一方面心跳加速血管收縮手心冒汗,但你感到的是興奮而不是焦慮,內(nèi)心深處是安靜的,沉著的。
最后大家要是覺得本文還OK,對(duì)你的工作學(xué)習(xí)有所幫助的話請(qǐng)給點(diǎn)個(gè)贊??!筆芯
如果你對(duì)設(shè)計(jì)模式學(xué)習(xí)感興趣的話,請(qǐng)關(guān)注下我,因?yàn)槲易罱诰帉懸徊俊稄牧汩_始學(xué)設(shè)計(jì)模式》系列。