三分钟带你看懂 GC 日志!

开发 前端
在 jdk1.8 及之后的版本中,-XX:+UseParallelGC和-XX:+UseParallelOldGC​参数效果是一样的,都是用的 Parallel Old 作为老年代收集器;而在 jdk1.7 及之后的版本中,-XX:+UseParallelGC参数用的是 Serial Old 作为老年代收集器。

01、背景介绍

那么如何分析当前虚拟机性能呢?其中 GC 日志起到至关重要的作用。

实际上,每种垃圾收集器都有它独立的日志格式,尽管如此,虚拟机为了方便用户阅读,将各个收集器的日志都维持在一定的共性状态。

下面我们一起来看看不同的垃圾收集器,相关的 GC 日志内容。

本文是基于 JDK 1.8 版本运行,可能不同的版本各个内存区域的名称略有不同,对知识的理解不会产生明显的误区。

02、触发GC时机

通常,GC 触发的条件有两种:

1.程序调用System.gc时可能会触发,此时会建议 JVM 进行垃圾回收,但不代表一定会进行 GC 动作;

2.系统自身来决定 GC 触发的时机,比如年轻代空间不足、老年代空间不足等就会主动触发 GC 动作

以上两种行为都会产生 GC 日志。

03、GC日志

在介绍之前,我们先看一段代码,下文的 GC 日志都会基于这段代码来分析。

/**
 * 虚拟机参数:-verbose:gc
 */
public class GCObjectTest {

    public Object instance = null;

    /**
     * 设置成员属性占用一点内存,2M
     */
    public byte[] bigSize = new byte[2 * 1024 * 1024];

    public static void main(String[] args) {
        GCObjectTest objectA = new GCObjectTest();
        GCObjectTest objectB = new GCObjectTest();

        // 设置两个对象互相引用
        objectA.instance = objectB;
        objectB.instance = objectA;

        objectB = null;
        objectA = null;

        // 触发 GC,不一定实时生效
        System.gc();

    }
}
  • 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.

运行时加上-verbose:gc参数,以便简要的查看程序的 GC 情况,运行后的输出结果如下!

[GC (System.gc())  6101K->520K(125952K), 0.0022878 secs]
[Full GC (System.gc())  520K->408K(125952K), 0.0049120 secs]
  • 1.
  • 2.

以上代码是一段对象相互引用的场景,但是 JVM 还是将对象回收了,也应证了一点,HotSpot 虚拟机并不是通过引用计数法来判定对象是否存活的。

下面我们还是以上面的代码为例,设置不同的虚拟机参数,看看 GC 日志情况。

3.1、Serial 和 Serial Old 组合垃圾收集器

Serial 和 Serial Old 组合的垃圾收集器,可以在运行时设置如下参数来开启。

-XX:+PrintGCDetails
-XX:+UseSerialGC
  • 1.
  • 2.

运行之后,输出结果如下!

[Full GC (System.gc()) [Tenured: 0K->393K(87424K), 0.0104804 secs] 6891K->393K(126720K), [Metaspace: 3052K->3052K(1056768K)], 0.0105689 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap
 def new generation   total 39424K, used 351K [0x0000000740000000, 0x0000000742ac0000, 0x000000076aaa0000)
  eden space 35072K,   1% used [0x0000000740000000, 0x0000000740057c58, 0x0000000742240000)
  from space 4352K,   0% used [0x0000000742240000, 0x0000000742240000, 0x0000000742680000)
  to   space 4352K,   0% used [0x0000000742680000, 0x0000000742680000, 0x0000000742ac0000)
 tenured generation   total 87424K, used 393K [0x000000076aaa0000, 0x0000000770000000, 0x00000007c0000000)
   the space 87424K,   0% used [0x000000076aaa0000, 0x000000076ab02608, 0x000000076ab02800, 0x0000000770000000)
 Metaspace       used 3062K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 336K, capacity 388K, committed 512K, reserved 1048576K
  • 1.
  • 2.
  • 3.
  • 4.
  • 5.
  • 6.
  • 7.
  • 8.
  • 9.
  • 10.

各个参数描述介绍:

  • def new generation:表示年轻代的内存使用情况,其中eden space表示Eden空间的内存使用情况;from space表示From Survivor空间的内存使用情况;to space表示To Survivor空间的内存使用情况;
  • tenured generation:表示老年代的内存使用情况
  • Metaspace:表示元空间的内存使用情况,在 JDK1.7 中称为永久代

3.2、ParNew 和 Serial Old 组合垃圾收集器

ParNew 和 Serial Old 组合的垃圾收集器,可以在运行时设置如下参数来开启。

-XX:+PrintGCDetails
-XX:+UseParNewGC
  • 1.
  • 2.

运行之后,输出结果如下!

[Full GC (System.gc()) [Tenured: 0K->395K(87424K), 0.0044216 secs] 6891K->395K(126720K), [Metaspace: 3058K->3058K(1056768K)], 0.0044869 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 
Heap
 par new generation   total 39424K, used 1052K [0x0000000740000000, 0x0000000742ac0000, 0x000000076aaa0000)
  eden space 35072K,   3% used [0x0000000740000000, 0x0000000740107228, 0x0000000742240000)
  from space 4352K,   0% used [0x0000000742240000, 0x0000000742240000, 0x0000000742680000)
  to   space 4352K,   0% used [0x0000000742680000, 0x0000000742680000, 0x0000000742ac0000)
 tenured generation   total 87424K, used 395K [0x000000076aaa0000, 0x0000000770000000, 0x00000007c0000000)
   the space 87424K,   0% used [0x000000076aaa0000, 0x000000076ab02d70, 0x000000076ab02e00, 0x0000000770000000)
 Metaspace       used 3064K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 336K, capacity 388K, committed 512K, reserved 1048576K
  • 1.
  • 2.
  • 3.
  • 4.
  • 5.
  • 6.
  • 7.
  • 8.
  • 9.
  • 10.

其中par new generation表示年轻代的内存使用情况,其它表达的内容与上相同。

3.3、Parallel Scavenge 和 Parallel Old 组合垃圾收集器

Parallel Scavenge 和 Parallel Old 组合的垃圾收集器,可以在运行时设置如下参数来开启。

-XX:+PrintGCDetails
-XX:+UseParallelOldGC
  • 1.
  • 2.

需要注意的是,在 jdk1.8 及之后的版本中,-XX:+UseParallelGC和-XX:+UseParallelOldGC参数效果是一样的,都是用的 Parallel Old 作为老年代收集器;而在 jdk1.7 及之后的版本中,-XX:+UseParallelGC参数用的是 Serial Old 作为老年代收集器。

运行之后,输出结果如下!

[GC (System.gc()) [PSYoungGen: 6767K->496K(38400K)] 6767K->504K(125952K), 0.0014375 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[Full GC (System.gc()) [PSYoungGen: 496K->0K(38400K)] [ParOldGen: 8K->390K(87552K)] 504K->390K(125952K), [Metaspace: 3008K->3008K(1056768K)], 0.0045268 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
Heap
 PSYoungGen      total 38400K, used 998K [0x0000000795580000, 0x0000000798000000, 0x00000007c0000000)
  eden space 33280K, 3% used [0x0000000795580000,0x0000000795679b20,0x0000000797600000)
  from space 5120K, 0% used [0x0000000797600000,0x0000000797600000,0x0000000797b00000)
  to   space 5120K, 0% used [0x0000000797b00000,0x0000000797b00000,0x0000000798000000)
 ParOldGen       total 87552K, used 390K [0x0000000740000000, 0x0000000745580000, 0x0000000795580000)
  object space 87552K, 0% used [0x0000000740000000,0x0000000740061b10,0x0000000745580000)
 Metaspace       used 3042K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 333K, capacity 388K, committed 512K, reserved 1048576K
  • 1.
  • 2.
  • 3.
  • 4.
  • 5.
  • 6.
  • 7.
  • 8.
  • 9.
  • 10.
  • 11.

其中PSYoungGen表示年轻代的内存使用情况;ParOldGen表示老年代的内存使用情况,其它表达的内容与上相同。

3.4、ParNew 和 CMS + Serial Old 组合垃圾收集器

ParNew 和 CMS + Serial Old 组合的垃圾收集器,可以在运行时设置如下参数来开启。

-XX:+PrintGCDetails
-XX:+UseConcMarkSweepGC
  • 1.
  • 2.

运行之后,输出结果如下!

[Full GC (System.gc()) [CMS: 0K->388K(87424K), 0.0214068 secs] 6192K->388K(126720K), [Metaspace: 2925K->2925K(1056768K)], 0.0214982 secs] [Times: user=0.01 sys=0.01, real=0.03 secs] 
Heap
 par new generation   total 39424K, used 1052K [0x0000000740000000, 0x0000000742ac0000, 0x0000000754cc0000)
  eden space 35072K,   3% used [0x0000000740000000, 0x0000000740107280, 0x0000000742240000)
  from space 4352K,   0% used [0x0000000742240000, 0x0000000742240000, 0x0000000742680000)
  to   space 4352K,   0% used [0x0000000742680000, 0x0000000742680000, 0x0000000742ac0000)
 concurrent mark-sweep generation total 87424K, used 388K [0x0000000754cc0000, 0x000000075a220000, 0x00000007c0000000)
 Metaspace       used 2932K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 319K, capacity 388K, committed 512K, reserved 1048576K
  • 1.
  • 2.
  • 3.
  • 4.
  • 5.
  • 6.
  • 7.
  • 8.
  • 9.

其中par new generation表示年轻代的内存使用情况;concurrent mark-sweep generation表示老年代的内存使用情况,其它表达的内容与上相同。

3.5、G1 垃圾收集器

G1 垃圾收集器,可以在运行时设置如下参数来开启。

-XX:+PrintGCDetails
-XX:+UseG1GC
  • 1.
  • 2.

运行之后,输出结果如下!

[Full GC (System.gc())  5985K->395K(8192K), 0.0083534 secs]
   [Eden: 2048.0K(14.0M)->0.0B(4096.0K) Survivors: 0.0B->0.0B Heap: 5985.1K(128.0M)->395.9K(8192.0K)], [Metaspace: 3059K->3059K(1056768K)]
 [Times: user=0.01 sys=0.00, real=0.01 secs] 
Heap
 garbage-first heap   total 8192K, used 395K [0x0000000740000000, 0x0000000740100040, 0x00000007c0000000)
  region size 1024K, 1 young (1024K), 0 survivors (0K)
 Metaspace       used 3066K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 336K, capacity 388K, committed 512K, reserved 1048576K
  • 1.
  • 2.
  • 3.
  • 4.
  • 5.
  • 6.
  • 7.
  • 8.

G1 收集器与以上收集器都不同,它会把整个 Java 堆分成若干个大小相等的独立区域,也是日志中的 Region,然后针对优先级高的 Region 区域进行收集。Region 区域可能存放的是年轻代的对象,也可能是老年代的对象。

04、小结

以上的日志输出,会发现很多的共性。

比如,以“GC”开头的,通常表示年轻代的收集情况;以“Full GC”开头的,表示整个堆的收集情况,其中带有“(System.gc()) ”信息的表示调用System.gc()方法所触发的 GC。

以下面这个日志为例,来解读一下相关信息。

[Full GC (System.gc()) [PSYoungGen: 496K->0K(38400K)] [ParOldGen: 8K->390K(87552K)] 504K->390K(125952K), [Metaspace: 3008K->3008K(1056768K)], 0.0045268 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
  • 1.

1.Full GC (System.gc()表示 Full GC 类型的 GC 动作,通过调用System.gc()方法而触发;

2.PSYoungGen: 496K->0K(38400K)表示年轻代 GC 前使用的容量为 496K,GC 后该内存区域使用的容量为 0K,年轻代总容量为 38400K;

3.ParOldGen: 8K->390K(87552K)表示老年代 GC 前使用的容量为 8K,GC 后该内存区域使用的容量为 390K,老年代总容量为 87552K;

4.504K->390K(125952K)表示整个堆 GC 前使用的容量为 504K,GC 后该内存区域使用的容量为 390K,整个堆总容量为 125952K;

5.Metaspace: 3008K->3008K(1056768K)表示元空间 GC 前使用的容量为 3008K,GC 后该内存区域使用的容量为 3008K,整个元空间总容量为 1056768K;

6.0.0045268 secs表示 Full GC 耗时为 0.0045268 秒;

7.Times: user=0.01 sys=0.00, real=0.00 secs表示 Full GC 期间用户的耗时、系统的耗时、实际操作的耗时,单位秒;

Heap 后面列举的是堆的内存使用情况。

责任编辑:武晓燕 来源: 潘志的研发笔记
相关推荐

2021-04-20 13:59:37

云计算

2020-06-30 10:45:28

Web开发工具

2024-01-16 07:46:14

FutureTask接口用法

2022-02-17 09:24:11

TypeScript编程语言javaScrip

2020-06-29 07:42:20

边缘计算云计算技术

2022-02-24 10:28:23

物联网

2021-02-03 14:31:53

人工智能人脸识别

2024-01-12 07:38:38

AQS原理JUC

2024-07-05 09:31:37

2020-08-17 17:20:36

pythonJAVA代码

2017-01-18 15:38:20

语言

2024-09-13 08:49:45

2020-03-08 16:45:58

数据挖掘学习数据量

2024-02-22 07:37:37

对象JVM内存

2024-05-16 11:13:16

Helm工具release

2024-06-06 08:50:43

2009-11-09 12:55:43

WCF事务

2024-12-18 10:24:59

代理技术JDK动态代理

2023-12-27 08:15:47

Java虚拟线程

2022-02-21 18:16:38

Go语言枚举
点赞
收藏

51CTO技术栈公众号