本文是一次线上的FGC分析及原理剖析。通过本文,可以深入的了解FGC,堆外Buffer和Buffer Pool的设计。
1 背景
运维通知,线上系统一直在FGC,通过zabbix查看GC 的次数
再查看YGC和FGC空间占用情况
这里有几个疑问:
1:old space 空间一直很低,为什么会有频繁的FGC?
2:Eden space 回收的阈值为什么越来越低,越来越频繁?
3:从Eden space空间看一直在YGC,但是从YGC的次数看并没有过YGC?
4:FGC的越来越频繁,到最后为什么一直在FGC?
第一个问题
通过查看打印出来的ERROR日志,确定是Direct buffer 不够。在申请DirectByteBuffer的时候,会检查是否还有空闲的空间,剩余空间不够,则会调用system.gc,引起FGC(具体后续会详细介绍)。这里可以解释old space很低,但是一直FGC。并不是old区不够用,而是堆外空间不够用。
第二个问题
FGC是对整个堆进行GC(包含eden space,old space,perm space),FGC越来越频繁,会导致eden space 回收的越来越频繁。 正常的YGC触发是新建对象,申请不到eden space空间,才会进行YGC,但是这里是FGC引起的YGC,所以并不是eden space满了才会进行YGC。
第三个问题
统计YGC的次数一般是通过JMX或者日志方式统计。
JMX统计方式: 通过查询java.lang:type=GarbageCollector,name=PS MarkSweep 的CollectionCount
日志方式:统计YGC日志出现的次数。下面为YGC的日志。
[GC2016-11-26T00:05:50.539+0800: 36.542: [ParNew: 3355520K->34972K(3774912K), 0.0249160 secs] 3355520K->34972K(7969216K), 0.0250290 secs] [Times: user=0.31 sys=0.00, real=0.03 secs]
FGC引起的Eden space 回收没有打印YGC日志或者 CollectionCount的增加。
第四个问题
申请DirectByteBuffer,会新建cleaner对象(负责资源的回收)。在GC时,会释放没有引用的DirectByteBuffer。开始GC会释放掉部分空间,但是后面越来越频繁,直到一直FGC。说明分配的堆外空间已经被全部使用,每次申请DirectByteBuffer都会导致FGC。
通过日志发现使用的是netty的buffer pool,基本上可以确定是某个地方在拿到DirectByteBuffer,没有归还导致的堆外内存泄露。
2 FGC日志分析
[Full GC2016-11-26T00:07:22.259+0800: 128.262: [CMS: 43613K->43670K(4194304K), 0.1500870 secs] 82477K->43670K(7969216K), [CMS Perm : 29810K->29810K(262144K)], 0.1501840 secs] [Times: user=0.15 sys=0.00, real=0.15 secs]
上述日志时候调用system.gc打印出来的。可以看到user=real=0.15,可知是只有一个线程在进行FGC,导致STW。
有如下问题
1 : user和real有什么区别
2:是哪一个线程在进行FGC
3:这里FGC是否有优化的空间
第一个问题
real代表真实的时间消耗,user代表是所有cpu相加的时间消耗。如果相等,说明只有一个线程在GC。 如果日志如下:[Times: user=0.31 sys=0.00, real=0.03 secs] 说明将近有10个线程在进行gc。
第二个问题
System.gc(),实际上是封装了一个_java_lang_system_gc操作放到VMThread的队列上,VMThread会扫描队列,做对应的操作。这里可以判定FGC的线程是VMThread。
VMThread线程是JVM线程,该线程会一直扫描VM_operation的队列。内存分配失败或者system.gc等,都会封装一个操作放到VM_operation队列上。VMThread在对GC等操作执行的时候,会让业务线程都进入到安全点进行阻塞。操作完成后,会让业务线程离开安全点继续做业务操作。
安全点等信息可查看:JVM的Stop The World,安全点,黑暗的地底世界
第三个问题
在old区是cms的情况下影响system.gc()的主要有2个jvm属性:DisableExplicitGC和ExplicitGCInvokesConcurrent
具体详细信息参考: JVM源码分析之SystemGC完全解读
下面对gc做一个梳理(jdk7和开启CMS)