细说jvm(六)、垃圾回收器CMS详解

3,037 阅读20分钟

之前的文章

1、细说jvm(一)、jvm运行时的数据区域

2、细说jvm(二)、java对象创建过程

3、细说jvm(三)、对象创建的内存分配

4、细说jvm(四)、垃圾回收算法

5、细说jvm(五)、垃圾回收器入门

最近实在太忙,更新文章速度慢了不少,但是不管多忙,这个系列我还是会坚持写完的,关注jvm的人请放心哈~

上篇我们说了几个比较基础的垃圾回收器,从这篇开始,我们来说说当下用的比较多的垃圾回收器,并且会教大家怎么去看垃圾回收的日志,这些也常常涉及到工作面试中各种各样的问题,当然,这篇开始文章难度会偏大,不建议跳着看或者是这个领域刚刚入门的人来看这里。

一、简介

CMS全称Concurrent Mark Sweep,是一款以低停顿为目标的垃圾回收器,这个回收器是一款真正意义的并发收集器。我们知道,通常基于B/S的服务端会对低停顿有着较高的要求,因为这样能够提高用户的交互体验,因此,CMS可以说正好满足了这样的要求,也正是因为这一点,它目前被广泛的使用在各种应用的服务端。

我们在学习这款收集器的时候,一定要注意的一个是CMS是针对老年代的回收器,当我们使用jdk1.8的时候开启了-XX:+UseConcMarkSweepGC这个参数,在年轻代就只能使用ParNew了,这也是为什么当开启CMS之后gc日志中会有ParNew的日志的原因。

二、工作过程

1、主要工作流程

CMS的回收用的是标记清除算法,它的回收会经历以下几个阶段:

  • 初始标记(Initial Mark) (STW)
  • 并发标记(Concurrent Mark)
  • 并发预清理(Concurrent Preclean)
  • 并发可取消的预清理(Concurrent Abortable Preclean)
  • 最终标记(Final Remark) (STW)
  • 并发清除(Concurrent Sweep)
  • 并发重置(Concurrent Reset) 我们一个一个的来说下:
  • 初始标记(Initial Mark) 这个阶段所做的事情是从GC Root出发,标记所有GC Root直接关联的老年代存活的对象,其实也会扫描到新生代去(这是因为扫描之前并不知道这个GC Root引用的对象是不是老年代),你可以把这个阶段理解成我在算法那篇说三色标记的时状态1到状态2做的事情。这个阶段是STW的,原因也很简单,如果这个阶段是和用户线程一起运行的话,那么准确性就会大大收到影响。
这个阶段还有一个名字,就是叫做根结点枚举,以后还要讲的收集器如G1,ZGC也有这个阶段,并且它们的这个阶段也都是STW的,
STW目的也都是为了保证这个阶段所做工作的准确性。

这个阶段的速度是非常快的,所以即使是STW的,停顿时间也不会很长,我们还可以通过使用CMSParallelInitialMarkEnabled这个参数来使这个阶段变成多线程进行。

  • 并发标记(Concurrent Mark) 这个阶段是从上个阶段找出的对象出发,遍历整个对象引用链,这个阶段是耗时比较长的,但是它是可以和用户线程并发运行的,因此不会造成停顿。但是,需要注意的是,这个阶段由于是和应用线程并发进行,应用线程此时还在不断的分配对象,因此CMS在触发GC之前是需要保留一定的空间来支持应用线程分配对象,如果此时空间不够,就会触发“concurrent mode failure”,这是一个非常严重的问题,此时cms会退化成Serial old来进行gc,从而引发非常长的停顿时间。
  • 并发预清理(Concurrent Preclean) 这个阶段GC线程和应用线程也是并发执行,因为阶段2是与应用线程并发执行,可能有些引用关系已经发生改变。 通过卡片标记(Card Marking),提前把老年代空间逻辑划分为相等大小的区域(Card),如果引用关系发生改变,JVM会将发生改变的区域标记位“脏区”(Dirty Card),然后在本阶段,这些脏区会被找出来,刷新引用关系,清除“脏区”标记。
  • 并发可取消的预清理(Concurrent Abortable Preclean) 这个阶段也不停止应用线程. 本阶段尝试在 STW 的 最终标记阶段(Final Remark)之前尽可能地多做一些工作,以减少应用暂停时间 在该阶段不断循环处理:标记老年代的可达对象、扫描处理Dirty Card区域中的对象,循环的终止条件有: 1 达到循环次数 2 达到循环执行时间阈值 3 新生代内存使用率达到阈值。这个阶段最大持续时间(条件2)为5秒,之所以可以持续5秒,有个原因也是为了期待这5秒内能够发生一次young gc,清理年轻带的引用,减少下个阶段的重新标记阶段扫描年轻带指向老年代的引用的时间。
  • 最终标记(Final Remark) 这个阶段是STW的,目标是完成老年代中所有存活对象的标记。在此阶段执行: 1、遍历新生代对象,重新标记 2、根据GC Roots,重新标记 3 遍历老年代的Dirty Card,重新标记。
  • 并发清除(Concurrent Sweep) 这个阶段与应用程序并发执行,不需要STW停顿,根据标记结果清除垃圾对象。
  • 并发重置(Concurrent Reset) 此阶段与应用程序并发执行,重置CMS算法相关的内部数据, 为下一次GC循环做准备。
2、CMS的background和foreground模式

这块是关于CMS比较重要但是很多人却都不知道的点,做GC优化的人用CMS的时候可能经常会奇怪,为什么明明还没到CMSInitiatingOccupancyFraction参数的值却发生了GC,这是因为CMS GC发生的情况其实并不仅仅只有这一个。

a、foreground模式:这个模式是比较好理解的,就是当给对象分配内存但是空间不够的时候就会触发,这时候用的是标记清除算法,不会进行压缩

b、background模式:这个模式比较复杂,这个模式主要是由于CMS的后台线程不停的扫描,一旦发现符合触发条件,便会触发一次background模式的gc。我们来看看具体的条件

I、当调用是System.gc()并且配置了 ExplicitGCInvokesConcurrent 参数或者触发原因是gc locker且配置了 GCLockerInvokesConcurrent 参数。

我们一个一个来说下两种情况,当我们使用CMS的时候,并且在运行到了System.gc()这里,我们知道,System.gc()触发的是一次full gc,一般的full gc都是整个流程都是暂停的,但是如果配置了ExplicitGCInvokesConcurrent这个参数后,有的过程是可以并发执行的(这时候是background gc),这样就提高了效率。

至于gc locker,这货是个非常复杂的东西。简单来说就是在执行JNI的时候不允许发生gc,这是因为这时候线程是运行在临界区的,人家线程还没跑完gc把人家需要的数据清除掉了那样会有问题(一个典型的场景是使用本地方法JNI函数访问JVM中的字符串或数组数据),所以这个时候不允许gc。那么当线程运行在临界区的时候又需要gc 怎么办呢?这时候会把这次gc block住(这就是gc locker做的事情),在所有临界区的线程都运行完毕之后,再由gc locker触发一次gc,这时候的gc就是background gc。

II、根据统计数据动态计算(仅未配置 UseCMSInitiatingOccupancyOnly 时) 未配置 UseCMSInitiatingOccupancyOnly 时,会根据统计数据动态判断是否需要进行一次 CMS GC。

判断逻辑是,如果预测 CMS GC 完成所需要的时间大于预计的老年代将要填满的时间,则进行 GC。 这些判断是需要基于历史的 CMS GC 统计指标,然而,第一次 CMS GC 时,统计数据还没有形成,是无效的,这时会跟据 Old Gen 的使用占比来判断是否要进行 GC。

III、根据老年代的使用情况,这里有两种情况,第一种是配置了UseCMSInitiatingOccupancyOnly,并且当老年代使用的比例比我们设置的CMSInitiatingOccupancyFraction(没设置就是默认值的92%)大的时候,就会触发。另外一种情况是没有配UseCMSInitiatingOccupancyOnly,这时候又有两种小的分支情况,一个是当老年代是因为分配对象而成功扩容的,这时候会触发background gc(足以看出-xmx 和 -xms设置成一样的重要性),第二个是一个非常复杂的情况,这个和CMS老年代的空闲链表有关系,复杂的原因是freeList这玩意本身的复杂度就是非常高的,简单的说此时CMS的后台线程判断FreeList中的空间不足以分配新的下一次晋升到老年代的对象时候,就会触发background gc。

IV、young gc是否会失败(类似于之前说的parllel gc的悲观策略,CMS这货也有这样的行为) 当young gc失败的时候会触发background gc,为什么young gc会失败呢,大多数的原因是因为老年代的空间不够;还有一个是统计之前晋升的平均大小,如果老年代空间不够,也会触发老年代gc,这时候的gc也是background gc。

V、根据meta space使用情况来判断 当meta space扩容的时候,我们如果配置了CMSClassUnloadingEnabled(这个参数是用来控制是否允许CMS回收元空间的),就会触发一次CMS GC,这个情况如果表现出来是非常诡异的,这时候你可以看到明明老年代没用多少,但是却发生了gc。

3、回收和压缩之间的权衡

我们知道,CMS回收用的是标记清除算法,也就是说它平时并不对空间进行整理,这样会造成过多的内存碎片,这些内存碎片会降低对象分配的效率,如果空间碎片太多导致无法分配大对象,这时候就不得不进行一次full gc,这时候会有一个参数-XX:+UseCMSComPackAtFullCollection来控制在full gc的时候来压缩对象,这样虽然解决了碎片问题,但是停顿时间却变长了,并且这是一种被动的解决方案,容易造成停顿时间不可控制或是不容易预测,为了更容易预测或是控制停顿的时间,CMS提供了另外一个参数-XX:CMSFullGCsBeforeCompaction来解决这个问题,这个参数的含义是要求CMS在进行了若干次不整理空间的full gc之后下次进入full gc会对碎片进行整理,默认值是0,表示每次full gc都会整理空间,这个值太小会导致空间整理太过于频繁从而降低效率,太大又会造成太多内存碎片,降低分配对象的效率,在实际使用中,若想精准的控制这个值,必须经过压测综合观察吞吐量和停顿时间,以取得一个最合适的值。

三、CMS回收器的缺点

CMS无论在哪个jdk的版本都不是默认的回收器,原因是他有着比较明显的几个缺点

1、内存碎片

内存碎片是由于使用标记整理法导致,上面已说过,这里不在赘述。

2、浮动垃圾

这是因为CMS是和用户线程并发运行的,在程序运行过程中自然还会产生新的垃圾,但是这部分垃圾是CMS这次回收无法处理的,只能等到下个回收再处理,这部分垃圾就是浮动垃圾。

3、并发标记失败

正是因为用户程序还在运行,因此CMS不能在老年代空间使用百分之百的时候再去回收,这也是配置CMSFullGCsBeforeCompaction的原因,这里值得一提的是,在回收的过程中,如果老年代的空间不足以存放用户程序产生的对象数据,那么就会触发并发标记失败,这时候会导致一次full gc。设置CMSFullGCsBeforeCompaction也是需要权衡的,因为设置的太大,容易触发并发标记失败,设置的太小,则会频繁的回收,增大停顿时间的同时还会降低吞吐量。

四、常见参数

除过文中提到的参数之外,还有下面的参数比较常用

1、XX:+UseConcMarkSweepGC

默认是false 老年代采用CMS回收器,1.8的时候来使用,在新生代默认会使用ParNew

2、-XX:+CMSScavengeBeforeRemark

默认是false,重新标记之前,先执行一次ygc,回收掉年轻带的对象无用的对象,并将对象放入幸存带或晋升到老年代,这样再进行年轻带扫描时,只需要扫描幸存区的对象即可,一般幸存带非常小,这大大减少了扫描时间,从而减少STW的时间

3、-XX:+UseCMSCompactAtFullCollection

默认是true,开启之后是CMS在full gc 之后可不可以对老年代内对象布局进行压缩,它和第4个参数是搭配使用的

4、-XX:CMSFullGCsBeforeCompaction=n

如果第3个参数是true,那么在n次full gc之后会对对象布局进行压缩,如果是0的话,会在每次gc之后都进行压缩

5、–XX:ParallelGCThreads=n

这是并发回收的线程数量,一般使用默认值即可

6、-XX:CMSInitiatingOccupancyFraction=n

这个参数是和第7个参数搭配使用的,这个参数的意思是当老年代空间被占用百分之n的时候触发一次major gc,也就是old gc,1.8这个参数默认值是92,但是如果应用并发量较大(意味着分配对象速度快),这个值是需要设置的低一些的。

7、-XX:+UseCMSInitiatingOccupancyOnly

CMS会自动调整触发major gc的阈值,如果仅仅想使用我们设置的值,还需要使用这个参数

五、日志解读

1、gc日志关注点

这里主要是教大家去读CMS的日志,另外也会教大家使用一款gc可视化的分析工具,GC Viewer。我们读gc日志,首先要明白读gc日志需要关注的点都有哪些,否则真的还不如别看。读GC需要关注的几个基本的点:

  • 一定时间内gc的次数
  • 单次gc耗时
  • full gc的次数
  • 发生gc的原因 另外,需要我们注意的一点是,由于jvm对于gc日志这里没有一个规范(目前在规划中),因此不同的垃圾回收器打出来的日志是不一样的,这也是读gc日志非常头疼的一点。
2、ParNew日志

用我们测试环境的数据来举个例子,我们测试环境的jvm参数如下:

-Xms1024m 
-Xmx1024m 
-XX:NewRatio=1 
-XX:+UseConcMarkSweepGC 
-XX:+CMSParallelRemarkEnabled 
-XX:+UseParNewGC 
-XX:+PrintGCDetails 
-XX:+PrintGCDateStamps 
-XX:+PrintGC 
-Xloggc:/export/Logs/gc.log 
-XX:+PrintHeapAtGC 
-XX:+HeapDumpOnOutOfMemoryError 
-XX:HeapDumpPath=/export/Logs/oom_error.hprof

由于配置了PrintHeapAtGC,所以在每次gc前后都会打出来堆的大小,日志会显得比较长,这里不需要担心,都是纸老虎,没什么好害怕的。另外需要知道的是,使用了CMS的话,年轻代用的是ParNew,因此年轻代日志是都会有ParNew,我们来看个例子: 我用红色数字表示出来的123456分别是回收前后的堆内存的使用情况,这里注意,1处的总的大小等于2+3的,这是因为from和to空间只用一个,1这里很有意思,因为我们用的是parnew回收器,因此这里叫做par new generation,5这里是老年代,同理因为用的是CMS,所以这里也叫做concurrent mark-sweep generation,6则是metaspace空间使用情况以及其中的class存放区的使用情况,这些相信是很容易看懂的,我就不对数字标记的地方做更多解释了。

我们来看下两个红框中比较长的这个框,为了便于讲解,我再把这里的日志贴出来: 我把每个部分用红框拆分出来,用蓝色数字标记,我们一个一个来看下:

第1个部分中的“GC (Allocation Failure) 45.679:”表示在jvm启动45.679秒之后,由于为对象分配内存空间失败而导致了这次gc;

第2个部分中“455889K->31600K(471872K), 0.3074756 secs”,455889K表示年轻代一共使用了这么大空间,这里和上个图的1中的used值是一样的,回收之后占用了31600K,471872K说的是年轻代的总容量,和上面图的1中的total值是一样的,0.3074756是回收耗时;

第3部分“464536K->46851K(996160K)”中,464536k是回收之前整个堆使用了这么大,46851k是回收之后整个堆用了这么大空间,括号里的996160k是整个堆的大小;

第4部分“ 0.3076113 secs”(其实这个和第3部分是一起的),这是整个堆回收工作的耗时,虽说回收的是年轻代,但是可能涉及到把对象升级到老年代等工作,所以这个时间比第2部分中的耗时的值大一些;

第5部分“Times: user=0.63 sys=0.02, real=0.31 secs”,这里面涉及到三种时间类型,含义是: user:GC 线程在垃圾收集期间所使用的 CPU 总时间; sys:系统调用或者等待系统事件花费的时间; real:应用被暂停的时钟时间,由于 GC 线程是多线程的,导致了 real 小于 (user+real),如果是 gc 线程是单线程的话,real 是接近于 (user+real) 时间。

再看看看第一个图的短框: 这个框内容很少,主要是两个部分,第一个是invocations=5,这个是从jvm启动到现在发生了5次gc(这里没有包括老年代gc,也就是说年轻代gc了5次,full gc回收的是全堆,因此在full gc的时候,这个值也会加1),full=2是说full gc发生了两次,我们通过观察这个可以看出来一定时间发生gc的次数和full gc的次数。

3、CMS日志

参数还是和上面的参数一样,来看一段CMS的日志

这里之所以没有截图的原因是CMS的日志和ParNew是交替输出的,并且CMS一个回收周期持续时间比较长,所以很难找到一个完整的图,但是你如果是认真看到这里来的,这个日志对你来说应该也只是小意思了。

含义见里面的汉语注释

// 1、这里是第一个阶段初始标记,0是老年代使用大小,524288K是整个老年代大小,268461K是整个堆使用大小,996160K是整个堆的大小,0.0369037 secs是这个阶段耗时,这个阶段是STW的,Times含义和上面一样
2021-01-15T15:10:22.071+0800: 4.271: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(524288K)] 268461K(996160K), 0.0369037 secs] [Times: user=0.10 sys=0.00, real=0.04 secs] 
// 2、并发标记开始
2021-01-15T15:10:22.109+0800: 4.308: [CMS-concurrent-mark-start]
2021-01-15T15:10:22.109+0800: 4.308: [CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
// 3、并发预清理开始
2021-01-15T15:10:22.109+0800: 4.308: [CMS-concurrent-preclean-start]
2021-01-15T15:10:22.111+0800: 4.310: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
// 4、可被终止的并发预清理开始
2021-01-15T15:10:22.111+0800: 4.310: [CMS-concurrent-abortable-preclean-start]
// 5、最终标记,这里写到文章里,因为太长了
2021-01-15T15:10:24.601+0800: 6.800: [GC (CMS Final Remark) [YG occupancy: 26035 K (471872 K)]6.800: [Rescan (parallel) , 0.0727898 secs]6.873: [weak refs processing, 0.0000510 secs]6.873: [class unloading, 0.0168876 secs]6.890: [scrub symbol table, 0.0033340 secs]6.893: [scrub string table, 0.0005541 secs][ CMS-remark: 0K(524288K)] 26035K(996160K), 0.0968042 secs] [Times: user=0.20 sys=0.01, real=0.10 secs] 
// 6、并发清理开始
2021-01-15T15:10:24.698+0800: 6.897: [CMS-concurrent-sweep-start]
2021-01-15T15:10:24.698+0800: 6.897: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
// 7、并发重置
2021-01-15T15:10:24.698+0800: 6.897: [CMS-concurrent-reset-start]
2021-01-15T15:10:24.771+0800: 6.970: [CMS-concurrent-reset: 0.007/0.073 secs] [Times: user=0.08 sys=0.01, real=0.07 secs] 

第5部分最终标记:

YG occupancy是年轻代占用大小,26035是年轻代当前使用大小,471872是年轻代总大小,和之前说parnew的时候这两个值是一样的;

Rescan (parallel)是当应用暂停的情况下完成对所有存活对象的标记,这个阶段是并行处理的,这里花了0.0727898 secs;

weak refs processing, 0.0000510 secs:第一个子阶段,它的工作是处理弱引用;

class unloading, 0.0168876 secs:第二个子阶段,它的工作是:unloading the unused classes;

scrub symbol table, 0.0033340 secs 到 scrub string table, 0.0005541 secs:最后一个子阶段,它的目的是:清理类级元数据和内部字符串的符号对应在string table的引用;

CMS-remark: 0K(524288K),0是这个阶段之后的老年代占用大小,524288K是这个阶段之后的老年代占用大小;

26035K(996160K)0.0968042 secs:26035K这个阶段之后的堆内存使用情况,996160K是整个堆的大小;0.0968042 secs是这个阶段所花费的时间。

细心的读者会注意到老年代的使用是0k,但是这里却发生了一次老年代的GC,这里是因为元空间的大小在此时发生变化导致的。这个也是我需要解释的一点,这个gc是发生在我们的springboot项目刚刚启动的时候的,这次gc其实是full gc的一部分,我之前也说过,full gc包含了old gc和young gc,这时候因为在加载各种各样的类,并且频繁调用asm生成新的类导致元空间大小发生变化。这点可以通过观察类的图来证明。

4、GC Viewer

统计整个日志中gc次数是件很麻烦的事情,这里有个比较好用的可视化工具GC Viewer,这玩意下载安装的过程我就不在这里说了,我们来看看一些基础的玩法,下面是我把我们的gc日志用GC Viewer打开的界面:

第1部分是内存随着时间变化的折线图,我一般都不看这个的(不是说没用);第2部分各项数据的统计,我看的最多的是下面这个界面的东西: 这里面是这个gc日志文件里面所有的gc暂停以及full gc次数以及并发日志的一些数据,随着gc日志格式的不一样这里的数据也会有一些不一样,很熟悉CMS的看到这个界面应该也是不需要多少解释就能看明白的,关于GC Viewer的具体用法,请参考github.com/chewiebug/G…