APP下载

《跟我一起学JVM》之理解GC日志

消息来源:baojiabao.com 作者: 发布时间:2026-05-21

报价宝综合消息《跟我一起学JVM》之理解GC日志

那些变优秀的人不是一夜之间的好运降临,是无数次的准备和积累之后的质变。

关注一下,更多精彩等著您

阅读GC日志是处理Java虚拟机器内存问题的基础技能,它只是一些人为确定的规则,没有太多技术含量。

每一种收集器的日志形式都是由它们自身的实现所决定的,换而言之,每个收集器的日志格式都可以不一样。但虚拟机器设计者为了方便使用者阅读,将各个收集器的日志都维持一定的共性,例如以下两段典型的GC日志

33.125: [GC [DefNew: 3324K->152K(3712K), 0.0025925 secs] 3324K->152K(11904K), 0.0031680 secs]

100.667: [Full GC [Tenured: 0K->210K(10240K), 0.0149142 secs] 4603K->210K(19456K), [Perm : 2999K->2999K(21248K)], 0.0150007 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]

最前面的数字"33.125:"和"100.667:"代表GC发生的时间,这个数字的含义是从Java虚拟机器启动以来经过的秒数。

GC日志开头的"[GC"和“[Full GC”说明了这次垃圾收集的停顿型别,而不是用来区分新生代GC还是老年代GC的。如果有“Full”,说明这次GC是发生了Stop-The-World的,例如下面这段新生代收集器ParNew的日志也会出现“[Full GC”(这一般是因为出现了分配担保失败之类的问题,所以才导致STW)。如果是呼叫System.gc()方法触发的收集,那么这里将显示"[Full GC(System)"。

[Full GC 283.736: [ParNew: 261599K->261599K(261952K), 0.0000288 secs]

接下来的"[DefNew"、"[Tenured"、"[Perm" 表示GC发生的区域,这里显示的区域名称与使用的GC收集器是密切相关的,例如上面样例所使用的Serial收集器中的新生代名为"Default New Generation",所以显示的是"[DefNew"。如果是ParNew收集器,新生代名称就会变为"[ParNew",意为"Parallel New Generation"。如果采用Parallel Scavenge收集器,那它配套的新生代名称为"PSYoungGen",老年代和永久代同理,名称也是由收集器决定 的。

后面方括号内部的"3324K->152K(3712K)"含义是"GC前该内存区域已使用容量->GC后该内存区域已使用容量(该内存区域总容量)"。而在方括号之外的"3324K->152K"表示"GC前Java堆已使用容量->GC后Java堆已使用容量(Java堆总容量)"。

再往后,"0.0025925 secs"表示该内存区域GC所占用的时间,单位是秒。有的收集器会给出更具体的时间资料,如"[Times: user=0.01 sys=0.00 real=0.02 secs]",这里面的user、sys和real与Linux的time命令所输出的时间含义一致,分别代表使用者态消耗的CPU时间、核心态消耗的CPU时间和操作从开始到结束经过的墙锺时间(Wall Clock Time)。CPU时间与墙锺时间的区别是,墙锺时间包括各种非运算的等待耗时,例如等待磁盘I/O、等待执行绪阻塞,而CPU时间不包括这些消耗,但当系统有多CPU或者多核的话,多执行绪操作会叠加这些CPU时间,所以读者看到user或sys时间超过real时间是完全正常的。

扩充套件阅读:

《跟我一起学JVM》之执行时资料区域

《跟我一起学JVM》之物件是怎么建立的

《跟我一起学JVM》之物件的内存布局

《跟我一起学JVM》之物件在JVM中的访问方式

《跟我一起学JVM》之如何判断物件“已死”

《跟我一起学JVM》之垃圾收集算法

《跟我一起学JVM》之HotSpot的垃圾收集算法实现

2019-12-24 05:49:00

相关文章