JVM-（十五）GC日志

本文最后更新于：May 13, 2023 pm

积土成山，风雨兴焉；积水成渊，蛟龙生焉；积善成德，而神明自得，圣心备焉。故不积跬步，无以至千里，不积小流无以成江海。齐骥一跃，不能十步，驽马十驾，功不在舍。面对悬崖峭壁，一百年也看不出一条裂缝来，但用斧凿，能进一寸进一寸，能进一尺进一尺，不断积累，飞跃必来，突破随之。

目录

GC日志分析

内存分配与垃圾回收的参数列表：

运行代码：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
package com;


import java.util.ArrayList;
import java.util.List;

/**
 * @Author DragonOne
 * @Date 2022/4/25 15:04
 * @墨水记忆 www.tothefor.com
 */
public class AllStu {
  public static void main(String[] args) {

    List<byte[]> list = new ArrayList<>();
    for(int i=1;i<=100;++i){
      list.add(new byte[1024*100]);
    }

  }
}
  • -XX:+PrintGC：输出GC日志。类似：-verbose:gc

JVM参数配置：

1
-Xms20m -Xmx20m -XX:+PrintGC

输出：

1
2
3
[GC (Allocation Failure)  5614K->4296K(19968K), 0.0033189 secs]
[GC (Allocation Failure)  9876K->9793K(19968K), 0.0040851 secs]
[Full GC (Ergonomics)  9793K->9591K(19968K), 0.0060989 secs]
  • -XX:+PrintGCDetails：输出GC的详细日志。

JVM参数配置：

1
-Xms20m -Xmx20m -XX:+PrintGCDetails

输出：

1
2
3
4
5
6
7
8
9
10
11
12
13
[GC (Allocation Failure) [PSYoungGen: 5601K->504K(6144K)] 5601K->4396K(19968K), 0.0037385 secs] [Times: user=0.01 sys=0.01, real=0.01 secs] 
[GC (Allocation Failure) [PSYoungGen: 6071K->504K(6144K)] 9964K->9905K(19968K), 0.0026925 secs] [Times: user=0.01 sys=0.02, real=0.00 secs] 
[Full GC (Ergonomics) [PSYoungGen: 504K->0K(6144K)] [ParOldGen: 9401K->9782K(13824K)] 9905K->9782K(19968K), [Metaspace: 3156K->3156K(1056768K)], 0.0104482 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
Heap
 PSYoungGen      total 6144K, used 766K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 13% used [0x00000007bf980000,0x00000007bfa3fa30,0x00000007bff00000)
  from space 512K, 0% used [0x00000007bff80000,0x00000007bff80000,0x00000007c0000000)
  to   space 512K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007bff80000)
 ParOldGen       total 13824K, used 9782K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 70% used [0x00000007bec00000,0x00000007bf58db78,0x00000007bf980000)
 Metaspace       used 3163K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 340K, capacity 388K, committed 512K, reserved 1048576K

  • -XX:+PrintGCTimeStamps：输出GC的时间戳（以基准时间的形式）。

JVM参数配置：

1
-Xms20m -Xmx20m -XX:+PrintGCDetails -XX:+PrintGCTimeStamps

输出：

1
2
3
4
5
6
7
8
9
10
11
12
13
0.196: [GC (Allocation Failure) [PSYoungGen: 5614K->504K(6144K)] 5614K->4341K(19968K), 0.0015160 secs] [Times: user=0.00 sys=0.01, real=0.00 secs] 
0.198: [GC (Allocation Failure) [PSYoungGen: 6071K->484K(6144K)] 9908K->9930K(19968K), 0.0022234 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 
0.200: [Full GC (Ergonomics) [PSYoungGen: 484K->0K(6144K)] [ParOldGen: 9445K->9687K(13824K)] 9930K->9687K(19968K), [Metaspace: 3180K->3180K(1056768K)], 0.0052203 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
Heap
 PSYoungGen      total 6144K, used 903K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 16% used [0x00000007bf980000,0x00000007bfa61d78,0x00000007bff00000)
  from space 512K, 0% used [0x00000007bff80000,0x00000007bff80000,0x00000007c0000000)
  to   space 512K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007bff80000)
 ParOldGen       total 13824K, used 9687K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 70% used [0x00000007bec00000,0x00000007bf575de0,0x00000007bf980000)
 Metaspace       used 3191K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 347K, capacity 388K, committed 512K, reserved 1048576K

主要区别是前面几行的前面显示的数字。下同。

  • -XX:+PrintGCDateStamps：输出GC的时间戳（以日期的形式，包含日期和时间）。

JVM参数配置：

1
-Xms20m -Xmx20m -XX:+PrintGCDetails -XX:+PrintGCDateStamps

输出：

1
2
3
4
5
6
7
8
9
10
11
12
13
2022-06-23T14:19:14.031+0800: [GC (Allocation Failure) [PSYoungGen: 5614K->504K(6144K)] 5614K->4281K(19968K), 0.0029828 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 
2022-06-23T14:19:14.035+0800: [GC (Allocation Failure) [PSYoungGen: 6071K->484K(6144K)] 9848K->9878K(19968K), 0.0036393 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 
2022-06-23T14:19:14.039+0800: [Full GC (Ergonomics) [PSYoungGen: 484K->0K(6144K)] [ParOldGen: 9393K->9684K(13824K)] 9878K->9684K(19968K), [Metaspace: 3161K->3161K(1056768K)], 0.0059208 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
Heap
 PSYoungGen      total 6144K, used 903K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 16% used [0x00000007bf980000,0x00000007bfa61d18,0x00000007bff00000)
  from space 512K, 0% used [0x00000007bff80000,0x00000007bff80000,0x00000007c0000000)
  to   space 512K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007bff80000)
 ParOldGen       total 13824K, used 9684K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 70% used [0x00000007bec00000,0x00000007bf575010,0x00000007bf980000)
 Metaspace       used 3186K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 346K, capacity 388K, committed 512K, reserved 1048576K

  • -XX:+PrintHeapAtGC：在进行GC的前后打印出堆的信息。

JVM参数配置：

1
-Xms20m -Xmx20m -XX:+PrintGCDetails -XX:+PrintHeapAtGC

输出：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
{Heap before GC invocations=1 (full 0):
 PSYoungGen      total 6144K, used 5614K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 99% used [0x00000007bf980000,0x00000007bfefb988,0x00000007bff00000)
  from space 512K, 0% used [0x00000007bff80000,0x00000007bff80000,0x00000007c0000000)
  to   space 512K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007bff80000)
 ParOldGen       total 13824K, used 0K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 0% used [0x00000007bec00000,0x00000007bec00000,0x00000007bf980000)
 Metaspace       used 3155K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 339K, capacity 388K, committed 512K, reserved 1048576K
[GC (Allocation Failure) [PSYoungGen: 5614K->504K(6144K)] 5614K->4333K(19968K), 0.0051174 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 6144K, used 504K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 0% used [0x00000007bf980000,0x00000007bf980000,0x00000007bff00000)
  from space 512K, 98% used [0x00000007bff00000,0x00000007bff7e030,0x00000007bff80000)
  to   space 512K, 0% used [0x00000007bff80000,0x00000007bff80000,0x00000007c0000000)
 ParOldGen       total 13824K, used 3829K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 27% used [0x00000007bec00000,0x00000007befbd468,0x00000007bf980000)
 Metaspace       used 3155K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 339K, capacity 388K, committed 512K, reserved 1048576K
}
{Heap before GC invocations=2 (full 0):
 PSYoungGen      total 6144K, used 6071K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 98% used [0x00000007bf980000,0x00000007bfeefe30,0x00000007bff00000)
  from space 512K, 98% used [0x00000007bff00000,0x00000007bff7e030,0x00000007bff80000)
  to   space 512K, 0% used [0x00000007bff80000,0x00000007bff80000,0x00000007c0000000)
 ParOldGen       total 13824K, used 3829K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 27% used [0x00000007bec00000,0x00000007befbd468,0x00000007bf980000)
 Metaspace       used 3155K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 339K, capacity 388K, committed 512K, reserved 1048576K
[GC (Allocation Failure) [PSYoungGen: 6071K->452K(6144K)] 9900K->9881K(19968K), 0.0047050 secs] [Times: user=0.02 sys=0.02, real=0.01 secs] 
Heap after GC invocations=2 (full 0):
 PSYoungGen      total 6144K, used 452K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 0% used [0x00000007bf980000,0x00000007bf980000,0x00000007bff00000)
  from space 512K, 88% used [0x00000007bff80000,0x00000007bfff1010,0x00000007c0000000)
  to   space 512K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007bff80000)
 ParOldGen       total 13824K, used 9429K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 68% used [0x00000007bec00000,0x00000007bf5357e8,0x00000007bf980000)
 Metaspace       used 3155K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 339K, capacity 388K, committed 512K, reserved 1048576K
}
{Heap before GC invocations=3 (full 1):
 PSYoungGen      total 6144K, used 452K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 0% used [0x00000007bf980000,0x00000007bf980000,0x00000007bff00000)
  from space 512K, 88% used [0x00000007bff80000,0x00000007bfff1010,0x00000007c0000000)
  to   space 512K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007bff80000)
 ParOldGen       total 13824K, used 9429K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 68% used [0x00000007bec00000,0x00000007bf5357e8,0x00000007bf980000)
 Metaspace       used 3155K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 339K, capacity 388K, committed 512K, reserved 1048576K
[Full GC (Ergonomics) [PSYoungGen: 452K->0K(6144K)] [ParOldGen: 9429K->9682K(13824K)] 9881K->9682K(19968K), [Metaspace: 3155K->3155K(1056768K)], 0.0149688 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
Heap after GC invocations=3 (full 1):
 PSYoungGen      total 6144K, used 0K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 0% used [0x00000007bf980000,0x00000007bf980000,0x00000007bff00000)
  from space 512K, 0% used [0x00000007bff80000,0x00000007bff80000,0x00000007c0000000)
  to   space 512K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007bff80000)
 ParOldGen       total 13824K, used 9682K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 70% used [0x00000007bec00000,0x00000007bf574b68,0x00000007bf980000)
 Metaspace       used 3155K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 339K, capacity 388K, committed 512K, reserved 1048576K
}
Heap
 PSYoungGen      total 6144K, used 903K [0x00000007bf980000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 5632K, 16% used [0x00000007bf980000,0x00000007bfa61d18,0x00000007bff00000)
  from space 512K, 0% used [0x00000007bff80000,0x00000007bff80000,0x00000007c0000000)
  to   space 512K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007bff80000)
 ParOldGen       total 13824K, used 9682K [0x00000007bec00000, 0x00000007bf980000, 0x00000007bf980000)
  object space 13824K, 70% used [0x00000007bec00000,0x00000007bf574b68,0x00000007bf980000)
 Metaspace       used 3170K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 342K, capacity 388K, committed 512K, reserved 1048576K

  • -Xloggc:./logs/gc.log：日志文件的输出路径。可以把GC日志保存到文件中。这里的相对位置不是相对当前运行的文件，而是项目的位置，所以创建文件夹logs时需要建立在项目名称的文件夹目录下。

JVM参数配置：

1
-Xms20m -Xmx20m -XX:+PrintGCDetails -Xloggc:./logs/gc.log

然后查看文件即可。

📢注意：必须要先建logs文件夹，并且相对位置是项目，而不是运行的代码文件处！！！

日志补充说明

  • “ [ GC”和” [ Full GC”说明了这次垃圾收集的停顿类型，如果有”Full”则说明GC发生了STW。
  • 使用Serial收集器在新生代的名字是Default New Generation，因此显示的是” [ DefNew”。
  • 使用ParNew收集器在新生代的名字会变成” [ ParNew”，意思是”Parallel New Generation”。
  • 使用Parallel Scavenge收集器在新生代的名字是 “ [ PSYoungGen”。
  • 老年代的收集器和新生代道理一样，名字也是收集器决定的。
  • 使用G1收集器的话，会显示为” [ garbage-first heap”。
  • Allocation Failure：表明本次引起GC的原因是因为在年轻代中没有足够的空间能够存储新的数据了。
  • [ PSYoungGen：5986K -> 696K(8704K) ] 5986K-> 704K(9216K)：中括号：GC回收前年轻代大小，回收后大小，(年轻代总大小)；括号外：GC回收前年轻代和老年代大小，回收后大小，（年轻代和老年代总大小）
  • user代表用户态回收耗时，sys内核态回收耗时，rea实际耗时。由于多核的原因，时间总和可能会超过real时间。部分输出：
1
2
3
[GC (Allocation Failure) [PSYoungGen: 5614K->484K(6144K)] 5614K->4353K(19968K), 0.0019891 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 

[Full GC (Ergonomics) [PSYoungGen: 500K->0K(6144K)] [ParOldGen: 9469K->9782K(13824K)] 9970K->9782K(19968K), [Metaspace: 3156K->3156K(1056768K)], 0.0071729 secs] [Times: user=0.03 sys=0.00, real=0.00 secs]

GC：

Full GC：

![](/Users/dragonone/Library/Application Support/typora-user-images/image-20220623160540852.png)

GC日志分析工具

在线分析日志文件网站，GCEasy 。在上传文件时，选择上面最后一个参数生成的日志文件即可。使用如下图：