一、狀況概述
公司之前的某報名系統,項目啓動後,在通過用戶一段時間的使用以後,項目響應便開始變得極其緩慢,最後幾乎毫無反應。日誌裏輸出了一些彷佛無關痛癢的異常,逐步修復,項目仍然出現這種狀況,且 「項目啓動 -> 服務無響應」 這段時間並不穩定。直到在被反覆折磨的這幾天裏終於日誌抓到了幾個異常,都是 javax.servlet.ServletException: java.lang.OutOfMemoryError: Java heap space
二、異常分析
JVM在啓動時默認設置可調配的內存空間爲物理內存的1/64但小於1G,若是該空間的可用空間不足 2%,則拋出異常
OutOfMemoryError : Java heap space
項目中的日誌模塊並沒能輸出可追溯的內存溢出,只能先排除一些猜測:
- 項目中幾乎不涉及大圖片加載,流不關閉等狀況能夠排除
- 項目中的對象模型並不複雜,JVM的初始參數足夠使用,因此單純調整JVM的參數設置不是個好辦法
在瞭解一下定位排錯的方式後,發現這麼個東西:JVM Heap Dump(堆轉儲文件),Heap Dump 記錄了JVM中堆內存運行的狀況,可使用JDK提供的命令
jmap 生成,命令格式以下:
jmap -dump:live,format=b,file=heap-dump.bin <pid>
其中
pid 是JVM進程的id,
heap-dump.bin 是生成的文件名稱,會在執行命令的目錄下生成該文件
注:在執行命令生成 dump 文件的過程當中,曾報錯 "Insufficient memory or insufficient privileges to attach",這是由於權限問題,調用系統服務啓動的tomcat和命令行執行命令看上去都在同個administrator用戶下,其實否則。解決方法是將 tomcat 以 startup.bat 啓動,再在命令行調用 jmap 便可。
使用該工具打開生成的 dump 文件,緩慢分析載入後彈出選框,選擇 Leak Suspects Report:
Dominator Tree :支配樹,列出Heap Dump中處於活躍狀態中的最大的幾個對象,默認按 retained size進行排序,所以很容易找到佔用內存最多的對象。
使用工具的支配樹功能,看到以下:
兩個最高佔比,而奇怪的在於之中:
總佔比 29.85%,可是之中最大的對象居然也就只佔了 2.41%,怎麼回事?仔細一看,除開前幾個對象以外,後面所有都是 Examinee 對象,數量之多,下面的黑體提示 "
Total: 25 of 228,841 entries; 228,816",剩餘二十多萬個對象,展開一看全是 Examinee 和相關 Hibernate 的 EntityEntry 對象!那麼形成內存溢出的問題就顯而易見了,
內存中加載的數據量過於龐大,多是循環引用形成的內存泄漏,也多是對象產出過快垃圾回收沒法及時處理。
三、錯誤定位
跟用戶進行溝通後,瞭解到其主要是在進行考生報名添加的操做,因而進行了模擬,發如今添加報名時發送了一個請求響應很慢,數據量也很大:
響應耗時2s,數據量居然有2MB,點開一看,正是大量的考生信息數據,足足有30000+條:
看了下這個請求數據的做用,是在拿給前端的一個插件進行自動選擇用的:
再看後臺的代碼也很粗暴,數據沒作處理,抓出來直接全丟給前臺了,這個過程當中固然也就生成了成千上萬個 Examinee 對象:
由於這個方法是在每次添加考生報名的時候都會觸發,而用戶在進行考生報名時添加操做很頻繁,若是多個用戶同時進行添加操做,那麼短期內產生的考生對象 Examinee 將直線上升,垃圾回收清理不及時,因而內存溢出的異常也就隨之而來了。
知道了因果,那麼把前端的數據抓取方式改一下就解決了。
修改以前,系統異常時的 dump 文件足有 280MB,修改以後系統穩定運行,生成的 dump 文件大概只有 100MB 左右了,完結撒花。
四、回顧和經驗
這個項目前年就投入使用,去年也僅是增長了微信支付等和核心業務沒有太大關聯的相關功能,直到今年才暴露這個問題,其緣由也正是由於數據量隨着時間在不斷增長,以往數據量小,哪怕數據徹底加載也沒有壓力,可是如今徹底加載的話,內存就吃不消了。
這也是爲何我以前使用 "項目重啓" 的方式來恢復使用,但每次的效果卻愈來愈差的緣由,由於隨着使用數據量也愈來愈大了。
此次排錯的兩點收穫:
- 學會了最基本的內存分析方式,經過 dump 文件和 MAT 工具
- 明白了某些功能在生產運行的過程當中,可能會隨着數據量和業務狀況的不斷龐大而性能降低,在編寫代碼初期就要儘可能預估未來數據量的發展趨勢,以作出穩定合理的算法
五、參考連接