JVM系列4-GC log

本文详细介绍了JVM的GC日志,包括JVM参数如-XX:+PrintGC、-XX:PrintGCDetails等的作用,以及它们如何影响GC日志的输出。GC日志分析工具GCviewer的使用,CMS日志分析中的不同阶段,如初始标记、并发标记、并发预清理、最终标记、并发清理和并发重置等阶段的解释,展示了GC日志的解析和理解过程。
摘要由CSDN通过智能技术生成

1、JVM参数

-XX:+PrintGC

参数-XX:+PrintGC开启了简单GC日志模式,为每一次新生代(young generation)的GC和每一次的Full GC打印一行信息。日志默认输出到终端。下面举例说明:

[GC 1843K->632K(116736K), 0.0112928 secs]
[Full GC 632K->558K(116736K), 0.0157125 secs]

每行开始首先是GC的类型(可以是“GC”或者“Full GC”),然后是在GC之前和GC之后已使用的堆空间,再然后是当前的堆容量,最后是GC持续的时间(以秒计)。

第一行的意思就是GC将已使用的堆空间从1843K减少到632K,当前的堆容量(译者注:GC发生时)是116736K,GC持续的时间是0.0112928 秒。

简单模式的GC日志格式是与GC算法无关的,日志也没有提供太多的信息。在上面的例子中,我们甚至无法从日志中判断是否GC将一些对象从young generation移到了old generation。所以详细模式的GC日志更有用一些。

-XX:PrintGCDetails

如果不是使用-XX:+PrintGC,而是-XX:PrintGCDetails,就开启了详细GC日志模式。在这种模式下,日志格式和所使用的GC算法有关。我们首先看一下使用PS垃圾收集器在young generation中生成的日志。为了便于阅读这里将一行日志分为多行并使用缩进。备注:共同使用PrintGC和PrintGCDetails,只会显示PrintGCDetails。

[GC
 [PSYoungGen: 1843K->632K(35840K)] 1843K->632K(116736K), 0.0149062 secs] 
 [Times: user=0.03 sys=0.00, real=0.02 secs] 

[Full GC 
 [PSYoungGen: 632K->0K(35840K)] 
 [ParOldGen: 0K->558K(80896K)] 632K->558K(116736K) 
 [PSPermGen: 2930K->2930K(21504K)], 0.0220857 secs]
 [Times: user=0.02 sys=0.00, real=0.02 secs] 

我们可以很容易发现:这是一次在young generation中的GC,它将已使用的堆空间从1843K减少到了632K,用时0.0149062秒。此外我们还可以得到更多的信息:所使用的垃圾收集器(即Parallel Scavenge GC)、young generation的大小和使用情况(在这个例子中PS垃圾收集器将young generation所使用的堆空间从1843K减少到632K)。

既然我们已经知道了young generation的大小,所以很容易判定发生了GC,因为young generation无法分配更多的对象空间:已经使用了35840K中的1843K。我们可以进一步得出结论,多数从young generation移除的对象仍然在堆空间中,只是被移到了old generation。

接下来看一下Full GC的输出日志:
除了关于young generation的详细信息,日志也提供了old generation和permanent generation的详细信息。对于这三个generations,一样也可以看到所使用的垃圾收集器、堆空间的大小、GC前后的堆使用情况。需要注意的是显示堆空间的大小等于young generation和old generation各自堆空间的和。以上面为例,堆空间总共占用了558K,其中0K在young generation,558K在old generation。Full GC持续了0.02秒,用户空间的CPU执行时间为0.02秒,说明GC使用了多线程。

对不同generation详细的日志可以让我们分析GC的原因,如果某个generation的日志显示在GC之前,堆空间几乎被占满,那么很有可能就是这个generation触发了GC。但是在上面的例子中,三个generation中的任何一个都不是这样的,在这种情况下是什么原因触发了GC呢。对于Throughput垃圾收集器,在某一个generation被过度使用之前,GC ergonomics决定要启动GC。

Full GC也可以通过显式的请求而触发,可以是通过应用程序,或者是一个外部的JVM接口。这样触发的GC可以很容易在日志里分辨出来,因为输出的日志是以“Full GC(System)”开头的,而不是“Full GC”。

对于Serial垃圾收集器,详细的GC日志和Throughput垃圾收集器是非常相似的。唯一的区别是不同的generation日志可能使用了不同的GC算法。使用垃圾收集器作为一行日志的开头可以方便我们从日志就判断出JVM的GC设置。

对于CMS垃圾收集器,young generation的详细日志也和Throughput垃圾收集器非常相似,但是old generation的日志却不是这样。对于CMS垃圾收集器,在old generation中的GC是在不同的时间片内与应用程序同时运行的。GC日志自然也和Full GC的日志不同。而且在不同时间片的日志夹杂着在此期间young generation的GC日志。但是了解了上面介绍的GC日志的基本元素,也不难理解在不同时间片内的日志。只是在解释GC运行时间时要特别注意,由于大多数时间片内的GC都是和应用程序同时运行的,所以和那种独占式的GC相比,GC的持续时间更长一些并不说明一定有问题。

即使CMS垃圾收集器没有完成一个CMS周期,Full GC也可能会发生。如果发生了GC,在日志中会包含触发Full GC的原因,例如众所周知的”concurrent mode failure“。

-XX:+PrintGCTimeStamps和-XX:+PrintGCDateStamps

使用-XX:+PrintGCTimeStamps可以将时间和日期也加到GC日志中。表示自JVM启动至今的时间戳会被添加到每一行中。例子如下:

0.148: [GC
 [PSYoungGen: 1843K->632K(35840
  • 1
    点赞
  • 8
    收藏
    觉得还不错? 一键收藏
  • 2
    评论
评论 2
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值