Java堆溢出OutOfMemoryError之代码实例和原因分析
本文演示了编写代码使得出现”java.lang.OutOfMemoryError: Java heap space”异常,分析GC日志得出OOM的原因,同时对堆转储文件进行分析,以查看把Heap塞满的罪魁祸首;
实例代码
这段代码来自《深入理解Java虚拟机-JVM高级特性与最佳实践》一书:
在eclipse运行该代码时,需要设置堆size的最小值和最大值,同时使用-XX:+PrintGCDetails参数开启GC日志打印,使用-XX:+HeapDumpOnOutOfMemoryError参数当OOM时转储堆数据
然后点运行,会出现以下的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区要晋升的对象大小
上一篇: 我的第一个开源项目 GWT Model