GC 日志分析

日志示例

---

[GC (Allocation Failure) [PSYoungGen: 5478K->511K(6144K)] 17766K->13732K(19968K), 0.0016107 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

[Full GC (Ergonomics) [PSYoungGen: 511K->0K(6144K)] [ParOldGen: 13220K->13671K(13824K)] 13732K->13671K(19968K), [Metaspace: 3314K->3314K(1056768K)], 0.0105324 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]

[Full GC (Ergonomics) [PSYoungGen: 4096K->4096K(6144K)] [ParOldGen: 13671K->13585K(13824K)] 17767K->17681K(19968K), [Metaspace: 3314K->3314K(1056768K)], 0.0106094 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]

[Full GC (Allocation Failure) [PSYoungGen: 4096K->4096K(6144K)] [ParOldGen: 13585K->13568K(13824K)] 17681K->17664K(19968K), [Metaspace: 3314K->3314K(1056768K)], 0.0102245 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

日志解读

---

[GC、[Full GC：

日志开头的 [GC、[Full GC 说明了这次垃圾收集的停顿类型，并不是用来区分新生代 GC 和老年代 GC 的，如果有 “Full”，说明这次 GC 是发生了 Stop-The-Word 的。

(Allocation Failure)、(Ergonomics)：

描述触发 GC 的原因。

• Allocation Failure：年轻代内存不足
• Ergonomics：虚拟机自动优化

[PSYoungGen、[ParOldGen、 [Metaspace：

特定的垃圾收集器日志标识，不同的垃圾收集器各不相同。

• PSYoungGen：新生代垃圾回收，使用 Parallel Scavenge 收集器
• ParOldGen：老年代垃圾回收，使用 Parallel Old 收集器
• Metaspace：元空间垃圾回收；注意，JDK1.8后，JVM不再有永久代（PermGen），但类的元数据信息（metadata）还在，存储在叫做 “Metaspace” 的本地内存（Native memory）中；强调：元空间并不在虚拟机中，而是在本地内存。参考：Metaspace 之一：Metaspace整体介绍（永久代被替换原因、元空间特点、元空间内存查看分析方法）

以第一条日志为例解释每组数字的含义：

[GC (Allocation Failure) [PSYoungGen: 5478K->511K(6144K)] 17766K->13732K(19968K), 0.0016107 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

5478K->511K(6144K)：
中括号 “[ ]” 内的数值，表示 “GC 前该区域（此处代表新生代）已使用内存 -> GC 后该区域已使用内存（该区域内存总量）”。

17766K->13732K(19968K)：
中括号 “[ ]” 后面的数值，表示 “GC 前堆区已使用内存 -> GC 后堆区已使用内存（堆区内存总量）”。

0.0016107 secs]：
本次 GC 耗时，单位为秒。

[Times: user=0.00 sys=0.00, real=0.00 secs]：
分别表示：用户态耗时、内核态耗时、总耗时。

结果分析

---

第一条日志

新生代经过 GC 后，减少了 5478 - 511 = 4967(K)；
整个堆区经过 GC 后，减少了 17766 - 13732 = 4034(K)；
两者的差值为 4967 - 4034 = 933(K)，此差值表示有 933K 的数据被转移到了老年代。

第二条日志

重点看老年代收集结果：[ParOldGen: 13220K->13671K(13824K)]，可以看出，老年代 GC 后并未释放多少空间，并且老年代空间占用已满。

第三条日志

还是重点看老年代的收集结果：[ParOldGen: 13671K->13585K(13824K)]，可以看出，JVM 再次尝试对老年代进行 GC，但效果依然不理想。

第四条日志

从日志可知，新生代和老年代的空间均以占满，此时，程序即将发生 java.lang.OutOfMemoryError: Java heap space。

总结
不看源码，仅看 GC 日志，我们应得出如下结论：

• 运行时，新生代中不断的在产生“朝生夕死”，即生命周期较短的对象
• 老年代的内存在持续增长且不释放

有此结论，基本上就能找出优化方式了：

• 增大堆内存，尤其是老年代的内存
• 如果老年代内存一直持续增长不释放，那就默默的去检查源码吧~

测试源码

---

示例中的日志，来自于一个简单的测试方法：在限制了堆内存大小的情形下，向集合中不停的添加新对象。

/**
 * -Xms20M -Xmx20M -XX:+PrintGCDetails -XX:HeapDumpPath=D:\
 */
public class HeapOOM {

    static class OOMProject{
    }

    public static void main(String[] args) {
        List<OOMProject> list = new ArrayList<>();
        while (true){
            list.add(new OOMProject());
        }
    }
}

补充：堆的内存分配

---

在采用“分代收集算法”进行垃圾回收的虚拟机中，根据对象存活周期的不同，一般将 Java 堆分为新生代和老年代。
新生代中对象的生命周期通常较短，因此选用“复制”算法对其进行垃圾回收较为合适，每次仅需付出少量对象的复制成本即可完成回收。而老年代中对象存活率高且没有额外空间进行担保，因此必须采用“标记-清除”或“标记-整理”算法对其进行回收。

新生代和老年代的内存分配比例

参数 -XX:NewRatio 用来设置新生代和老年代的比例，默认值为 2，即新生代占堆内存的1/3，老年代占堆内存的2/3。

参数 -XX:SurvivorRatio 用来设置新生代中 Eden 区域和两个 survivor 区域的比例，默认值为 8，Eden 区域占新生代内存的8/10，两个 survivor 各占1/10。注意：新生代中可用内存为 Eden + 一个 survivor 区域，有一个 survivor 区域是不可用的。