GC日志详解
配置 GC 日志输出
对于java应用我们可以通过一些配置把程序运行过程中的gc日志全部打印出来，然后分析gc日志得到关键性指标，分析GC原因，调优JVM参数。
打印GC日志方法，在JVM参数里增加参数，%t 代表时间
-Xloggc:./gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M
参数详解
-Xloggc:./gc-%t.log：将 GC 日志输出到当前目录，日志文件名以 gc- 开头，后跟当前时间戳。-XX:+PrintGCDetails：打印详细的 GC 日志信息。-XX:+PrintGCDateStamps：在 GC 日志中打印日期时间戳。-XX:+PrintGCTimeStamps：在 GC 日志中打印时间戳。-XX:+PrintGCCause：在 GC 日志中打印 GC 原因。-XX:+UseGCLogFileRotation：当 GC 日志文件达到指定大小时自动进行轮换。-XX:NumberOfGCLogFiles=10：指定 GC 日志文件最大数量为 10。-XX:GCLogFileSize=100M：指定单个 GC 日志文件的最大大小为 100MB。
分析GC日志
运行程序加上对应gc日志
java -jar -Dserver.port=8100 -Xloggc:./gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M /home/demotest.jar
下图中是我截取的JVM刚启动的一部分GC日志
我们可以看到图中第一行红框，是项目的配置参数。这里不仅配置了打印GC日志，还有相关的VM内存参数。
第二行红框中的是在这个GC时间点发生GC之后相关GC情况。
1、对于2.909： 这是从jvm启动开始计算到这次GC经过的时间，前面还有具体的发生时间日期。
2、Full GC(Metadata GC Threshold)指这是一次full gc，括号里是gc的原因， PSYoungGen是年轻代的GC，ParOldGen是老年代的GC，Metaspace是元空间的GC
3、 6160K->0K(141824K)，这三个数字分别对应GC之前占用年轻代的大小，GC之后年轻代占用，以及整个年轻代的大小。
4、112K->6056K(95744K)，这三个数字分别对应GC之前占用老年代的大小，GC之后老年代占用，以及整个老年代的大小。
5、6272K->6056K(237568K)，这三个数字分别对应GC之前占用堆内存的大小，GC之后堆内存占用，以及整个堆内存的大小。
6、20516K->20516K(1069056K)，这三个数字分别对应GC之前占用元空间内存的大小，GC之后元空间内存占用，以及整个元空间内存的大小。
7、0.0209707是该时间点GC总耗费时间。
从日志可以发现几次fullgc都是由于元空间不够导致的，所以我们可以将元空间调大点
java -jar -Dserver.port=8100 -Xloggc:./gc-%t.log -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M /home/demotest.jar
调整完我们再看下gc日志发现已经没有因为元空间不够导致的fullgc了
使用其他垃圾收集测试
对于CMS和G1收集器的日志会有一点不一样，也可以试着打印下对应的gc日志分析下，可以发现gc日志里面的gc步骤跟我们之前讲过的步骤是类似的
public class HeapTest {
byte[] a = new byte[1024 * 100]; //100KB
public static void main(String[] args) throws InterruptedException {
ArrayList<HeapTest> heapTests = new ArrayList<>();
while (true) {
heapTests.add(new HeapTest());
Thread.sleep(10);
}
}
}
CMS
-Xloggc:d:/gc-cms-%t.log -Xms50M -Xmx50M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M
-XX:+UseParNewGC -XX:+UseConcMarkSweepGC
G1
-Xloggc:d:/gc-g1-%t.log -Xms50M -Xmx50M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M -XX:+UseG1GC
利用gceasy分析gc日志
上面的这些参数，能够帮我们查看分析GC的垃圾收集情况。但是如果GC日志很多很多，成千上万行。就算你一目十行，看完了，脑子也是一片空白。所以我们可以借助一些功能来帮助我们分析，这里推荐一个gceasy(https://gceasy.io)，可以上传gc文件，然后他会利用可视化的界面来展现GC情况。具体下图所示
上图我们可以看到年轻代，老年代，以及永久代的内存分配，和最大使用情况。
上图我们可以看到堆内存在GC之前和之后的变化，以及其他信息。
这个工具还提供基于机器学习的JVM智能优化建议，当然现在这个功能需要付费
JVM参数汇总查看命令
java -jar -Dserver.port=8100 -Xloggc:./gc-%t.log -XX:+PrintFlagsInitial -XX:+PrintFlagsFinal -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M /home/demotest.jar
java -XX:+PrintFlagsInitial 表示打印出所有参数选项的默认值
java -XX:+PrintFlagsFinal 表示打印出所有参数选项在运行程序时生效的值
