浅谈GC日志

GC日志

young gc

young gc是需要stop the world的
这里写图片描述
例子:当eden满时,young gc使用的是ParNew收集器

ParNew: 2230361K->129028K(2403008K), 0.2363650 secs
  • 2230361K->129028K,指回收前后eden+s1(或s2)大小
  • 2403008K,指可用的young代大小,即eden+s1(或s2)
  • 0.2363650 secs,指消耗时间
2324774K->223451K(3975872K), 0.2366810 sec
  • 2335109K->140198K,指整个堆大小的变化(heap=(young+old)+perm;young=eden+s1+s2;s1=s2=young/(survivor ratio+2))
  • 0.2366810 sec,指消耗时间
[Times: user=0.60 sys=0.02, real=0.24 secs]
  • 指用户时间,系统时间,真实时间

full gc

在full gc时,stop the world。

有两种情况会触发full gc

  • concurrent-mode-failure:当cms gc正进行时,此时有新的对象要进行old代,但是old代空间不足造成的
  • promotion-failed:当进行young gc时,有部分young代对象仍然可用,但是S1或S2放不下,因此需要放到old代,但此时old代空间无法容纳此部分promotion对象

垃圾回收器

Serial

单线程、新生代复制算法、老年代标记-压缩;垃圾收集的过程中会Stop The World

-XX:+UseSerialGC

ParNew

Serial收集器的多线程版本。新生代并行,老年代串行;新生代复制算法、老年代标记-压缩算法

-XX:+UseParNewGC
-XX:ParallelGCThreads

Parallel

类似ParNew收集器,Parallel收集器更关注系统的吞吐量。新生代复制算法、老年代标记-压缩

-XX:+UseParallelGC

cms gc(提高吞吐率)

这里写图片描述
首先jvm根据-XX:CMSInitiatingOccupancyFraction,-XX:+UseCMSInitiatingOccupancyOnly来决定什么时间开始垃圾收集。如果设置了-XX:+UseCMSInitiatingOccupancyOnly,那么只有当old代占用确实达到了-XX:CMSInitiatingOccupancyFraction参数所设定的比例时才会触发cms gc。如果没有设置-XX:+UseCMSInitiatingOccupancyOnly,那么系统会根据统计数据自行决定什么时候触发cms gc;因此有时会遇到设置了80%比例才cms gc,但是50%时就已经触发了,就是因为这个参数没有设置的原因

CMS-initial-mark(初始标记)

此阶段是初始标记阶段,是stop the world阶段,因此此阶段标记的对象只是从root集最直接可达的对象

CMS-initial-mark:961330K(1572864K)
  • 指标记时,old代的已用空间和总空间

CMS-concurrent-mark(并发标记)

此阶段是和应用线程并发执行的,所谓并发收集器指的就是这个,主要作用是标记可达的对象。此阶段会打印2条日志:CMS-concurrent-mark-start,CMS-concurrent-mark

CMS-concurrent-preclean

此阶段主要是进行一些预清理,因为标记和应用线程是并发执行的,因此会有些对象的状态在标记后会改变,此阶段正是解决这个问题。因为之后的Rescan阶段也会stop the world,为了使暂停的时间尽可能的小,也需要preclean阶段先做一部分工作,以节省时间。此阶段会打印2条日志:CMS-concurrent-preclean-start,CMS-concurrent-preclean。

CMS-concurrent-abortable-preclean

加入此阶段的目的是使cms gc更加可控一些,作用也是执行一些预清理,以减少Rescan阶段造成应用暂停的时间。此阶段会打印一些日志如下:CMS-concurrent-abortable-preclean-start,CMS-concurrent-abortable-preclean,CMS:abort preclean due to time XXX

此阶段涉及几个参数

  • -XX:CMSMaxAbortablePrecleanTime:当abortable-preclean阶段执行达到这个时间时才会结束
  • -XX:CMSScheduleRemarkEdenSizeThreshold(默认2m):控制abortable-preclean阶段什么时候开始执行,即当eden使用达到此值时,才会开始abortable-preclean阶段
  • -XX:CMSScheduleRemarkEdenPenetratio(默认50%):控制abortable-preclean阶段什么时候结束执行

Rescan(重新标记)

是第二个stop the world阶段了,对对象进行重新扫描并标记

YG occupancy:964861K(2403008K)
  • 指执行时young代的情况
CMS remark:961330K(1572864K)
  • 指执行时old代的情况。此外,还打印出了弱引用处理、类卸载等过程的耗时。

CMS-concurrent-sweep(并发清除)

进行并发的垃圾清理

CMS-concurrent-reset

为下一次cms gc重置相关数据结构

G1

将堆空间划分成了互相独立的区块。每块区域既有可能属于O区、也有可能是Y区,且每类区域空间可以是不连续的(对比CMS的O区和Y区都必须是连续的)。这种将O区划分成多块的理念源于:当并发后台线程寻找可回收的对象时、有些区块包含可回收的对象要比其他区块多很多,即,第一时间处理垃圾最多的区块。([E]Eden,[O]Old,[S]Survivor)

主要阶段

  • YGC(不同于CMS)
  • 并发阶段
  • 混合模式
  • full GC (一般是G1出现问题时发生)

YGC

很多情况下,S区的对象会有部分晋升到Old区,另外如果S区已满、Eden存活的对象会直接晋升到Old区
这里写图片描述

这里写图片描述

23.430: [GC pause (young), 0.23094400 secs]
...
[Eden: 1286M(1286M)->0B(1212M)
Survivors: 78M->152M Heap: 1454M(4096M)->242M(4096M)]
[Times: user=0.85 sys=0.05, real=0.23 secs]
  • Young GC实际占用230毫秒、其中GC线程占用850毫秒的CPU时间
  • E:内存占用从1286MB变成0、都被移出
  • S:从78M增长到了152M、说明从Eden移过来74M
  • Heap:占用从1454变成242M、说明这次Young GC一共释放了1212M内存空间

并发阶段

图中Young区发生了变化、这意味着在G1并发阶段内至少发生了一次YGC。因为在并发阶段应用线程同时在工作、所以可以看到Eden又有新的占用。

一些区域被X标记,这些区域属于O区,此时仍然有数据存放、不同之处在G1已标记出这些区域包含的垃圾最多、也就是回收收益最高的区域。这个阶段在O区没有回收任何对象:它的作用主要是标记出垃圾最多的区块出来。对象实际上是在后面的阶段真正开始被回收

初始标记阶段

这里写图片描述

这里写图片描述

50.541: [GC pause (young) (initial-mark), 0.27767100 secs]
[Eden: 1220M(1220M)->0B(1220M)
Survivors: 144M->144M Heap: 3242M(4096M)->2093M(4096M)]
[Times: user=1.02 sys=0.04, real=0.28 secs]

这个过程会执行一次YGC。应用线程为此暂停了280毫秒(stop the world),Eden区被清空(71MB从Young区移到了O区)。日志里面initial-mark的字样表明后台的并发GC阶段开始了。因为初始标记阶段本身也是要暂停应用线程的,G1正好在YGC的过程中把这个事情也一起干了

concurrent-root-region-scan-start
50.819: [GC concurrent-root-region-scan-start]
51.408: [GC concurrent-root-region-scan-end, 0.5890230]

后台线程并行处理的。这个阶段不能被YGC所打断、因此后台线程有足够的CPU时间很关键。如果Young区空间恰好在Root扫描的时候满了、YGC必须等待root扫描之后才能进行。带来的影响是YGC暂停时间会相应的增加

350.994: [GC pause (young)
351.093: [GC concurrent-root-region-scan-end, 0.6100090]
351.093: [GC concurrent-mark-start],0.37559600 secs]

GC暂停这里可以看出在root扫描结束之前就发生了,表明YGC发生了等待,等待时间大概是100毫秒

concurrent-mark-start
111.382: [GC concurrent-mark-start]
....
120.905: [GC concurrent-mark-end, 9.5225160 sec]
remark

短暂stop the world

120.910: [GC remark 120.959:
[GC ref-PRC, 0.0000890 secs], 0.0718990 secs]
[Times: user=0.23 sys=0.01, real=0.08 secs]
cleanup

短暂stop the world

120.985: [GC cleanup 3510M->3434M(4096M), 0.0111040 secs]
[Times: user=0.04 sys=0.00, real=0.01 secs]
concurrent-cleanup-start

发现哪些区域包含可回收的垃圾最多(标记为X),实际空间释放较少

120.996: [GC concurrent-cleanup-start]
120.996: [GC concurrent-cleanup-end, 0.0004520]

混合GC

会同时进行YGC和清理上面已标记为X的区域。每次混合GC只是清理一部分的O区内存,整个GC会一直持续到几乎所有的标记区域垃圾对象都被回收,这个阶段完了之后G1会重新回到正常的YGC阶段。周期性的,当O区内存占用达到一定数量之后G1又会开启一次新的并行GC阶段。

79.826: [GC pause (mixed), 0.26161600 secs]
....
[Eden: 1222M(1222M)->0B(1220M)
Survivors: 142M->144M Heap: 3200M(4096M)->1964M(4096M)]
[Times: user=1.01 sys=0.00, real=0.26 secs]

适用场景

  • Serial收集器:大多数client-style机器。对于低程序暂停时间没有需求的程序。
  • Parallel收集器:多核机器,对于低程序暂停时间没有需求的程序。
  • CMS收集器:适用于要求快速响应的程序,但是需要更大的堆空间。
  • G1收集器:大容量内存和较小GC延迟的应用程序。

参考资料

https://blog.csdn.net/b2222505/article/details/78073180
https://blog.csdn.net/b2222505/article/details/72775665
https://blog.csdn.net/b2222505/article/details/78662187

  • 0
    点赞
  • 1
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

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

抵扣说明:

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

余额充值