言归正传,今天有个同事找我,其实好像之前就找过我,一直因为太忙,后面就忘记他的事了,到今天还没查出原因就又找了过来,现象是系统老是进行Full GC,在启动没过多久就会发生Full GC,这个现象相对比较少见的,于是找他要了GC日志,赫然看到如下日志:
这个很显然就是达到了Metaspace的阈值触发的Full GC了,但是看看Metaspace的size,使用了134M左右,于是我询问他MetaspaceSize和MaxMetaspaceSize分别设置了多少,告知我设置的是256M,那就有几个比较奇怪的地方了:
- 为什么启动没多久就因为Metaspace触发了Full GC
- 从使用率来看并没有达到阈值
- 在Full GC之后立马就能正常运行一段时间,说明Metaspace确实回收了
先说个JVM的BUG
从上面的GC日志,我们看到了Full GC前后,Metaspace的使用变化是从137752K->71671K,其实你们如果用的oracle官方的JDK,看到的会是137752K->137752K,也就是并没有发生变化,看起来好像Metaspace并没有被回收,其实这是JVM的一个BUG,我们alijdk将这个问题进行了修复,能看到前后是有变化的,所以如果大家在排查Metaspace的问题时候,希望不要被这个信息骗到
再聊点GC日志
从JDK8开始,任何GC,都会默认打印GC Cause,所以你看到上面的Full GC是因为Metadata GC Threshold触发的,也就是Metaspace committed的内存加上这次要分配的内存达到了MetaspaceSize的阈值。如果是JDK7(之前版本不支持),那可以通过加JVM参数-XX:+PrintGCCause来打印原因,可以通过下面的图片小程序链接点进去看看这个参数的具体用法及含义:
再提一点,Metaspce触发的GC都是Full GC。
另外大家常看到的类似下面的Allocation Failure的GC Cause,其实是正常的,因为大部分GC,尤其是YGC,都是因为分配内存失败才触发的,所以不要认为看到Failure就觉得有问题。
为何使用率这么低就触发了Full GC
Metaspace触发Full GC,是因为Metaspace committed的内存加上这次要分配的内存之和超过了阈值才会触发,但是我们看使用了才134M,而阈值却是256M,那可能怀疑下面两种情况:
这次分配的内存达到122M以上?
碎片化问题?
对于***种情况,基本不太可能,因为一个类不可能要这么大内存,所以暂时先排除这种可能。
对于第二种情况,有一个场景是能满足的,类加载器创建非常多,但是每个类加载器加载的类又特别少,同时Full GC之后又能很快被回收掉
为了验证第二种情况,我尝试加两个参数-XX:+HeapDumpBeforeFullGC和-XX:+HeapDumpAfterFullGC,在Full GC前后分别对内存做一个dump,这两个参数,可以通过下面的图片小程序链接看到具体的使用情况
从两个dump的分析结果来看,查了下类加载器的情况,果然在Full GC之前看到了31650个类加载器,而Full GC之后,类加载器个数变成了872个,于是开始找究竟是哪些类加载器,最终发现某个特定类型的类加载器对象非常之多,咨询了业务方确实存在这种情况,因为没有做好缓存,所以导致了无止境创建
类加载器过多为什么会导致Full GC
类加载器创建过多,带来的一个问题是,在类加载器***次加载类的时候,会在Metaspace里会给它分配内存块,为了分配高效,每个类加载器用来存放类信息的内存块都是独立的,所以哪怕你这个类加载器只加载一个类,也会为之分配一块空的内存给这个类加载器,其实是至少两个内存块,于是你有可能会发现Metaspace的内存使用率非常低,但是committed的内存已经达到了阈值,从而触发了Full GC,如果这种只加载很少类的类加载器非常多,那造成的后果就是很多碎片化的内存
JVMPocket介绍
JVMPocket是我最近捣鼓的一个微信小程序,大家可以通过搜索JVMPocket或者从我公众号菜单里进入,该小程序主要缘因JVM参数而诞生,有人问我相关的问题,告诉他们什么参数可以解决,但是苦于参数太长而无法记住,特尴尬,有了JVMPocket之后,直接找到对应的参数发个链接过去就可以看到对应参数的具体含义,用法,默认值以及大家的使用建议等,希望该小程序也能帮到大家,大家如果自己的JVM参数经验,都可以到对应的参数下面留言让更多人知道它背后的故事。
JVMPocket
JVM参数锦囊
【本文是51CTO专栏作者李嘉鹏的原创文章,转载请通过微信公众号(你假笨,id:lovestblog)联系作者本人获取授权】