一次完整的JVM堆外内存泄漏故障排查记录

前言记录一次线上JVM堆外内存泄漏问题的排查过程与思路,其中夹带一些「JVM内存分配机制」以及「常用的JVM问题排查指令和工具分享」,希望对大家有所帮助 。
在整个排查过程中,我也走了不少弯路,但是在文章中我仍然会把完整的思路和想法写出来,当做一次经验教训,给后人参考,文章最后也总结了下内存泄漏问题快速排查的几个原则 。
「本文的主要内容:」

  • 故障描述和排查过程
  • 故障原因和解决方案分析
  • JVM堆内内存和堆外内存分配原理
  • 常用的进程内存泄漏排查指令和工具介绍和使用
?
文章撰写不易,请大家多多支持我的原创技术公众号:后端技术漫谈
?
故障描述8月12日中午午休时间,我们商业服务收到告警,服务进程占用容器的物理内存(16G)超过了80%的阈值,并且还在不断上升 。
一次完整的JVM堆外内存泄漏故障排查记录

文章插图
 
监控系统调出图表查看:
一次完整的JVM堆外内存泄漏故障排查记录

文章插图
 
像是JAVA进程发生了内存泄漏,而我们堆内存的限制是4G,这种大于4G快要吃满内存应该是JVM堆外内存泄漏 。
确认了下当时服务进程的启动配置:
-Xms4g -Xmx4g -Xmn2g -Xss1024K -XX:PermSize=256m -XX:MaxPermSize=512m -XX:ParallelGCThreads=20 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+UseCMSCompactAtFullCollection -XX:CMSInitiatingOccupancyFraction=80虽然当天没有上线新代码,但是「当天上午我们正在使用消息队列推送历史数据的修复脚本,该任务会大量调用我们服务其中的某一个接口」,所以初步怀疑和该接口有关 。
下图是该调用接口当天的访问量变化:
一次完整的JVM堆外内存泄漏故障排查记录

文章插图
 
可以看到案发当时调用量相比正常情况(每分钟200+次)提高了很多(每分钟5000+次) 。
「我们暂时让脚本停止发送消息,该接口调用量下降到每分钟200+次,容器内存不再以极高斜率上升,一切似乎恢复了正常 。」
接下来排查这个接口是不是发生了内存泄漏 。
排查过程首先我们先回顾下Java进程的内存分配,方便我们下面排查思路的阐述 。
「以我们线上使用的JDK1.8版本为例」 。JVM内存分配网上有许多总结,我就不再进行二次创作 。
JVM内存区域的划分为两块:堆区和非堆区 。
  • 堆区:就是我们熟知的新生代老年代 。
  • 非堆区:非堆区如图中所示,有元数据区和直接内存 。

一次完整的JVM堆外内存泄漏故障排查记录

文章插图
 
「这里需要额外注意的是:永久代(JDK8的原生去)存放JVM运行时使用的类,永久代的对象在full GC时进行垃圾收集 。」
复习完了JVM的内存分配,让我们回到故障上来 。
堆内存分析虽说一开始就基本确认与堆内存无关,因为泄露的内存占用超过了堆内存限制4G,但是我们为了保险起见先看下堆内存有什么线索 。
我们观察了新生代和老年代内存占用曲线以及回收次数统计,和往常一样没有大问题,我们接着在事故现场的容器上dump了一份JVM堆内存的日志 。
堆内存Dump堆内存快照dump命令:
jmap -dump:live,format=b,file=xxxx.hprof pid
?
画外音:你也可以使用jmap -histo:live pid直接查看堆内存存活的对象 。
?
导出后,将Dump文件下载回本地,然后可以使用Eclipse的MAT(Memory Analyzer)或者JDK自带的JVisualVM打开日志文件 。
使用MAT打开文件如图所示:
一次完整的JVM堆外内存泄漏故障排查记录

文章插图
 
「可以看到堆内存中,有一些nio有关的大对象,比如正在接收消息队列消息的nioChannel,还有nio.HeapByteBuffer,但是数量不多,不能作为判断的依据,先放着观察下 。」
下一步,我开始浏览该接口代码,接口内部主要逻辑是调用集团的WCS客户端,将数据库表中数据查表后写入WCS,没有其他额外逻辑
发觉没有什么特殊逻辑后,我开始怀疑WCS客户端封装是否存在内存泄漏,这样怀疑的理由是,WCS客户端底层是由SCF客户端封装的,作为RPC框架,其底层通讯传输协议有可能会申请直接内存 。
「是不是我的代码出发了WCS客户端的Bug,导致不断地申请直接内存的调用,最终吃满内存 。」


推荐阅读