CMS 触发GC(Allocation Failure)解析

       针对GC中发生的"Allocation Failure"，源码描述为：Allocation Failure is a cause of GC cycle to kick in.        "Allocation Failure" means that no more space left in Eden to allocate object. So, it is normal cause of young GC.        Older JVM were not printing GC cause for minor GC cycles.        "Allocation Failure" is almost only possible cause for minor GC. Another reason for minor GC to kick could be CMS remark phase (if +XX:+ScavengeBeforeRemark is enabled).

       分代收集器：

       ParNew：一款多线程的收集器，采用复制算法，主要工作在 Young 区，可以通过使用

-XX:ParallelGCThreads 参数来控制收集的线程数，整个过程都是STW的，常与CMS组合使用。

       CMS：以获取最短回收停顿时间为目标，采用“标记-清除”算法，分 4 大步进行垃圾收集，其中初始标记和重新标记会 STW ，多数应用于互联网站或者 B/S 系统的服务器端上，JDK9 被标记弃用，JDK14 被删除，详情可见 JEP 363

•  业务场景
• 
  
• 
  

393537.923: [GC (Allocation Failure) 393537.923: [ParNew: 277920K->5804K(306688K), 0.0254145 secs] 1619294K->1347211K(2063104K), 0.0257722 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
394659.416: [GC (Allocation Failure) 394659.416: [ParNew: 278444K->5412K(306688K), 0.0189196 secs] 1619851K->1346850K(2063104K), 0.0192075 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
395824.591: [GC (Allocation Failure) 395824.591: [ParNew: 278052K->5905K(306688K), 0.0227978 secs] 1619490K->1347361K(2063104K), 0.0231599 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
396658.661: [GC (Allocation Failure) 396658.661: [ParNew: 278545K->4291K(306688K), 0.0194256 secs] 1620001K->1345779K(2063104K), 0.0197811 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
397674.141: [GC (Allocation Failure) 397674.141: [ParNew: 276931K->5287K(306688K), 0.0213385 secs] 1618419K->1346807K(2063104K), 0.0216235 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]

• 
  
•    日志解析
• GC：前面没有Full修饰，表明此应用服务进行了一次Minor GC 。注意它不表示只GC新生代，并且现有的不管是新生代还是老年代都会STW。        
• Allocation Failure: 表明引起本次应用GC的原因是因为在年轻代中没有足够的空间能够存储新的数据。        
• ParNew: 表明本次GC发生在年轻代并且使用的是ParNew垃圾收集器。ParNew是一个Serial收集器的多线程版本，会使用多个CPU和线程完成垃圾收集工作（默认使用的线程数和CPU数相同，可以使用-XX：ParallelGCThreads参数限制）。该收集器采用复制算法回收内存，期间会停止其他工作线程，即Stop The World。        
• 277920K->5804K(306688K)：单位为KB。三个参数分别为：GC前该内存区域(这里是年轻代)使用容量，GC后该内存区域使用容量，该内存区域总容量。        
• 0.0254145 secs：表明内存区域GC耗时，单位是秒。        
• 1619294K->1347211K(2063104K)：三个参数分别为：堆区垃圾回收前的大小，堆区垃圾回收后的大小，堆区总大小。        
• 0.0257722 secs：该内存区域GC耗时，单位是秒。        
• [Times: user=0.05 sys=0.00, real=0.02 secs]：分别表示用户态耗时，内核态耗时以及总耗时
• 根据gc log文件分析可以得出结论：        
• （1）该次GC新生代减少了277920K - 5804K = 272116K        
• （2）该次GC Heap区总共减少了1619294K - 1347211K = 272083K        272116 – 272083 = 33K，说明该次共有33K内存从年轻代移到了老年代，可以得出数量并不多，说明都是生命周期短的对象，只是这种对象较多。
•  
•    解决方案

     (1)   尽量避免Full GC的发生，让对象尽可能的在年轻代就回收掉，此处，可适当增加年轻代-Xmn的大小，让那33K的数据也保存在年轻代中。        

     (2)   优化分析代码，将可疑对象揪出来。