作为 java 程序员，还不会分析GC日志？请看这里！

Java极客技术

发布于 2024-03-25 13:53:39

980

发布于 2024-03-25 13:53:39

文章被收录于专栏：Java极客技术Java极客技术

一、摘要

在之前的文章中，我们介绍了 JVM 的垃圾收集器相关知识，那么如何分析当前虚拟机性能呢？其中 GC 日志起到至关重要的作用。

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

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

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

二、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();

    }
}

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

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

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

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

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

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

-XX:+PrintGCDetails
-XX:+UseSerialGC

运行之后，输出结果如下！

[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

各个参数描述介绍：

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

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

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

-XX:+PrintGCDetails
-XX:+UseParNewGC

运行之后，输出结果如下！

[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

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

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

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

-XX:+PrintGCDetails
-XX:+UseParallelOldGC

需要注意的是，在 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

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

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

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

-XX:+PrintGCDetails
-XX:+UseConcMarkSweepGC

运行之后，输出结果如下！

[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

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

2.5、G1 垃圾收集器

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

-XX:+PrintGCDetails
-XX:+UseG1GC

运行之后，输出结果如下！

[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

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

2.6、小结

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

比如，以“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.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 后面列举的是堆的内存使用情况。

三、触发GC时机

了解了相关的 GC 日志之后，虚拟机什么时候触发 GC 呢？

通常，GC 触发的条件有两种：

1.程序调用System.gc时可能会触发，此时会建议 JVM 进行垃圾回收，但不代表一定会进行 GC 动作；
2.系统自身来决定 GC 触发的时机，比如年轻代空间不足、老年代空间不足等就会主动触发 GC 动作

四、日志分析工具

通常情况下，运维人员并不会直接在服务器端通过命令方式实时打印当前应用程序的 GC 日志来分析服务的性能，通常的做法是导出当前服务的 GC 日志文件，然后通过其它的可视化工具来分析服务的性能指标。

目前，软件市场上对 GC 日志进行可视化分析的工具非常多，在此我们介绍几款业界比较流行的日志分析工具，以便能更加快速的排查 GC 问题。

4.1、GCeasy

GCeasy 是一款在线的 GC 日志分析器，使用起来非常方便，用户可以通过它的 web 网站导入 gc 日志，实时进行内存泄漏检测、GC暂停原因分析、JVM 配置建议优化等功能，而且是可以免费使用的（有部分服务是收费的），网站访问地址如下！

http://gceasy.io

选择中文语言之后，即可看到如下界面。

还是以最开头的代码为例，在运行的时候，加上如下命令即可导出 gc 日志。

-Xloggc:/Users/xxx/Documents/logs/gc.log

如果是 jar 包的启动方式，比如 SpringBoot 工程，可以在启动命令时加上Xloggc参数即可，例如下面的示例。

java  -Xloggc:gc.log  -XX:+PrintGCDetails -jar application.jar

如果是 war 包的启动方式，比如放在 tomcat 里面，可以通过修改bin/catalina.sh文件来开启 gc 日志，例如下面的示例。

JAVA_OPTS='-Xloggc:/tmp/gc.log -XX:+PrintGCDetails'

最后，将导出的 gc 日志，上传到 GCeasy 中，即可实时统计出相关的 gc 信息。

以下导入 gc 日志后，相关的分析截图信息，有兴趣的朋友，可以自行尝试一下。

4.2、GCViewer

GCViewer 也是一款非常强大的 gc 日志可视化分析工具，与 GCeasy 稍有不同，它需要本地运行，而且完全免费。

安装和启动方式如下！

--  1.下载源码
git clone https://github.com/chewiebug/GCViewer.git
--  2.用 IDEA打开项目，使用 maven 进行打包
mvn clean pacakge
--  3.得到一个 可运行的jar包，在 target目录下，启动服务
java -jar gcviewer-1.37-SNAPSHOT.jar

启动服务之后，会弹出一个类似于如下的界面。

点击左上角的按钮，打开本地的 gc 日志文件，就会显示了日志分析的结果。

左侧是图表，右侧是数据统计面板，展示的内容还是比较丰富的，有兴趣的访问它的官网特性说明，地址如下。

https://github.com/chewiebug/GCViewer/wiki

五、小结

本文主要围绕 GC 日志以及相关的可视化分析工具，进行了一次知识内容的整合和总结，内容比较多，如果有描述不对的地方，欢迎大家留言指出，不胜感激。

六、参考

1.https://juejin.cn/post/7029130033268555807

2.https://www.cnblogs.com/xrq730/p/4836700.html

本文参与腾讯云自媒体分享计划，分享自微信公众号。

原始发表：2024-03-18，如有侵权请联系 cloudcommunity@tencent.com 删除

java

程序员

内存

日志

本文分享自 Java极客技术微信公众号，前往查看

如有侵权，请联系 cloudcommunity@tencent.com 删除。

本文参与腾讯云自媒体分享计划，欢迎热爱写作的你一起参与！

登录后参与评论

0 条评论

热度