爱站程序员基地CMS垃圾收集器小实验之CMSInitiatingOccupancyFraction参数
背景
测试CMSInitiatingOccupancyFraction参数，测试结果和我的预期不符，所以花了一点时间一探究竟，文中有一些细节问题搞得不是特别清楚，但是也解决了我的困惑，在此记录一下。
预备知识
CMS收集器
garbage-collection-algorithms-implementations#concurrent-mark-and-sweep
CMSInitiatingOccupancyFraction说明
触发cms gc的老年代占用率，比如设置-XX:CMSInitiatingOccupancyFraction=80，那么在老年代占用率达到80%时触发cms gc。
CMSWaitDuration说明
cms gc线程定时执行的时间间隔，默认为2s一次。
测试步骤
测试环境准备
1.下载fastdebug版本openjdk（debug版本的jdk可以输出调试信息，方便分析问题），下载地址fastdebug
2.准备测试代码
public static void log(String msg){SimpleDateFormat sdf = new SimpleDateFormat(\"yyyy-MM-dd HH:mm:ss\");System.out.println(sdf.format(new Date())+\" \"+msg);}public static void displayMemoryInfo(){log(\"======memory info start=======\");MemoryMXBean mmbean = ManagementFactory.getMemoryMXBean();List<MemoryPoolMXBean> pools = ManagementFactory.getMemoryPoolMXBeans();for(MemoryPoolMXBean bean : pools){System.out.println(bean.getName()+\"=\"+bean.getUsage());}log(\"======memory info end=======\");}public static void testCMSInitiatingOccupancyFraction() throws Exception{log(\"a1 allocate start \");List<byte[]> list = new ArrayList<>(3);byte a1[] = new byte[5*_1MB];//a1内存直接分配到eden区，此时eden区内存占用5m+list.add(a1);log(\" a1 allocated,sleep 4s\");displayMemoryInfo();Thread.sleep(4000);log(\"a2 allocate start \");byte a2[] = new byte[5*_1MB];//由于a1占用了eden 5m+内存，剩余内存不足以容纳a2，//此时会触发ygc，因为s0和s1都不足以容纳a1，所以a1直接晋升到老年代，//然后将a2分配到年轻代，老年代当前内存占用5m+，年轻代当前内存占用5m+list.add(a2);log(\" a2 allocated,sleep 4s\");displayMemoryInfo();Thread.sleep(4000);log(\"a3 allocate start \");byte a3[] = new byte[10*_1MB];list.add(a3);log(\" a3 allocated,exit it\");//直接分配到老年代，老年代当前15M+displayMemoryInfo();Thread.sleep(10000);System.exit(0);}
3.整个堆30m，年轻代10m，eden 8m，so/s1 1m
4.测试代码搭配的jvm参数
java -verbose:gc -Xms30M -Xmx30M -Xmn10M -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=80 -XX:+UseConcMarkSweepGC -XX:+PrintTenuringDistribution -XX:+PrintHeapAtGC -XX:+PrintGC -XX:+PrintCMSInitiationStatistics -XX:CMSWaitDuration=3000 -XX:+Verbose coding4fun.jvm.TestCMS > testCMSInitiatingOccupancyFraction.log
我设置了CMSInitiatingOccupancyFraction=80，CMSWaitDuration=3000，意味着cms gc线程每3s执行一次，如果检测到老年代内存占用率达到80%，那么就触发垃圾收集。
预期分析
1.构造a1对象，a1是一个5m的字节数组；
2.睡眠4s，等待cms gc 线程执行；
3.cms gc线程执行，此时老年代空间利用率为0，不应该触发垃圾收集；
4.构造a2对象，a2是一个5m的字节数组，由于eden区空间不足，这时导致a1直接晋升到老年代，此时老年代内存占用5m+；
5.睡眠4s;
6.cms gc线程执行，此时老年代空间占用率为20%+，依然小于CMSInitiatingOccupancyFraction，不应该触发垃圾收集；
7.构造a3对象，a3是一个10m的字节数据，由于大于eden区空间，所以直接分配到老年代，此时老年代内存占用15m+；
8.睡眠10s；
9.cms gc线程执行，此时老年代空间利用率为75%+，依然小于CMSInitiatingOccupancyFraction，不应该触发垃圾收集；
以上是我结合理论知识对cms gc行为的一个预测，下一步我试图结合真实的gc log来验证结果是否符合预期。
通过gc日志验证猜想
gc日志比较长，我截取其中一部分：
2020-05-29 14:59:46 a1 allocate start2020-05-29 14:59:46 a1 allocated,sleep 4s###1 a1 分配完以后打印内存信息，此时eden区内存占用6980K，old区空着2020-05-29 14:59:46 ======memory info start=======Code Cache=init = 2555904(2496K) used = 2514048(2455K) committed = 2555904(2496K) max = 251658240(245760K)Metaspace=init = 0(0K) used = 4624072(4515K) committed = 4980736(4864K) max = -1(-1K)Compressed Class Space=init = 0(0K) used = 458088(447K) committed = 524288(512K) max = 1073741824(1048576K)Par Eden Space=init = 8388608(8192K) used = 7148216(6980K) committed = 8388608(8192K) max = 8388608(8192K)Par Survivor Space=init = 1048576(1024K) used = 0(0K) committed = 1048576(1024K) max = 1048576(1024K)CMS Old Gen=init = 20971520(20480K) used = 0(0K) committed = 20971520(20480K) max = 20971520(20480K)2020-05-29 14:59:46 ======memory info end=======###2 cms gc 线程第一次执行（属于jvm的debug信息，使用fastdebug版本的jdk才能输出，这也是我选用fastdebug版本jdk做测试的原因），###因为不满足触发条件所以没有触发cms收集过程### openjdk 代码位置ConcurrentMarkSweepGeneration::promotion_attempt_is_safeCMS: promo attempt is safe: available(20971520) >= av_promo(0),max_promo(7148216)2020-05-29 14:59:50 a2 allocate startTwoGenerationCollectorPolicy::mem_allocate_work: attempting locked slow path allocationDefNewGeneration::allocate_from_space(655362): will_fail: false heap_lock: locked free: 1048576 should_allocate_from_space: NOTreturns NULL{Heap before GC invocations=0 (full 0):par new generation total 9216K, used 6980K [0x00000000fe200000, 0x00000000fec00000, 0x00000000fec00000)eden space 8192K, 85% used [0x00000000fe200000, 0x00000000fe8d12b8, 0x00000000fea00000)from space 1024K, 0% used [0x00000000fea00000, 0x00000000fea00000, 0x00000000feb00000)to space 1024K, 0% used [0x00000000feb00000, 0x00000000feb00000, 0x00000000fec00000)concurrent mark-sweep generation total 20480K, used 0K [0x00000000fec00000, 0x0000000100000000, 0x0000000100000000)Metaspace used 4515K, capacity 4638K, committed 4864K, reserved 1056768Kclass space used 447K, capacity 462K, committed 512K, reserved 1048576K4.491: [GC (Allocation Failure) Allocated 0 objects, 0 bytes concurrently4.492: [ParNewlevel=0 invoke=1 size=5242896CMS: promo attempt is safe: available(20971520) >= av_promo(0),max_promo(7148216)Desired survivor size 524288 bytes, new threshold 1 (max 15)- age 1: 1038272 bytes, 1038272 total: 7148216->1048568(9437184), 0.0052765 secs] 7148216->6324312(30408704)Promoted 97 objects, 5265264 bytes Contiguous available 15530664 bytes , 0.0054440 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]Heap after GC invocations=1 (full 0):par new generation total 9216K, used 1023K [0x00000000fe200000, 0x00000000fec00000, 0x00000000fec00000)eden space 8192K, 0% used [0x00000000fe200000, 0x00000000fe200000, 0x00000000fea00000)from space 1024K, 99% used [0x00000000feb00000, 0x00000000febffff8, 0x00000000fec00000)to space 1024K, 0% used [0x00000000fea00000, 0x00000000fea00000, 0x00000000feb00000)concurrent mark-sweep generation total 20480K, used 5152K [0x00000000fec00000, 0x0000000100000000, 0x0000000100000000)Metaspace used 4515K, capacity 4638K, committed 4864K, reserved 1056768Kclass space used 447K, capacity 462K, committed 512K, reserved 1048576K}###3 这里为什么会触发一次呢？上一次是49s触发，理论上来讲应该在52s左右触发，估计得看源码CMS: promo attempt is safe: available(15695776) >= av_promo(5275744),max_promo(6291464)###4 a2 分配完以后打印内存信息，此时eden区内存占用5219K，old区占用5152K2020-05-29 14:59:50 a2 allocated,sleep 4s2020-05-29 14:59:50 ======memory info start=======Code Cache=init = 2555904(2496K) used = 2517568(2458K) committed = 2555904(2496K) max = 251658240(245760K)Metaspace=init = 0(0K) used = 4624936(4516K) committed = 4980736(4864K) max = -1(-1K)Compressed Class Space=init = 0(0K) used = 458088(447K) committed = 524288(512K) max = 1073741824(1048576K)Par Eden Space=init = 8388608(8192K) used = 5345200(5219K) committed = 8388608(8192K) max = 8388608(8192K)Par Survivor Space=init = 1048576(1024K) used = 1048568(1023K) committed = 1048576(1024K) max = 1048576(1024K)CMS Old Gen=init = 20971520(20480K) used = 5275744(5152K) committed = 20971520(20480K) max = 20971520(20480K)2020-05-29 14:59:50 ======memory info end=======###5 cms gc 线程第三次执行，由上面Heap after GC日志可以看出此时old区内存占用率为5152/20480=25%，依然不满足触发条件CMS: promo attempt is safe: available(15695776) >= av_promo(5275744),max_promo(6393768)2020-05-29 14:59:54 a3 allocate startTwoGenerationCollectorPolicy::mem_allocate_work: attempting locked slow path allocationDefNewGeneration::allocate_from_space(1310722): will_fail: false heap_lock: locked free: 8 should_allocate_from_space: NOTreturns NULL2020-05-29 14:59:54 a3 allocated,exit it2020-05-29 14:59:54 ======memory info start=======Code Cache=init = 2555904(2496K) used = 2527680(2468K) committed = 2555904(2496K) max = 251658240(245760K)Metaspace=init = 0(0K) used = 4626464(4518K) committed = 4980736(4864K) max = -1(-1K)Compressed Class Space=init = 0(0K) used = 458088(447K) committed = 524288(512K) max = 1073741824(1048576K)Par Eden Space=init = 8388608(8192K) used = 5345200(5219K) committed = 8388608(8192K) max = 8388608(8192K)Par Survivor Space=init = 1048576(1024K) used = 1048568(1023K) committed = 1048576(1024K) max = 1048576(1024K)CMS Old Gen=init = 20971520(20480K) used = 15761520(15392K) committed = 20971520(20480K) max = 20971520(20480K)2020-05-29 14:59:54 ======memory info end=======###6 cms gc 线程第三次执行，由上面Heap after GC日志可以看出此时old区内存占用率为15761520/20971520=75%，依然不满足触发条件，但是却触发了cms gcCMS: promo attempt is not safe: available(5210000) < av_promo(5275744),max_promo(6393768)CMSCollector: collect because incremental collection will fail 10.498: [GC (CMS Initial Mark) 10.498: [checkpointRootsInitialWork, 0.0015329 secs][1 CMS-initial-mark: 15761520(20971520)] 22155288(30408704), 0.0017536 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]10.500: [CMS-concurrent-mark-start]10.500: [CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]10.500: [CMS-concurrent-preclean-start](modUnionTable: 0 cards)10.500: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]10.500: [CMS-concurrent-abortable-preclean-start]CMS: promo attempt is not safe: available(5210000) < av_promo(5275744),max_promo(6393768)10.500: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]10.500: [GC (CMS Final Remark) [YG occupancy: 6243 K (9216 K)]10.500: [checkpointRootsFinalWork10.500: [Rescan (parallel) , 0.0015643 secs]10.502: [refProcessingWork10.502: [weak refs processing, 0.0000342 secs]10.502: [class unloading, 0.0010723 secs]10.503: [scrub symbol table, 0.0006146 secs]10.504: [scrub string table, 0.0001729 secs], 0.0019787 secs], 0.0049316 secs][1 CMS-remark: 15761520(20971520)] 22155288(30408704), 0.0050250 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]10.505: [CMS-concurrent-sweep-start]Collected 25 objects, 3144 bytesLive 73 objects, 15747896 bytes Already free 123 objects, 5220480 bytesTotal sweep: 20971520 bytesStatistics for BinaryTreeDictionary:------------------------------------Total Free Space: 633548Max Chunk Size: 630611Number of Blocks: 3Av. Block Size: 211182Tree Height: 310.506: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]MetaspaceGC::compute_new_size:minimum_free_percentage: 0.40 maximum_used_percentage: 0.60used_after_gc : 4864.0KBmaximum_free_percentage: 0.70 minimum_used_percentage: 0.30minimum_desired_capacity: 21296.0KB maximum_desired_capacity: 21296.0KBFrom compute_new_size:Free fraction 0.248582Desired free fraction 0.400000Maximum free fraction 0.700000Capactiy 20971Desired capacity 26263Younger gen size 9437unsafe_max_alloc_nogc 5044contiguous available 5044Expand by 5292440 (bytes)Expanded CMS gen for Free ratioExpanded free fraction 0.24858210.506: [CMS-concurrent-reset-start]10.506: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]###7 周期性触发cms gc线程15761520->15758376(20971520)CMS: promo attempt is not safe: available(5213144) < av_promo(5275744),max_promo(6393768)CMSCollector: collect because incremental collection will fail 13.506: [GC (CMS Initial Mark) 13.506: [checkpointRootsInitialWork, 0.0015626 secs][1 CMS-initial-mark: 15758376(20971520)] 22152144(30408704), 0.0017226 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]13.508: [CMS-concurrent-mark-start]13.508: [CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]13.508: [CMS-concurrent-preclean-start](modUnionTable: 0 cards)13.509: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]13.509: [CMS-concurrent-abortable-preclean-start]CMS: promo attempt is not safe: available(5213144) < av_promo(5275744),max_promo(6393768)13.509: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]13.509: [GC (CMS Final Remark) [YG occupancy: 6243 K (9216 K)]13.509: [checkpointRootsFinalWork13.509: [Rescan (parallel) , 0.0015383 secs]13.510: [refProcessingWork13.510: [weak refs processing, 0.0000320 secs]13.511: [class unloading, 0.0014836 secs]13.512: [scrub symbol table, 0.0006510 secs]13.513: [scrub string table, 0.0001597 secs], 0.0024201 secs], 0.0048316 secs][1 CMS-remark: 15758376(20971520)] 22152144(30408704), 0.0048838 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]13.514: [CMS-concurrent-sweep-start]Collected 0 objects, 0 bytesLive 73 objects, 15747896 bytes Already free 79 objects, 5223624 bytesTotal sweep: 20971520 bytesStatistics for BinaryTreeDictionary:------------------------------------Total Free Space: 634511Max Chunk Size: 630611Number of Blocks: 6Av. Block Size: 105751Tree Height: 513.514: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]MetaspaceGC::compute_new_size:minimum_free_percentage: 0.40 maximum_used_percentage: 0.60used_after_gc : 4864.0KBmaximum_free_percentage: 0.70 minimum_used_percentage: 0.30minimum_desired_capacity: 21296.0KB maximum_desired_capacity: 21296.0KBFrom compute_new_size:Free fraction 0.248582Desired free fraction 0.400000Maximum free fraction 0.700000Capactiy 20971Desired capacity 26263Younger gen size 9437unsafe_max_alloc_nogc 5044contiguous available 5044Expand by 5292440 (bytes)Expanded CMS gen for Free ratioExpanded free fraction 0.24858213.514: [CMS-concurrent-reset-start]13.514: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]Heappar new generation total 9216K, used 6243K [0x00000000fe200000, 0x00000000fec00000, 0x00000000fec00000)eden space 8192K, 63% used [0x00000000fe200000, 0x00000000fe718fb0, 0x00000000fea00000)from space 1024K, 99% used [0x00000000feb00000, 0x00000000febffff8, 0x00000000fec00000)to space 1024K, 0% used [0x00000000fea00000, 0x00000000fea00000, 0x00000000feb00000)concurrent mark-sweep generation total 20480K, used 15389K [0x00000000fec00000, 0x0000000100000000, 0x0000000100000000)Metaspace used 4524K, capacity 4638K, committed 4864K, reserved 1056768Kclass space used 448K, capacity 462K, committed 512K, reserved 1048576KClassLoaderData CLD: 0x0000000015895070, loader: 0x00000000feb00000, loader_klass: 0x000000010000fa50 sun/misc/Launcher$ExtClassLoader { claimed handles 0x000000001576a350metaspace: 0x00000000158da150
从gc日志里我写的注释可以看到###6 cms gc 线程第三次执行，由上面Heap after GC日志可以看出此时old区内存占用率为15761520/20971520=75%，依然不满足触发条件，但是却触发了cms gc不满足我之前的第9条预期，带着疑问接下来结合gc日志和openjdk源码尝试解答这个问题。
再看gc日志
CMS: promo attempt is not safe: available(5210000) < av_promo(5275744),max_promo(6393768)CMSCollector: collect because incremental collection will fail 10.498: [GC (CMS Initial Mark) 10.498: [checkpointRootsInitialWork, 0.0015329 secs][1 CMS-initial-mark: 15761520(20971520)] 22155288(30408704), 0.0017536 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]10.500: [CMS-concurrent-mark-start]10.500: [CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]10.500: [CMS-concurrent-preclean-start]
其实日志的开头2行已经说明了原因，只是我知识面比较浅薄不知道cms gc触发不仅仅是“老年代占用率达到CMSInitiatingOccupancyFraction”这一个条件，从日志信息初判是因为老年代剩余空间小于平均晋升大小导致（CMS: promo attempt is not safe: available(5210000) < av_promo(5275744),max_promo(6393768) CMSCollector: collect because incremental collection will fail），这里扯个题外话，正常版本的jdk是打印不出来这种debug信息的，强烈建议下载debug版本的jdk学习jvm，当遇到阻碍的时候根据debug信息去网络上搜索会得到更有价值的信息。
结合日志看源码
\”CMSCollector: collect because incremental collection will fail\”是在concurrentMarkSweepGeneration.cpp中shouldConcurrentCollect方法输出的，简单读一下源码：
- 如果发生了full gc会触发，看下面日志是调用了System.gc或者gc_locker（这个没明白是什么场景）
//如果发生了full gc，看下面日志是调用了System.gc或者gc_locker（这个没明白是什么场景）if (_full_gc_requested) {if (Verbose && PrintGCDetails) {gclog_or_tty->print_cr(\"CMSCollector: collect because of explicit \"\" gc request (or gc_locker)\");}return true;}
2.如果没有指定UseCMSInitiatingOccupancyOnly参数，jdk就按自己的规则来决定老年代当前的利用率是否会触发gc，这里分两种情况：
2.1 根据历史数据做预测，如果cms执行完gc需要的时间大于老年代被填满的时间那就触发gc，具体的判断逻辑在time_until_cms_start中；
2.2 没有历史数据的时候判断老年代利用率是否大于_bootstrap_occupancy，_bootstrap_occupancy是根据CMSBootstrapOccupancy计算出来的
// If the estimated time to complete a cms collection (cms_duration())// is less than the estimated time remaining until the cms generation// is full, start a collection./**如果没有指定UseCMSInitiatingOccupancyOnly参数，jdk就按自己的规则来决定老年代当前的利用率是否会触发gc分两种情况：1.根据历史数据做预测，如果cms执行完gc需要的时间大于老年代被填满的时间那就触发gc，具体的判断逻辑在time_until_cms_start中2.没有历史数据的时候判断老年代利用率是否大于_bootstrap_occupancy，_bootstrap_occupancy是根据CMSBootstrapOccupancy计算出来的_bootstrap_occupancy = ((double)CMSBootstrapOccupancy)/(double)100，CMSBootstrapOccupancy是一个可传递参数，默认值为50*/if (!UseCMSInitiatingOccupancyOnly) {//cms gc 只要被触发一次stats().valid()就会返回trueif (stats().valid()) {if (stats().time_until_cms_start() == 0.0) {return true;}} else {//下面的这段逻辑只会被触发一次// We want to conservatively collect somewhat early in order// to try and \"bootstrap\" our CMS/promotion statistics;// this branch will not fire after the first successful CMS// collection because the stats should then be valid.if (_cmsGen->occupancy() >= _bootstrap_occupancy) {if (Verbose && PrintGCDetails) {gclog_or_tty->print_cr(\" CMSCollector: collect for bootstrapping statistics:\"\" occupancy = %f, boot occupancy = %f\", _cmsGen->occupancy(),_bootstrap_occupancy);}return true;}}}
3.执行ConcurrentMarkSweepGeneration::should_concurrent_collect判断逻辑，分以下几种情况：
3.1 老年代利用率大于_initiating_occupancy会触发gc，_initiating_occupancy的值在CMSCollector被构造的时候通过CMSInitiatingOccupancyFraction计算出来；
3.2 发生了扩容需要触发gc；
3.3 _cmsSpace(CompactibleFreeListSpace)->should_concurrent_collect（这块没看明白）。
// Otherwise, we start a collection cycle if// old gen want a collection cycle started. Each may use// an appropriate criterion for making this decision.// XXX We need to make sure that the gen expansion// criterion dovetails well with this. XXX NEED TO FIX THISif (_cmsGen->should_concurrent_collect()) {if (Verbose && PrintGCDetails) {gclog_or_tty->print_cr(\"CMS old gen initiated\");}return true;}
bool ConcurrentMarkSweepGeneration::should_concurrent_collect() const {assert_lock_strong(freelistLock());//老年代利用率大于initiating_occupancyif (occupancy() > initiating_occupancy()) {if (PrintGCDetails && Verbose) {gclog_or_tty->print(\" %s: collect because of occupancy %f / %f \",short_name(), occupancy(), initiating_occupancy());}return true;}if (UseCMSInitiatingOccupancyOnly) {return false;}//发生了扩容if (expansion_cause() == CMSExpansionCause::_satisfy_allocation) {if (PrintGCDetails && Verbose) {gclog_or_tty->print(\" %s: collect because expanded for allocation \",short_name());}return true;}//没看明白if (_cmsSpace->should_concurrent_collect()) {if (PrintGCDetails && Verbose) {gclog_or_tty->print(\" %s: collect because cmsSpace says so \",short_name());}return true;}return false;}
4.执行gch->incremental_collection_will_fail判断逻辑，本质上是预测young gc是否会失败，这里的预测标准有以下几种：
4.1 最近一次已经是失败的；
4.2 最近一次未失败，继续询问年轻代是否会失败（DefNewGeneration::collection_attempt_is_safe()），年轻代的判断逻辑如下：
4.2.1 如果to区不为空，认为收集可能会失败（和to区是否为空有啥关系呢？）
4.2.2 询问老年代晋升是否会失败（ConcurrentMarkSweepGeneration::promotion_attempt_is_safe），老年代判断剩余空间大小是否大于平均晋升空间大小或者大于当前年轻代使用的空间大小；
// We start a collection if we believe an incremental collection may fail;// this is not likely to be productive in practice because it\'s probably too// late anyway.GenCollectedHeap* gch = GenCollectedHeap::heap();assert(gch->collector_policy()->is_two_generation_policy(),\"You may want to check the correctness of the following\");//if (gch->incremental_collection_will_fail(true /* consult_young */)) {if (Verbose && PrintGCDetails) {gclog_or_tty->print(\"CMSCollector: collect because incremental collection will fail \");}return true;}
// Returns true if an incremental collection is likely to fail.// We optionally consult the young gen, if asked to do so;// otherwise we base our answer on whether the previous incremental// collection attempt failed with no corrective action as of yet.bool incremental_collection_will_fail(bool consult_young) {// Assumes a 2-generation system; the first disjunct remembers if an// incremental collection failed, even when we thought (second disjunct)// that it would not.assert(heap()->collector_policy()->is_two_generation_policy(),\"the following definition may not be suitable for an n(>2)-generation system\");return incremental_collection_failed() ||(consult_young && !get_gen(0)->collection_attempt_is_safe());}
bool DefNewGeneration::collection_attempt_is_safe() {if (!to()->is_empty()) {if (Verbose && PrintGCDetails) {gclog_or_tty->print(\" :: to is not empty :: \");}return false;}if (_next_gen == NULL) {GenCollectedHeap* gch = GenCollectedHeap::heap();_next_gen = gch->next_gen(this);}return _next_gen->promotion_attempt_is_safe(used());}
bool ConcurrentMarkSweepGeneration::promotion_attempt_is_safe(size_t max_promotion_in_bytes) const {size_t available = max_available();size_t av_promo = (size_t)gc_stats()->avg_promoted()->padded_average();bool res = (available >= av_promo) || (available >= max_promotion_in_bytes);if (Verbose && PrintGCDetails) {gclog_or_tty->print_cr(\"CMS: promo attempt is%s safe: available(\"SIZE_FORMAT\") %s av_promo(\"SIZE_FORMAT\"),\"\"max_promo(\"SIZE_FORMAT\")\",res? \"\":\" not\", available, res? \">=\":\"<\",av_promo, max_promotion_in_bytes);}return res;}
5.判断MetaspaceGC _should_concurrent_collect标识
//5 读取should_concurrent_collect标识if (MetaspaceGC::should_concurrent_collect()) {if (Verbose && PrintGCDetails) {gclog_or_tty->print(\"CMSCollector: collect for metadata allocation \");}return true;}return false;}
云里雾里
到这儿虽然有一些细节问题我还打着问号，但是也算是解决了心中的疑惑，触发cms gc的条件有好多个，大体归纳为以下几种：
1.发生了full gc，比如代码里显示的调用System.gc；
2.没有指定UseCMSInitiatingOccupancyOnly参数的时候jvm根据状态数据决定是否要触发gc，大原则就是在老年代填满之前触发gc将空间腾出来；
3.老年代利用率达到了CMSInitiatingOccupancyFraction或者老年代发生了扩容等；
4.ygc可能不安全，主要还是担心老年代剩余空间不足以容纳晋升对象（我这个小实验中就是因为这个条件触发了cms gc）；
5.元空间_should_concurrent_collect标识为true；
总结
对任何参数的使用一定要经过亲自验证，否则直接应用到生产环境可能会带来不可预料的损失，如果发现和预期效果不一样那就去一步一步证实、论证，在互联网蓬勃发展的今天几乎任何问题都能找到蛛丝马迹，除非自己懒。这里再啰嗦一句，面对信息爆炸的时代如何甄别自己得到的信息是正确的呢？“纸上得来终觉浅,绝知此事要躬行”，多做实验多看源码才是学习的好办法。
参考资料
JVM发生CMS GC的 5 种情况，你知道的肯定不全！
garbage-collection-algorithms-implementations#concurrent-mark-and-sweep
