分析GC日志

一、GC日志参数

查看文章：JVM运行时参数_liming0025的专栏-CSDN博客一、JVM参数选项类型1、类型1:标准参数选项特点比较稳定，各版本差距不到以 - 开头各种选项运行java或者java -help可以查看全部的标准选项补充内容-server与-client2、类型2:-X参数选项特点非标准化参数功能还是比较稳定的，但是可能会改变以 -X 开头各种选项运行java -X 命令可以看到所有X选项JVM的JIT编译模式相关的选项特别地3、类型3:-XX参数选项二、添加JVM参数选项https://blog.csdn.net/liming0025/article/details/122515176

二、GC日志格式

1、GC分类

针对HotSpot VM的实现，它里面的GC按照回收区域又分为两种类型：一种是部分收集（Partial GC），一种是整堆收集（Full GC）

• 部分收集：不是完整的收集整个JVM堆的垃圾收集
  • 新生代收集（Young GC\Minor GC）：只是新生代（Eden、S1、S0）的垃圾收集
  • 老年代收集（Old GC\Major GC）：只是老年代的垃圾收集
    • 目前只有CMS GC 会对单独老年代进行收集
    • 注意，很多时候Major GC和Full GC混合使用，需要集体分析是老年代还是整堆收集
  • 混合收集（Mixed GC）：整个新生代和部分老年代的垃圾收集
    • 目前只有G1 GC会有这种行为
• 整堆收集（Full GC）：收集整个java堆和方法区的垃圾收集
  • 老年代空间不足
  • 方法区空间不足
  • System.gc()
  • Young GC，进入老年代平均大小大于老年代的可用空间
  • 大对象直接进入老年代，而老年代可用空间不足

2、GC日志分类

1、Minor GC

2、Full GC

3、GC日志结构剖析

[Times：user=0.00 sys=0.00, real=0.00 secs]

GC回收有三个时间：user、sys、real

• user：进程进入用户态代码所用的时间，这是执行此进程所使用的实际CPU时间，其它进程和此进程阻塞时间不包括在内。在垃圾收集的情况下，表示GC线程执行所用的时间CPU总和。
• sys：进程在内核态消耗的CPU时间，即在内核执行系统调用或等待系统事件所使用的CPU时间
• real：程序从开始到结束所用的时钟时间。这个时间包括其它进程使用的时间片和进程阻塞的时间。对于并行GC，这个数字应该接近于（用户时间+系统时间）/垃圾回收线程数

由于多核的原因，一般GC时间中，real<user+sys，因为一般是多线程并发的去做GC，所以real是要小于sys+user的。如果real>user+sys的话，证明应用可能存在IO负载很高或者CPU不够用。

4、Minor GC 日志解析

2022-01-16T15:25:15.896-0800: 0.164: [GC (Allocation Failure) [PSYoungGen: 912K->464K(1024K)] 912K->464K(1536K), 0.0106649 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 

• 2022-01-16T15:25:15.896-0800：日志时间打印
• 0.164：GC发生时，JVM起来以来经历的秒数
• [GC (Allocation Failure)：发生了一次垃圾回收，这个是Minor GC。它不区分新生代GC还是老年代GC，括号里面内容是发生GC原因，例子中原因是新生代没有足够的区域能够存放需要分配的数据而失败
• PSYoungGen: 912K->464K(1024K)]
  • PSYoungGen：表示发生GC的区域，区域名称与使用GC收集器是密切相关的
    • Serial收集器：DefNew
    • ParNew收集器：ParNew
    • Prarllel Sacnvenge收集器：PSYoung
    • 老年代和年轻代同理
  • 912K->464K(1024K)：GC前使用容量->GC后使用容量（总容量）
    • 如果是新生代，总容量则会显示整个新生代的9/10，即Eden+S1/S0区
    • 如果是老年代，总容量会显示全部内存大小，无变化
• 912K->464K(1536K)：在显示区域容量GC情况后，会接着显示整个堆内存区域的GC情况，GC前堆内存已使用容量->GC后堆内容量（堆内存总容量）
  • 堆内存总容量=9/10新生代+老年代<初始化内存大小
• 0.0106649 secs：整个GC花费的时间，单位是秒
• [Times: user=0.00 sys=0.00, real=0.01 secs] 
  • user：用户态花费时间
  • sys：内核态花费时间
  • real：此次GC花费总时间

5、Full GC 日志解析

2022-01-16T15:25:15.976-0800: 0.245: [Full GC (Ergonomics) [PSYoungGen: 512K->417K(1024K)] [ParOldGen: 351K->120K(512K)] 863K->537K(1536K), [Metaspace: 2807K->2807K(1056768K)], 0.0047681 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 

• 2022-01-16T15:25:15.976-0800：同上
• 0.245：同上
• Full GC (Ergonomics)
  • 发生了一次垃圾回收，这次是Full GC，它不区分新生代GC还是老年代GC
  • 括号里的内容是GC发生的原因
    • Metadata GC Threshold：元空间不够用
    • Ergonomics：JVM自适应调整导致GC
    • System：调用System.gc()方法
• [PSYoungGen: 512K->417K(1024K)]：同上
• [ParOldGen: 351K->120K(512K)] ：同新生代
• 863K->537K(1536K)：同上
• [Metaspace: 2807K->2807K(1056768K)]：同新生代
• 0.0047681 secs：同上
• [Times: user=0.01 sys=0.00, real=0.01 secs] ：同上

三、GC日志分析工具

1、GCEasy

在线的GC日志分析工具

Universal JVM GC analyzer - Java Garbage collection log analysis made easy

方法区OOM：

老年代OOM：

 

2、GCViewer

离线的分析工具，下载即可，直接运行jar文件

3、其它工具

• GChisto：维护较少，存在很多BUG
• HPjmeter：很强大的工具，只能打开由一下参数生成的GC log，-verbose:gc -Xlogggc:gc.log