本文记录堆内存OOM的排查过程。周末,我的同事扩展了在线服务。我认为这只是一些实例的简单添加。结果新实例收到流量后就疯狂报警,只好马上断线。查看日志后发现如下错误:jstat命令查看GC信息发现有很多fullgc,因为线上服务部署在k8s集群,实例运行在docker环境,镜像还没有以任何方式修改,这张图片已经上线近一个月了。为什么在线服务和新添加的服务都没有问题?实例变得疯狂并报了警。带着一头雾水,我想起了之前排查线上性能问题的各种手段。看来他们都对排查堆外内存问题束手无策。周末一直在思考这个问题,也做了一些尝试,但都无果。一转眼,周一到了。到公司后,第一时间查看了一些相关参数,看到了在线服务。我吃了一惊。在线服务的堆外内存也快满了(6G上限),生怕在线服务全部挂掉。失去。静下心来想一想我们服务中有哪些模块使用了堆外内存。首先想到的是我们的RPC框架,因为netty底层使用的是堆外内存。为了验证这个问题,我还查看了另外一组非常相似的下游服务,结果发现这个服务的堆外内存占用很小,只有20M左右,排除了RPC组件的问题。为了看到堆外内存的增长曲线,我将在线服务扩展到另一个副本,发现了一个重要的线索。实例启动成功后,堆外内存基本接近上限。然后流量模拟就省略了,于是在本地启动了一个服务查看内存使用情况,发现启动阶段堆外内存暴涨,达到一定水平后稳定下来,于是使用了排除注释疑似问题组件的方法我很快定位到公司的一个存储服务jar包,在本地进行了一次内存转储,因为这个jar包没有使用netty,所以必须使用DirectByteBuffer,所以在VisualVM中分析dump发现DirectByteBuffer的持有者集中在存储服务客户端的连接对象NioChannel上。下一步是反编译连接对象。查找了ByteBuffer#allocateDirect方法后,很快发现了一个问题。初始化对象时,会应用一个4M的堆。外存,也就是说每个链接在初始化的时候需要申请4M堆外内存,所以我们执行jmap-histo查看我们在线服务的对象数统计,发现有在线服务中多达1451个NioChannel对象,如下图粗略计算,每个对象持有4M堆外内存,而这1451个对象需要5804M的近6G堆外内存。问题一下子就清楚了。可以断定是线上堆外内存的问题。找到代码,发现这个链接的buffer是可以设置的。联系了存储的同学,对方说buffer可以设小一点,效果不大。为什么只有我们遇到这个问题?原来我们的连接数比较多,连接数过多的问题其实是我们的业务造成的,没有改进的余地。所以目前解决这个问题的办法只有很小的缓冲。至此,堆外内存占用过多的问题已经解决,那么fullgc过多的问题是什么呢?在线gc日志已打开。拉下一份看一下,如下图:可以看到一个比较明显的问题,在fgc之前,oldgeneration远远没有达到fgc的阈值。触发fgc的原因是有些代码调用了System.gc(),而我们并没有刻意设置-XX:+DisableExplicitGC,也不想设置这个参数。然后您需要检查System.gc()调用的位置。在网上查资料的时候,在这里无意间发现了一条线索:在初始化一个DirectByteBuffer对象时,它会在一定条件下主动调用System.gc()。查看了jdk的源码,发现在ByteBuffer#allocateDirect的过程中确实有System.gc()的调用。对比上图1中的调用栈,可以确定这里触发了fgc。也就是说fgc的问题其实是堆外内存OOM的一个副产品,可以解决堆外内存的OOM问题。至此,问题的原因已经排查清楚。那么为什么旧实例和新实例的行为不同呢?在线实例没有OOM错误日志。问题的关键是存储服务的客户端在初始化后并没有发生变化。数量太大,刚好达到6G堆外内存的上限,而netty的堆外内存是动态申请的,初始化时间比前者晚。当请求进来,申请堆外内存时没有可用的堆外内存,就会触发fgc,最终抛出OOM。
