Java堆溢位OutOfMemoryError之程式碼例項和原因分析
本文演示了編寫程式碼使得出現”java.lang.OutOfMemoryError: Java heap space”異常,分析GC日誌得出OOM的原因,同時對堆轉儲檔案進行分析,以檢視把Heap塞滿的罪魁禍首;
例項程式碼
這段程式碼來自《深入理解Java虛擬機器-JVM高階特性與最佳實踐》一書:
用於測試Java堆OOM的程式碼 Java123456789101112131415161718192021222324 | packagejvmtest;importjava.util.ArrayList;importjava.util.List;/** * VM Args:-Xms20m -Xmx20m -XX:+HeapDumpOnOutOfMemoryError |
在eclipse執行該程式碼時,需要設定堆size的最小值和最大值,同時使用-XX:+PrintGCDetails引數開啟GC日誌列印,使用-XX:+HeapDumpOnOutOfMemoryError引數當OOM時轉儲堆資料
1 | -verbose:gc-Xms20M-Xmx20M-Xmn10M-XX:+PrintGCDetails-XX:SurvivorRatio=8-XX:+HeapDumpOnOutOfMemoryError |
然後點執行,會出現以下的GC日誌、異常、堆資訊、轉儲資訊
[GC[DefNew: 7640K->1024K(9216K), 0.0164901 secs] 7640K->4593K(19456K), 0.0166075 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] [GC[DefNew: 9216K->1024K(9216K), 0.0190825 secs] 12785K->10510K(19456K), 0.0191593 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] [GC[DefNew: 9216K->9216K(9216K), 0.0000369 secs][Tenured: 9486K->5704K(10240K), 0.0520898 secs] 18702K->14129K(19456K), [Perm : 148K->148K(12288K)], 0.0522306 secs] [Times: user=0.06 sys=0.00, real=0.05 secs] [Full GC[Tenured: 5704K->5704K(10240K), 0.0435436 secs] 14616K->14616K(19456K), [Perm : 148K->148K(12288K)], 0.0436766 secs] [Times: user=0.03 sys=0.00, real=0.04 secs] [Full GC[Tenured: 5704K->5695K(10240K), 0.0499650 secs] 14616K->14606K(19456K), [Perm : 148K->147K(12288K)], 0.0500832 secs] [Times: user=0.06 sys=0.00, real=0.05 secs] java.lang.OutOfMemoryError: Java heap space Dumping heap to java_pid12428.hprof ... Heap dump file created [29715028 bytes in 0.335 secs] Exception in thread "main" java.lang.OutOfMemoryError: Java heap space at java.util.Arrays.copyOf(Arrays.java:2245) at java.util.Arrays.copyOf(Arrays.java:2219) at java.util.ArrayList.grow(ArrayList.java:242) at java.util.ArrayList.ensureExplicitCapacity(ArrayList.java:216) at java.util.ArrayList.ensureCapacityInternal(ArrayList.java:208) at java.util.ArrayList.add(ArrayList.java:440) at jvmtest.HeapOOM.main(HeapOOM.java:20) Heap def new generation total 9216K, used 8921K [0x33640000, 0x34040000, 0x34040000) eden space 8192K, 100% used [0x33640000, 0x33e40000, 0x33e40000) from space 1024K, 71% used [0x33e40000, 0x33ef6600, 0x33f40000) to space 1024K, 0% used [0x33f40000, 0x33f40000, 0x34040000) tenured generation total 10240K, used 5695K [0x34040000, 0x34a40000, 0x34a40000) the space 10240K, 55% used [0x34040000, 0x345cfc28, 0x345cfe00, 0x34a40000) compacting perm gen total 12288K, used 150K [0x34a40000, 0x35640000, 0x38a40000) the space 12288K, 1% used [0x34a40000, 0x34a658c8, 0x34a65a00, 0x35640000) ro space 10240K, 44% used [0x38a40000, 0x38eb73f0, 0x38eb7400, 0x39440000) rw space 12288K, 52% used [0x39440000, 0x39a8dd28, 0x39a8de00, 0x3a040000)
GC日誌分析
從圖中可以看出,發生了3次GC和2次FULL GC,當兩次FULL GC完成後,仍然發現沒有空間,於是丟擲了OOM異常;
首先貼一下GC和FULL GC的日誌格式:
還有jvm heap的記憶體結構
在正常執行狀況下:
- 新的物件都在eden上建立
- 如果eden的大小達到了閾值,就會觸發GC,執行“標記-複製”演算法,將Eden中有效的物件複製到Survivor中,並清除eden中無效的物件
- 如果eden的大小再次達到閾值,就會觸發GC,將物件從eden物件複製到survivor,如果survivor中的物件達到了年齡限制,就會複製到old區;
如果young區向old區複製物件的時候,發現old區的空間無法滿足,就會觸發FULL GC,如果FULL GC之後,仍然無法承載Young區要晉升的物件大小,那麼就會丟擲OOM;
從Heap開頭的日誌可以看到eden區已經佔用了100%,from survivor區也佔用了71%無法承載來自eden的物件,eden+from survivor區物件之和為8192K+1024K*71%=8919.04K,但是old區只剩下10240*(1-55%)=的空間4608K的空間;新的物件無法在100%佔用率的eden區建立,eden+survivor的物件又不能複製到old區,所以OOM;
注意:本文的程式碼很特殊,每個HeapOOM物件都沒有被釋放,正常情況下,eden很多無用物件是會被清除掉的,晉升到OLD的大小也不等於eden+survivor的大小之和;
堆轉儲檔案分析
由於加上了-XX:+HeapDumpOnOutOfMemoryError引數,所以OOM時,自動生成了一個java_pid12464.hprof的堆轉儲檔案,給eclipse安裝Memory Analyzer外掛後,直接可以用該外掛開啟;
開啟後如下圖所示
可以看到main函式執行緒佔用了13.9MB幾乎所有的Heap空間,在餅圖上右鍵 > list objects > with outgoing references,可以檢視該部分包含了那些物件:
開啟後發現,一個Obejct陣列中包含了1215488個元素,每個元素都是HeapOOM物件,每個元素(引用型別)為8byte,這就是讓堆OOM的罪魁禍首;
結論
- 使用JVM引數-XX:+PrintGCDetails可以列印GC日誌
- 使用JVM引數-XX:+HeapDumpOnOutOfMemoryError可以在OOM時列印堆轉儲檔案
- 使用eclipse外掛Memory Analyzer可以分析對轉儲檔案
- OOM的原因,是Old區在FULL GC之後的剩餘空間,仍然無法承載Young區要晉升的物件大小