JProfile 分析OOM hprof文件

JProfile 分析OOM OutOfMemoryError

1.JVM组成

首先要明白JVM组成

1. 方法区-非堆 Method Area、No-Heap
2. Java栈-虚拟机栈 VM Stack、Java Stack
3. 本地方法栈 Native Method Stack
4. 程序计数器 Program Counter Register
5. 堆 Heap

1.1 OOM发生在哪里?

OOM可以发生在除了程序计数器外的其他部分，包括四块：

• 方法区（非堆）
• Java栈
• 本地方法栈
• 堆

1.2 垃圾回收、哪里有垃圾？

• 方法区（非堆）
• 堆

1.3 基本JVM参数

参数示例	描述说明
-verbose:gc	控制台打印GC参数
-Xms20M	初始堆大小 20M
-Xmx20M	最大堆大小20M 一般情况下-Xms和-Xmx这两个值设为相同大小。因为如果不相同
-Xmn10M	新生代最大可用值10M
-XX:+PrintGC	触发GC时日志打印
-XX:+PrintGCDetails	触发GC时日志打印详细
–XX:UseSerialGC	串行回收
-XX:SurvivorRatio=2	eden:from:to =2:1:1
-XX:+HeapDumpOnOutOfMemoryErro	OOM时生成Dump文件
-XX:NewRatio=2	新生代:老年代 = 1:2

2.堆发生OOM

2.1 代码

调整JVM参数

# -verbose:gc  控制台打印GC参数
# -Xms10M 初始堆大小
# -Xmx10M 最大堆大小 一般情况下-Xms和-Xmx这两个值设为相同大小。因为如果不相同且内存不够用时会发生内存抖动现象，影响程序运行
# -Xmn5M  新生代最大可用值5M
# -XX:+PrintGC  触发GC时日志打印
# -XX:+PrintGCDetails 触发GC时日志打印详细
# -XX:+HeapDumpOnOutOfMemoryError OOM时生成Dump文件
# -XX:SurvivorRatio=3 说明伊甸区 eden:from:to=3:1:1
-verbose:gc -Xms10M -Xmx10M -Xmn5M  -XX:PrintGC  -XX:PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:SurvivorRatio=10

运行代码

package com.jzj.jvmtest.oomtest;

import java.util.ArrayList;
import java.util.List;

/**
 * 堆溢出， 只要不停的新建对象，就会堆溢出
 */
public class HeapOOM {
    public static void main(String[] args) {
        System.out.print("最大内存： ");
        System.out.println(Runtime.getRuntime().maxMemory() / 1024 / 1024 + "MB");
        System.out.print("可用内存： ");
        System.out.println(Runtime.getRuntime().freeMemory() / 1024 / 1024 + "MB");
        System.out.print("已使用内存： ");
        System.out.println(Runtime.getRuntime().totalMemory() / 1024 / 1024 + "MB");

        List<HeapOOM> list = new ArrayList<>();
        while (true) {
            list.add(new HeapOOM());
        }
    }
}

2.2 OOM日志

最大内存： 18MB
可用内存： 15MB
已使用内存： 18MB
[GC (Allocation Failure) [PSYoungGen: 5595K->2040K(8192K)] 5595K->2997K(18432K), 0.0022678 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [PSYoungGen: 8184K->2038K(8192K)] 9141K->7231K(18432K), 0.0053117 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
[Full GC (Ergonomics) [PSYoungGen: 6144K->6144K(8192K)] [ParOldGen: 10123K->10123K(10240K)] 16267K->16267K(18432K), [Metaspace: 3500K->3500K(1056768K)], 0.1431659 secs] [Times: user=1.41 sys=0.00, real=0.14 secs] 
[Full GC (Ergonomics) [PSYoungGen: 6144K->6144K(8192K)] [ParOldGen: 10124K->10124K(10240K)] 16268K->16268K(18432K), [Metaspace: 3500K->3500K(1056768K)], 0.1269467 secs] [Times: user=1.09 sys=0.00, real=0.13 secs] 
[Full GC (Ergonomics) [PSYoungGen: 6144K->6144K(8192K)] [ParOldGen: 10125K->10125K(10240K)] 16269K->16269K(18432K), [Metaspace: 3500K->3500K(1056768K)], 0.1402382 secs] [Times: user=1.41 sys=0.00, real=0.14 secs] 
[Full GC (Ergonomics) [PSYoungGen: 6144K->6144K(8192K)] [ParOldGen: 10126K->10126K(10240K)] 16270K->16270K(18432K), [Metaspace: 3500K->3500K(1056768K)], 0.1276036 secs] [Times: user=1.13 sys=0.00, real=0.13 secs] 
[Full GC (Ergonomics) [PSYoungGen: 6144K->6144K(8192K)] [ParOldGen: 10127K->10127K(10240K)] 16271K->16271K(18432K), [Metaspace: 3500K->3500K(1056768K)], 0.1277889 secs] [Times: user=1.24 sys=0.00, real=0.13 secs] 
java.lang.OutOfMemoryError: GC overhead limit exceeded
Dumping heap to java_pid30128.hprof ...
Heap dump file created [27909929 bytes in 0.072 secs]
[Full GC (Ergonomics) [PSYoungGen: 6144K->0K(8192K)] [ParOldGen: 10179K->762K(10240K)] 16323K->762K(18432K), [Metaspace: 3542K->3542K(1056768K)], 0.0042329 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 PSYoungGen      total 8192K, used 167K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 6144K, 2% used [0x00000000ff600000,0x00000000ff629e60,0x00000000ffc00000)
  from space 2048K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x0000000100000000)
  to   space 2048K, 0% used [0x00000000ffc00000,0x00000000ffc00000,0x00000000ffe00000)
 ParOldGen       total 10240K, used 762K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 7% used [0x00000000fec00000,0x00000000fecbe9a8,0x00000000ff600000)
 Metaspace       used 3615K, capacity 4508K, committed 4864K, reserved 1056768K
  class space    used 394K, capacity 396K, committed 512K, reserved 1048576K
Exception in thread "main" java.lang.OutOfMemoryError: GC overhead limit exceeded
	at com.jzj.jvmtest.oomtest.HeapOOM.main(HeapOOM.java:20)

Process finished with exit code 1

2.3 日志分析

Eden-From-To分析

-XX:SurvivorRatio=3 说明2个Survivor 与Eden区的 大小比值为 2：3
以-Xmn = 10M 为例 10*1024KB / （2+3） = 2048KB/每一份
Eden有 3份也就是6M，From Survivor有2M，To Survivor有2M
对比日志

 PSYoungGen      total 8192K, used 167K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 6144K, 2% used [0x00000000ff600000,0x00000000ff629e60,0x00000000ffc00000) -6M
  from space 2048K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x0000000100000000) -2M
  to   space 2048K, 0% used [0x00000000ffc00000,0x00000000ffc00000,0x00000000ffe00000) -2M

2.4 报错日志

Event: 5.271 GC heap after
Heap after GC invocations=39 (full 37):
 PSYoungGen      total 8192K, used 6143K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 6144K, 99% used [0x00000000ff600000,0x00000000ffbffff8,0x00000000ffc00000)
  from space 2048K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x0000000100000000)
  to   space 2048K, 0% used [0x00000000ffc00000,0x00000000ffc00000,0x00000000ffe00000)
 ParOldGen       total 10240K, used 10140K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 99% used [0x00000000fec00000,0x00000000ff5e70f0,0x00000000ff600000)
 Metaspace       used 3500K, capacity 4500K, committed 4864K, reserved 1056768K
  class space    used 382K, capacity 388K, committed 512K, reserved 1048576K
}

eden space 6144K, 99% used [0x00000000ff600000,0x00000000ffbffff8,0x00000000ffc00000) Eden区 占用99%说明程序在不停的新建对象，一直把Eden 占满了 ，而且 触发YongGC后，看一下YGC的日志

[GC (Allocation Failure) [PSYoungGen: 5595K->2040K(8192K)] 5595K->2997K(18432K), 0.0022678 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

PSYoungGen: 5595K->2040K(8192K)
年轻代垃圾回收前5595K，年轻代回收后 2040K， 年轻代总大小一共8192K
整个堆回收前大小5595K，整个堆回收后2997K，整个堆一共大小18432K~=18M

3.JProfile 分析Dump文件

3.1 打开JProfile

我们找到发生OOM时候，的Dump文件，然后用JProfile打开

3.2 找到最大的对象

最大的对象很有可能是当前OOM溢出的原因，可以看到最大的对象时HeapOOM这个对象，JVM中有81W个这样的对象

3.3 找到代码出错的位置

选中当前对象，右键 -> Use selected Objects

点击OK

选中 Incoming references

点击 show more

3.4 定位到代码行号

可以看到 com.jzj.jvmtest.oomtest.HeapOOM.main(java.lang.String[ ]) (line: 20)
Main函数的 20行 进行了ArrayList.add 操作 ，导致OOM