JVM性能优化之GC日志分析

JVM性能优化之GC日志分析

---

前言

任何项目日志都是一个非常重要的部分，同样GC日志也是在垃圾回收中相当重要的，我们想要对JVM优化，首先要知道优化哪个地方，怎么找到需要优化的部位就需要读懂GC日志，通过GC日志来分析当前应用再某些情况下的缺点。

一、GC日志参数

要想分析GC日志，首先我们需要收集日志，收集什么呢？我们可以根据自己需要分析的内容去配置相应的参数，让GC日志按照固定的格式打印出相关的内容，这样日志数据就非常清晰了。

GC日志参数

这是一些常见的GC日志参数：

参数	说明
-XX:+PrintGC	打印简单GC日志
-XX:+PrintGCDetails	打印GC详细信息
-XX:+PrintGCTimeStamps	输出GC的时间戳（以基准时间的形式）
-XX:+PrintGCDateStamps	输出GC的时间戳（以日期的形式）
-XX:+PrintGCApplicationStoppedTime	打印由GC日志产生的停顿时间
-XX:+UseGCLogFileRotation	滚动打印日志
-XX:+PrintHeapAtGC	在进行GC的前后打印出堆的信息
-Xloggc:文件路径	指定输出路径收集日志到日志文件

下面我们写段多线程创建对象的代码来看一下

public static void main(String[] args){
   for (int i = 0; i < 20; i++) {
       new Thread(()-> {
           List list = new ArrayList();
           for (int j = 0; j < 100000; j++) {
               list.add(new Object());
           }
       }).start();
   }
}

配置JVM参数(设置内存大小，打印详细日志、时间戳以及将GC日志输出到文件，这里需要注意日志路径文件夹必须手动创建好，否则报错找不到文件路径)：

-Xms32m -Xmx32m -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:F:/logs/gc.log

看一下gc.log中打印出来的日志

有点模糊，我们找出其中一条格式化后看一下具体的信息，最下面每个区的内存使用情况

2022-03-04T22:02:31.166+0800: 0.552: //这是时间戳信息
[Full GC  //这是触发的GC类型
(Ergonomics) //这是GC触发的原因
[PSYoungGen: 16080K->6148K(18944K)]  //这是新生代的信息，回收前的大小->回收后的大小(总大小)
[ParOldGen: 38844K->43780K(44032K)] //这是老年代的信息，回收前的大小->回收后的大小(总大小)
54924K->49929K(62976K),  //这是堆的信息，回收前的大小->回收后的大小(总大小)
[Metaspace: 4247K->4247K(1056768K)], //这是元空间的信息，回收前的大小->回收后的大小(总大小)
 0.1793855 secs] //这是本次GC耗时时间
[Times: user=0.72 sys=0.00, real=0.18 secs] //GC耗时具体  用户时间  系统时间 实际时间

常用的垃圾收集器配置

下面是一些常用的垃圾收集器配置：

参数	说明
UseSerialGC	使用Serial+Serial Old 收集器组合进行内存回收
UseParNewGC	使用 ParNew + Serial Old 收集器组合进行内存回收
UseConcMarkSweepGC	使用 ParNew + CMS + Serial Old 的收集器组合进行内存回收
UseParallelOldGC	使用 Parallel Scavenge + Parallel Old 的收集器组合
UseParallelGC	使用 Parallel Scavenge + Serial Old 的收集器组合
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)
G1HeapRegionSize	指定G1收集器每个heap区的大小，默认值将根据 heap size 算出最优解. 最小值为1Mb, 最大值为32Mb
-XX:PretenureSizeThreshold	在老年代分配的对象大小，如果大于该值则进入老年代

具体的垃圾收集器可以看前面的博客简单说明了几个常用的垃圾收集器。
使用如下：例如将GC设置为G1收集器，

-XX:+UseG1GC

我们再看一下执行后产生的日志，其他垃圾收集器产生的日志跟上面一样，G1垃圾收集器产生的格式不一样

具体的啥含义可以看这篇博客https://blog.csdn.net/zhanggang807/article/details/46011341

大对象回收

对于大对象提供了一个配置参数 -XX:PretenureSizeThreshold 如果大于该参数会直接进入到老年代来分配对象的空间，因为对象比较大新生代中来回的进行复制比较消耗性能。
设置参数：

-XX:PretenureSizeThreshold=5242880 //当对象占内存大于5M放到老年代

测试代码，创建3个10M的大对象

 public static void main(String[] args){
      byte[]  bigObject = new byte[10 * 1024*1024];
      byte[]  bigObject1 = new byte[10 * 1024*1024];
      byte[]  bigObject2 = new byte[10 * 1024*1024];
  }

可以看出来新生代的使用大小为不到3M，老年代的使用大小为30M+，所以三个10M的大对象都放到了老年代。

二、GC日志分析工具

同样的看GC日志是比较麻烦的，我们希望有一个可视化工具可以以图表的形式来展现GC日志信息，下面就介绍款GC日志分析工具。

GCeasy

GCeasy是一款比较好用的在线GC日志分析工具，以可视化图表的形式展现了GC日志的详细信息，其网址

https://gceasy.io/diamondgc-report.jsp?oTxnId_value=b8ca4d3d-3f5b-4d10-b5a2-d386d0d6d271

在网页上我们选中上面产生的GC日志，然后点击分析会看到下面几个分析图表。

JVM memory size

这一部分是JVM内存大小，Generation是JVM区域，Allocated指的是每部分分配的大小，Peak指的是峰值时候的内存使用情况。分别有新生代、老年代、元空间和总内存大小的统计信息。右面是对左边表格数据的可视化。

Key Performance Indicators

这一部分是关键指标，Throughput指的是GC的吞吐量，因为我们写的是循环一直创建对象，所以一直在执行垃圾回收，吞吐量才2.377%；再下面是GC回收期间的平均停顿时间和最大停顿时间；再下面是GC执行的时间范围和数量统计以及占用总GC数量统计的百分比，我们可以看到执行时间为0~100ms的GC总共执行了191次，占比为94.09%。右面就是GC执行占比的柱状图显示

Interactive Graphs

这一部分是图表统计，主要有这几方面的统计：回收后堆内存大小折线图、回收前堆内存大小折线图、GC执行时间分布图散点图、GC回收掉的对象占用空间大小的散点图、新生代回收内存情况的折线图、老年代回收内存情况的折线图、元区间回收内存情况的折线图以及堆内存分配和晋升情况(新生代对象晋升为老年代对象)散点图。

GC Statistics

这部分是GC的统计情况，第一个图是Minor GC和Full GC回收对象的大小；第二幅图为GC执行的总时间；第三幅图为GC执行的平均时间；
后面的四个表格分别是GC统计信息、Minor GC统计信息、Full GC统计信息以及GC执行暂停统计信息。

Object Stats

这是对象的统计信息，分别为总共创建的对象大小，新生代晋升老年代的对象大小，平均每秒创建的对象大小和平局每秒晋升的对象大小。

Memory Leak

这里是统计的内存泄漏信息，我们写的代码中没有内存泄漏的情况所以就没有结果

GC Causes

这一部分是GC花费的时间信息，前面是GC执行的原因，后面为他们的统计信息。

除了这些之外还有其他的信息，我们的GC执行日志没有对应的结果就不一一展示了。