分析GC日志

Posted on 2021-02-17 Edited on 2024-07-22 In 后端 , JVM Views: Word count in article: 1.7k Reading time ≈ 2 mins.

1、GC日志格式

1.1 GC分类

针对HotSpot VM的实现，它里面的GC按照回收区域又分为两大种类型：一种是部分收集（Partial GC），一种是整堆收集（Full GC）。
- 部分收集：不是完整收集整个Java堆的垃圾收集。其中又分为：
  - 新生代收集（Minor GC/Young GC）：只是新生代（Eden\S0，S1）的垃圾收集。
  - 老年代收集（Major GC/Old GC）：只是老年代的垃圾收集。
    - 目前，只有CMS GC会有单独收集老年代的行为。
    - 注意，很多时候MajorGC会和Full GC混淆使用，需要具体分辨是老年代回收还是整堆回收。
  - 混合收集（Mixed GC）：收集整个新生代以及部分老年代的垃圾收集。
    - 目前，只有G1 GC会有这种行为。
- 整堆收集（Full GC）：收集整个java堆和方法区的垃圾收集。

1.2 GC日志分类

MinorGC（或young GC或YGC）日志：

1	[GC (Allocation Failure) [PSYoungGen: 16383K->2020K(18432K)] 16383K->13992K(59392K), 0.0134292 secs] [Times: user=0.00 sys=0.01, real=0.01 secs]

Full GC日志：

[Full GC (Ergonomics) [PSYoungGen: 1984K->0K(18432K)] [ParOldGen: 28282K->30116K(40960K)] 30266K->30116K(59392K), [Metaspace: 3819K->3819K(1056768K)], 0.0198203 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]

1.3 GC日志结构

垃圾收集器：
- 使用Serial收集器在新生代的名字是Default New Generation，因此显示的是”[DefNew”。
- 使用ParNew收集器在新生代的名字会变成”[ParNew”，意思是”Parallel New Generation”。
- 使用Parallel Scavenge收集器在新生代的名字是”[PSYoungGen”，这里的JDK1.7使用的就是PSYoungGen。
- 使用Parallel Old Generation收集器在老年代的名字是”[ParoldGen”。
- 使用G1收集器的话，会显示为”garbage-first heap”。
GC前后情况：
- GC日志格式的规律一般都是：GC前内存占用一>GC后内存占用（该区域内存总大小）
  1
  [PSYoungGen: 16383K->2020K(18432K)] 16383K->13992K(59392K)
  - 中括号内：GC回收前年轻代堆大小->回收后大小（年轻代堆总大小）
  - 括号外：GC回收前年轻代和老年代大小->回收后大小（年轻代和老年代总大小）
GC时间：
- GC日志中有三个时间：user，sys和real。
  1
  [Times: user=0.00 sys=0.01, real=0.01 secs]
  - user-进程执行用户态代码（核心之外）所使用的时间。这是执行此进程所使用的实际CPU时间，其他进程和此进程阻塞的时间并不包括在内。在垃圾收集的情况下，表示GC线程执行所使用的CPU总时间。
  - sys-进程在内核态消耗的CPU时间，即在内核执行系统调用或等待系统事件所使用的CPU时间。
  - real-程序从开始到结束所用的时钟时间。这个时间包括其他进程使用的时间片和进程阻塞的时间（比如等待I/O完成）。对于并行gc，这个数字应该接近（用户时间+系统时间）除以垃圾收集器使用的线程数。
- 由于多核的原因，一般的GC事件中，real time是小于sys +user time的，因为一般是多个线程并发的去做GC，所以real time是要小于sys+usertime的。如果real>sys+user的话，则你的应用可能存在下列问题：I0负载非常重或者是CPU不够用。