GC日志是一个很重要的工具，它准确记录了每一次的GC的执行时间和执行结果，通过分析GC日志可以优化堆设置和GC设置，或者改进应用程序的对象分配模式。

1 GC日志参数

不同的垃圾收集器，输出的日志格式各不相同，但也有一些相同的特征。熟悉各个常用垃圾收集器的GC日志，是进行JVM调优的必备一步。 解析GC日志，首先需要收集日志，常用的有以下JVM参数用来打印输出日志信息：

1.1 GC日志参数

参数	说明
-XX:+PrintGC	打印简单GC日志。 类似：-verbose:gc
-XX:+PrintGCDetails	打印GC详细信息
-XX:+PrintGCTimeStamps	输出GC的时间戳（以基准时间的形式）
-XX:+PrintGCDateStamps	输出GC的时间戳（以日期的形式）
-XX:+PrintHeapAtGC	在进行GC的前后打印出堆的信息
-Xloggc:../logs/gc.log	指定输出路径收集日志到日志文件

例如，使用如下参数启动：

-Xms28m
-Xmx28m
//开启记录GC日志详细信息（包括GC类型、各个操作使用的时间）,并且在程序运行结束打印出JVM的内存占用情况
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+UseGCLogFileRotation  //开启滚动生成日志
-Xloggc:E:/logs/gc.log

1.2常用垃圾收集器参数

参数	描述
UseSerialGC	虚拟机在运行在 Client 模式下的默认值，打开此开关后，使用Serial+Serial Old 收集器组合进行内存回收
UseParNewGC	使用 ParNew + Serial Old 收集器组合进行内存回收
UseConcMarkSweepGC	使用 ParNew + CMS + Serial Old 的收集器组合尽心内存回收，当 CMS 出现Concurrent Mode Failure 失败后会使用 Serial Old 作为备用收集器
UseParallelOldGC	使用 Parallel Scavenge + Parallel Old 的收集器组合
UseParallelGC	使用 Parallel Scavenge + Serial Old （PS MarkSweep）的收集器组合
SurvivorRatio	新生代中 Eden 和任何一个 Survivor 区域的容量比值，默认为 8
PretenureSizeThreshold	直接晋升到老年代对象的大小，单位是Byte
UseAdaptiveSizePolicy	动态调整 Java 堆中各区域的大小以及进入老年代的年龄
ParallelGCThreads	设置并行 GC 时进行内存回收的线程数
GCTimeRatio	GC 时间占总时间的比率，默认值为99，只在 Parallel Scavenge 收集器的时候生效
MaxGCPauseMillis	设置 GC 最大的停顿时间，只在 Parallel Scavenge 收集器的时候生效
CMSInitiatingOccupancyFraction	设置 CMS 收集器在老年代空间被使用多少后触发垃圾收集，默认是68%，仅在 CMS 收集器上生效
CMSFullGCsBeforeCompaction	设置 CMS 收集器在进行多少次垃圾回收之后启动一次内存碎片整理
UseG1GC	使用 G1 (Garbage First) 垃圾收集器
MaxGCPauseMillis	设置最大GC停顿时间(GC pause time)指标(target). 这是一个软性指标(sox goal), JVM 会尽量去达成这个目标.
G1HeapRegionSize	使用G1时Java堆会被分为大小统一的的区(region)。此参数可以指定每个 heap区的大小. 默认值将根据 heap size 算出最优解. 最小值为 1Mb, 最大值为 32Mb.

2 GC日志分析

2.1日志的含义

GC 日志理解起来十分简单，因为日志本来就是要给开发人员看的，所以设计的很直观。

举个例子，我们来分别说明各个部分所代表的含义：

[GC (Allocation Failure) [PSYoungGen: 6146K->904K(9216K)] 6146K->5008K(19456K), 0.0038730 secs] [Times: user=0.08 sys=0.00, real=0.00 secs]

将上面 GC 日志抽象为各个部分，然后我们再分别说明各个部分的含义

[a(b)[c:d->e(f), g secs] h->i(j), k secs] [Times: user:l sys=m, real=n secs]

a: GC 或者是 Full GC
b: 用来说明发生这次 GC 的原因
c: 表示发生GC的区域，这里表示是新生代发生了GC，上面那个例子是因为在新生代中内存不够给新对象分配了，然后触发了 GC
d: GC 之前该区域已使用的容量
e: GC 之后该区域已使用的容量
f: 该内存区域的总容量
g: 表示该区域这次 GC 使用的时间
h: 表示 GC 前整个堆的已使用容量
i: 表示 GC 后整个堆的已使用容量
j: 表示 Java 堆的总容量
k: 表示 Java堆 这次 GC 使用的时间
l: 代表用户态消耗的 CPU 时间
m: 代表内核态消耗的 CPU 时间
n: 整个 GC 事件从开始到结束的墙钟时间（Wall Clock Time）

2.2 使用ParNew+Serial Old的组合进行内存回收**

设置JVM参数

-Xms20M -Xmx20M -Xmn10M -XX:+UseParNewGC -XX:+PrintGCDetails -XX:SurvivorRatio=8

测试代码

public class TestGCLog01 {
    private static final int _1MB = 1024 * 1024;
    /**
    * VM参数：
    * 1. -Xms20M -Xmx20M -Xmn10M -XX:+UseParNewGC -XX:+PrintGCDetails -XX:SurvivorRatio=8
    */
    public static void testAllocation() {
        byte[] allocation1, allocation2, allocation3, allocation4;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB]; //出现一次 Minor GC
    }
}

打印结果

[GC (Allocation Failure) [ParNew: 6146K->753K(9216K), 0.0065877 secs] 6146K->4849K(19456K),
0.0092108 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
Heap
par new generation total 9216K, used 7220K [0x00000000fec00000, 0x00000000ff600000,
0x00000000ff600000)
eden space 8192K, 78% used [0x00000000fec00000, 0x00000000ff250ea0, 0x00000000ff400000)
from space 1024K, 73% used [0x00000000ff500000, 0x00000000ff5bc488, 0x00000000ff600000)
to space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
tenured generation total 10240K, used 4096K [0x00000000ff600000, 0x0000000100000000,
0x0000000100000000)
the space 10240K, 40% used [0x00000000ff600000, 0x00000000ffa00020, 0x00000000ffa00200,
0x0000000100000000)
Metaspace used 3362K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 369K, capacity 388K, committed 512K, reserved 1048576K
Java HotSpot(TM) 64-Bit Server VM warning: Using the ParNew young collector with the Serial old
collector is deprecated and will likely be removed in a future release

结果分析

通过上面的GC日志我们可以看出一开始出现了 MinorGC, 引起GC的原因是 内存分配失败 ，因为分配allocation的时候，Eden区已经没有足够的区域来分配了，所以发生来本次 MinorGC ，经过 MinorGC 之后新生代的已使用容量从6146K->753K，然而整个堆的内存总量却几乎没有减少，原因就是，由于发现新生代没有可以回收的对象，所以不得不使用内存担保将allocation1～3 三个对象提前转移到老年代。此时再在 Eden 区域为 allocation 分配 4MB 的空间，因此最后我们发现 Eden 区域占用了 4MB，老年代占用了 6MB

2.3 使用Parallel Scavenge+Parallel Old的组合进行内存回收

设置参数:

-Xms20M -Xmx20M -Xmn10M -XX:+UseParallelGC -XX:+PrintGCDetails -XX:SurvivorRatio=8

测试代码

package com.lagou.unit5;
public class TestGCLog02 {
    private static final int _1MB = 1024 * 1024;
    /**
    * VM参数：
    * 2. -Xms20M -Xmx20M -Xmn10M -XX:+UseParallelGC -XX:+UseParallelOldGC -XX:+PrintGCDetails -XX:SurvivorRatio=8
    */
    public static void testAllocation() {
        byte[] allocation1, allocation2, allocation3, allocation4;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB]; //出现一次 Minor GC
    }
    public static void main(String[] args) {
        testAllocation();
    }
}

执行结果

[GC (Allocation Failure) [PSYoungGen: 6146K->872K(9216K)] 6146K->4976K(19456K), 0.0138583 secs]
[Times: user=0.06 sys=0.00, real=0.01 secs]
Heap
PSYoungGen total 9216K, used 7339K [0x00000000ff600000, 0x0000000100000000,
0x0000000100000000)
eden space 8192K, 78% used [0x00000000ff600000,0x00000000ffc50e68,0x00000000ffe00000)
from space 1024K, 85% used [0x00000000ffe00000,0x00000000ffeda020,0x00000000fff00000)
to space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
ParOldGen total 10240K, used 4104K [0x00000000fec00000, 0x00000000ff600000,
0x00000000ff600000)
object space 10240K, 40% used [0x00000000fec00000,0x00000000ff002020,0x00000000ff600000)
Metaspace used 3420K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 371K, capacity 388K, committed 512K, reserved 1048576K

结果分析

2.4 大对象回收分析

大对象直接进入老年代 虚拟机提供一个参数 -XX:PretenureSizeThreshold 用来设置直接在老年代分配的对象的大小，如果对象大于这个值就会直接在老年代分配。这样做的目的是避免在 Eden 区及两个Survivor 区之间发生大量的内存复制。

参数:

-verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+UseParNewGC -XX:+PrintGCDetails -XX:PretenureSizeThreshold=3145728

测试代码

package com.lagou.unit5;
public class TestGCLog03 {
    private static final int _1MB = 1024 * 1024;
    /**
    * VM参数：（参数序号对应实验序号）
    * -Xms20M -Xmx20M -Xmn10M -XX:+UseParNewGC -XX:+PrintGCDetails -XX:PretenureSizeThreshold=3145728
    */
    public static void testPreteureSizeThreshold() {
        byte[] allocation;
        allocation = new byte[4 * _1MB];
    }
    public static void main(String[] args) {
        testPreteureSizeThreshold();
    }
}

执行结果

Heap
par new generation total 9216K, used 2214K [0x00000000fec00000, 0x00000000ff600000,
0x00000000ff600000)
eden space 8192K, 27% used [0x00000000fec00000, 0x00000000fee29be8, 0x00000000ff400000)
from space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
to space 1024K, 0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000)
tenured generation total 10240K, used 4096K [0x00000000ff600000, 0x0000000100000000,
0x0000000100000000)
the space 10240K, 40% used [0x00000000ff600000, 0x00000000ffa00010, 0x00000000ffa00200,
0x0000000100000000)
Metaspace used 3430K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 373K, capacity 388K, committed 512K, reserved 1048576K

结果分析:

通过上面的堆的内存占用情况很容易看出我们分配的4MB大小的对象直接被放到了老年代

3 日志分析工具

3.1日志工具简介

GC日志可视化分析工具GCeasy和GCviewer。通过GC日志可视化分析工具，我们可以很方便的看到JVM各个分代的内存使用情况、垃圾回收次数、垃圾回收的原因、垃圾回收占用的时间、吞吐量等，这些指标在我们进行JVM调优的时候是很有用的。

GCeasy是一款在线的GC日志分析器，可以通过GC日志分析进行内存泄露检测、GC暂停原因分析、JVM配置建

议优化等功能，而且是可以免费使用在线分析工具 https://gceasy.io/index.jsp

GCViewer是一款实用的GC日志分析软件，免费开源使用，你需要安装jdk或者java环境才可以使用。软件为GC日志分析人员提供了强大的功能支持，有利于大大提高分析效率

3.2测试准备

编写代码生成gc.log日志准备分析

package com.lagou.unit5;
import java.util.ArrayList;
public class TestGCLog04 {
    private static final int _1MB = 1024 * 1024;
    /**
    * -Xms100M -Xmx100M -XX:SurvivorRatio=8 -XX:+PrintGCDetails -Xloggc:D://logs/gc.log
    */
    public static void main(String[] args) {
        ArrayList < byte[] > list = new ArrayList < byte[] > ();
        for(int i = 0; i < 500; i++) {
            byte[] arr = new byte[1024 * 100];
            list.add(arr);
            try {
                Thread.sleep(20);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }
    }
}

在d:/logs/gc.log 生成日志

Java HotSpot(TM) 64-Bit Server VM (25.162-b12) for windows-amd64 JRE (1.8.0_162-b12), built on Dec
19 2017 20:00:03 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16454268k(6068260k free), swap 32906696k(20647740k free)
CommandLine flags: -XX:InitialHeapSize=104857600 -XX:MaxHeapSize=104857600 -XX:+PrintGC -
XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
5.291: [GC (Allocation Failure) [PSYoungGen: 27642K->3064K(30720K)] 27642K->24839K(99328K),
0.2011370 secs] [Times: user=0.64 sys=0.01, real=0.20 secs]
Heap
PSYoungGen total 30720K, used 29578K [0x00000000fdf00000, 0x0000000100000000,
0x0000000100000000)
eden space 27648K, 95% used [0x00000000fdf00000,0x00000000ff8e4748,0x00000000ffa00000)
from space 3072K, 99% used [0x00000000ffa00000,0x00000000ffcfe1b0,0x00000000ffd00000)
to space 3072K, 0% used [0x00000000ffd00000,0x00000000ffd00000,0x0000000100000000)
ParOldGen total 68608K, used 21775K [0x00000000f9c00000, 0x00000000fdf00000,
0x00000000fdf00000)
object space 68608K, 31% used [0x00000000f9c00000,0x00000000fb143d50,0x00000000fdf00000)
Metaspace used 3947K, capacity 4568K, committed 4864K, reserved 1056768K
class space used 434K, capacity 460K, committed 512K, reserved 1048576K

3.3 GCeasy

这是一个在线分析日志的工具，主要功能是免费的，存在部分收费，地址： https://gceasy.io/

把上篇博客生成的日志文件，上传分析，就会接到可视化界面

jvm堆：

Allocated：各部分分配大小

Peak：峰值内存使用量

关键绩效指标：

吞吐量：93.769%，运行应用程序的时间/(GC时间的比值+运行应用程序的时间)

平均GC停顿时间

最大GC停顿时间

GC停顿持续时间范围：时间范围、GC数量、百分百

交互式图表：

左边菜单有很多：

GC之前的堆、GC之后的堆、GC持续时间、GC停顿持续时间、回收的内存字节、Young区内存变化、Old区内存变化、Metaspace内存变化、分配对象大小、对象从Young到Old内存大小变化后序的内容有：GC统计信息、Minor GC/Full GC信息、内存泄漏、GC的原因等等，所以这个工具的功能真的很强大

我们可以对比一下，Parallel、CMS、G1的GC效率

3.4 GCViewer

GCViewer是一个小工具，可以可视化展示 生成的详细GC输出。支持Sun / Oracle，IBM，HP和BEA的Java虚拟机。它是GNU LGPL下发布的免费软件。

下载： https://sourceforge.net/projects/gcviewer /

使用简介：

java -jar gcviewer-1.37-SNAPSHOT.jar

打开之后，点击File->Open File打开我们的GC日志，可以看到如下图，图标是可以放大缩小的，主要内容就是红线圈住的部分，里面的内容跟上面的GCeasy的比较类似，具体的可以看下GitHub中的描述。