參考文檔：Java Collectors
[GC [< collector >: < starting occupancy1 > -> < ending occupancy1 >, < pause time1 > secs] < starting occupancy3 > -> < ending occupancy3 >, < pause time3 > secs]
< collector >? ? ? ? ? ? ? ? ? ? ? GC收集器的名稱
< starting occupancy1 >? ? 新生代在GC前占用的內(nèi)存
< ending occupancy1 >? ? 新生代在GC后占用的內(nèi)存
< pause time1 >? ? ? ? ? ? ? ? 新生代局部收集時(shí)jvm暫停處理的時(shí)間
< starting occupancy3 >? ? JVM Heap 在GC前占用的內(nèi)存
< ending occupancy3 >? ? JVM Heap 在GC后占用的內(nèi)存
< pause time3 >? ? ? ? ? ? ? ? GC過程中jvm暫停處理的總時(shí)間
執(zhí)行參數(shù)：
-Xms128M -Xmx256M -XX:PermSize=64M -XX:MaxPermSize=64M -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSParallelRemarkEnabled -XX:+ParallelRefProcEnabled -XX:+CMSClassUnloadingEnabled? -XX:CMSInitiatingOccupancyFraction=80 -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSFullGCsBeforeCompaction=5 -XX+UseCMSCompactAtFullCollection -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError
所以：
PermSize=67108864（非堆內(nèi)存大小梯影，Perm代大行寄）
InitialHeapSize=134217728（初始化堆內(nèi)存大卸㈣搿）
MaxHeapSize=268435456 （最大堆內(nèi)存大谢娉痢）
NewSize=89481216（Young代內(nèi)存大星现辍）
MaxNewSize=89481216（Young代內(nèi)存最大大小）
OldSize=178954240（Old代內(nèi)存大小）
正常的CMS處理流程：
2017-03-15T19:00:24.845+0800: 9.826: [GC [1 CMS-initial-mark: 36126K(43712K)] 44831K(122368K), 0.0220800 secs] [Times: user=0.05 sys=0.02, real=0.02 secs]
2017-03-15T19:00:24.868+0800: 9.848: [CMS-concurrent-mark-start]
2017-03-15T19:00:25.130+0800: 10.110: [CMS-concurrent-mark: 0.256/0.262 secs] [Times: user=0.45 sys=0.14, real=0.26 secs]
2017-03-15T19:00:25.130+0800: 10.110: [CMS-concurrent-preclean-start]
2017-03-15T19:00:25.130+0800: 10.111: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2017-03-15T19:00:25.131+0800: 10.111: [CMS-concurrent-abortable-preclean-start]
2017-03-15T19:00:25.475+0800: 10.455: [GC2017-03-15T19:00:25.475+0800: 10.455: [ParNew: 78656K->8704K(78656K), 0.1270550 secs] 114782K->47719K(122368K), 0.1272540 secs] [Times: user=0.29 sys=0.02, real=0.12 secs]
2017-03-15T19:00:25.898+0800: 10.878: [CMS-concurrent-abortable-preclean: 0.270/0.767 secs] [Times: user=2.42 sys=0.06, real=0.77 secs]
2017-03-15T19:00:25.904+0800: 10.884: [GC[YG occupancy: 63473 K (78656 K)]2017-03-15T19:00:25.904+0800: 10.884: [Rescan (parallel) , 0.0750590 secs]2017-03-15T19:00:25.979+0800: 10.960: [weak refs processing, 0.0104990 secs]2017-03-15T19:00:25.990+0800: 10.970: [class unloading, 0.0014200 secs]2017-03-15T19:00:25.991+0800: 10.972: [scrub symbol table, 0.0028960 secs]2017-03-15T19:00:25.994+0800: 10.975: [scrub string table, 0.0006860 secs] [1 CMS-remark: 39015K(43712K)] 102488K(122368K), 0.0912600 secs] [Times: user=0.34 sys=0.00, real=0.09 secs]
2017-03-15T19:00:25.999+0800: 10.979: [CMS-concurrent-sweep-start]
2017-03-15T19:00:26.024+0800: 11.004: [CMS-concurrent-sweep: 0.024/0.025 secs] [Times: user=0.09 sys=0.00, real=0.03 secs]
2017-03-15T19:00:26.024+0800: 11.004: [CMS-concurrent-reset-start]
2017-03-15T19:00:26.027+0800: 11.007: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
說(shuō)明：
【初始化記錄，會(huì)停頓】[GC [1 CMS-initial-mark: 當(dāng)前old代大小 (old代容量) ] 當(dāng)前堆內(nèi)大小 (堆容量)
【標(biāo)記開始】
【標(biāo)記結(jié)束及耗時(shí)】
【預(yù)清理開始】
【預(yù)清理結(jié)束】
【可中斷預(yù)清理開始】
【執(zhí)行了ParNew GC】[ParNew: 當(dāng)前Young代大小->回收后Young代大小(Young代容量), 0.1270550 secs] 回收前堆的大小->回收后堆的大小(堆的容量)
【可中斷預(yù)清理結(jié)束】
【CMS處理過程悯搔，在remark時(shí)會(huì)停頓】
【清理開始】
【清理結(jié)束】
【重置開始】
【重置結(jié)束】
惡化流程分析：
查詢整個(gè)GC Log，找到惡化銜接點(diǎn)：
2017-03-16T13:19:17.213+0800: 65942.193: [GC2017-03-16T13:19:17.214+0800: 65942.194: [ParNew: 78656K->78656K(78656K), 0.0000890 secs]2017-03-16T13:19:17.214+0800: 65942.194: [CMS: 171692K->174783K(174784K), 1.0692500 secs] 250348K->179670K(253440K), [CMS Perm : 55543K->55525K(65536K)], 1.0706310 secs] [Times: user=12.60 sys=0.00, real=1.07 secs] 【想要通過GC舌仍，騰空Young妒貌，但是明顯Old也不夠地方了，要開始對(duì)Old做CMS】
2017-03-16T13:19:18.287+0800: 65943.267: [GC [1 CMS-initial-mark: 174783K(174784K)] 179700K(253440K), 0.0125980 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
···
2017-03-16T13:19:19.074+0800: 65944.055: [GC[YG occupancy: 5318 K (78656 K)]2017-03-16T13:19:19.075+0800: 65944.055: [Rescan (parallel) , 0.0074880 secs]2017-03-16T13:19:19.082+0800: 65944.062: [weak refs processing, 0.0027200 secs]2017-03-16T13:19:19.085+0800: 65944.065: [class unloading, 0.0067020 secs]2017-03-16T13:19:19.092+0800: 65944.072: [scrub symbol table, 0.0140110 secs]2017-03-16T13:19:19.106+0800: 65944.086: [scrub string table, 0.0014150 secs] [1 CMS-remark: 174783K(174784K)] 180102K(253440K), 0.0345230 secs] [Times: user=0.00 sys=0.00, real=0.03 secs]
···
2017-03-16T13:19:19.247+0800: 65944.227: [CMS-concurrent-reset: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
至
2017-03-16T14:30:00.068+0800: 70185.049: [GC [1 CMS-initial-mark: 174553K(174784K)] 253175K(253440K), 0.1776490 secs] [Times: user=0.18 sys=0.00, real=0.18 secs]
2017-03-16T14:30:00.248+0800: 70185.228: [CMS-concurrent-mark-start]
2017-03-16T14:30:00.249+0800: 70185.229: [GC2017-03-16T14:30:00.250+0800: 70185.230: [ParNew: 78656K->78656K(78656K), 0.0000570 secs]2017-03-16T14:30:00.250+0800: 70185.230: [CMS2017-03-16T14:30:00.623+0800: 70185.604: [CMS-concurrent-mark: 0.364/0.375 secs] [Times: user=0.38 sys=0.00, real=0.38 secs]
(concurrent mode failure): 174553K->174784K(174784K), 1.6327610 secs] 253209K->185593K(253440K), [CMS Perm : 55528K->55525K(65536K)], 1.6338660 secs] [Times: user=1.62 sys=0.00, real=1.64 secs] 【concurrent mode failure铸豁，CMS回收Old代速度太慢了灌曙，CMS工作完成前Old已經(jīng)被填滿了，需要降低CMSInitiatingOccupancyFraction】
2017-03-16T14:30:02.137+0800: 70187.117: [GC [1 CMS-initial-mark: 174784K(174784K)] 202184K(253440K), 0.0560980 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
···
2017-03-16T14:30:02.944+0800: 70187.925: [GC[YG occupancy: 29953 K (78656 K)]2017-03-16T14:30:02.945+0800: 70187.925: [Rescan (parallel) , 0.0363880 secs]2017-03-16T14:30:02.981+0800: 70187.961: [weak refs processing, 0.0018180 secs]2017-03-16T14:30:02.983+0800: 70187.963: [class unloading, 0.0068980 secs]2017-03-16T14:30:02.990+0800: 70187.970: [scrub symbol table, 0.0135000 secs]2017-03-16T14:30:03.003+0800: 70187.984: [scrub string table, 0.0014260 secs] [1 CMS-remark: 174784K(174784K)] 204737K(253440K), 0.0619150 secs] [Times: user=0.17 sys=0.00, real=0.06 secs]
···
2017-03-16T14:30:03.153+0800: 70188.133: [CMS-concurrent-reset: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
