一个频繁触发CMS的case浅析(一)

最近遇到一个频繁CMS的case，日志如下：

老年代的占用非常少，初步判断：并非由达到设置的内存比例触发，有可能是System.gc()或者permGen引发的CMS

【排查过程1】

增加日志，可以清楚看见，3个区的使用量都非常少

而gccause无法定位触发原因，只打印了CMS两个暂停阶段的信息

于是重新整理了一下background式CMS的触发点：

1、System.gc() + ExplicitGCInvokesConcurrent引起的

----确实设置了ExplicitGCInvokesConcurrent，但通过Btrace没有抓到System.gc的调用痕迹，可排除

2、JVM动态计算，并不是old gen占用率达到CMSInitiatingOccupancyFraction才进行回收

----设置了UseCMSInitiatingOccupancyOnly，可排除

3、当old gen的可用内存少于av_promo(每次次YGC时晋升到老年代对象大小的平均值)并且小于max_promotion_in_bytes(eden使用量+from使用量)时会触发

----小于max_promotion_in_bytes是有可能的，因为NewRatio=1，但少于av_promo的可能性太小，因为无法打印av_promo的值，写了一个分析gc日志计算晋升对象大小的程序，可排除

4、由permGen回收触发的

----没有设置CMSClassUnloadingEnabled，可排除

看上去好像都不满足触发CMS的条件，得从另外一个方向排查

【排查过程2】

查看concurrentMarkSweepThread的源码，关键点sleepBeforeNextCycle，意思是每个周期会调用一次shouldConcurrentCollect去判断是否需要执行CMS

而这个周期默认2秒，经检查测试环境设置的也是2秒，再看触发频率居然达到每秒2-3次！！远大于设置的2秒

因此，可以排除是由concurrentMarkSweepThread周期性触发的background式CMS，也和我们设置的CMSInitiatingOccupancyFraction没半点关系。

继续从源码追查，在genCollectedHeap中有一个GC的公共接口，关键点是should_do_concurrent_full_gc的判断

条件成立，会创建一个VM_GenCollectFullConcurrent的VM_operation，加到VMThread的队列中执行，可以看到System.gc()其中一种情况也是这样触发CMS进行并发回收的(另外一种情况是上述background式的CMS)

查看JVM参数，果然设置了GCLockerInvokesConcurrent (ExplicitGCInvokesConcurrent在上面已被排除)

于是屏蔽了GCLockerInvokesConcurrent进行反复测试，没有再发生过CMS了，而且触发YGC的GCLocker GCCause也涌现出来，至此，真相浮出水面

【小结与后续】

频繁触发CMS的原因找到了：设置了JVM参数GCLockerInvokesConcurrent

这里遗留了三个疑问：

(1)是什么JNI调用触发了gclocker

(2)什么情况下gclocker触发ygc还不够，要调用genCollectionHeap中的collect方法进行回收

(3)对于屏蔽掉GCLockerInvokesConcurrent的测试，ygc的频率随着时间不断增加，平均每秒2-3次(约等于之前的ygc+cms)，显然问题还是存在的，只是没有触发CMS

补充：

查看源码的时候，能看到initial和remark两个阶段会把cause回写，这也是为什么gccause只能看到CMS Initial Mark和CMS final Remark的原因吧