排查和解决JVM OOM实战

Alan CGH

于 2024-10-06 13:05:54 发布

阅读量606

点赞数 19

分类专栏：实战经验 JVM 文章标签： jvm

本文链接：https://blog.csdn.net/AllenChan_/article/details/142724491

版权

JVM 同时被 2 个专栏收录

8 篇文章 0 订阅

订阅专栏

实战经验

5 篇文章 0 订阅

订阅专栏

JVM OOM介绍

Java内存区域布局

下面的分析中都是基于JDK 8开始的。关于JMM不过多介绍每个区域的作用。OOM不单只会发生在堆内存，也可能是因为元空间或直接内存泄漏导致OOM，此时在OOM的详细信息中会有不同体现。

Java OOM的类别

java.lang.OutOfMemoryError: GC overhead limit exceeded

JVM 98%的CPU时间都在执行GC，并且每次GC回收空间小于堆内存的2% 基本就是应用不可用的状态了！

可能原因：1.堆内存设置过小 2.内存泄漏

java.lang.OutOfMemoryError: Java heap space

JVM 堆内存无法再分配对象。

可能原因：1.堆内存设置过小 2.内存泄漏 3.对象实现finalize方法不当，回收速度跟不上finalization queue入队速度

java.lang.OutOfMemoryError: Metaspace

元空间是直接用本地内存，受限于MaxMetaSpaceSize参数。存放的类对象信息过多导致元空间溢出。

可能原因：1.元空间过小 2.动态代理造成类对象过多

java.lang.OutOfMemoryError: request size bytes for reason. Out of swap space?

很少出现。通常是JVM的本地堆内存无法再分配对象导致。

java.lang.OutOfMemoryError: Compressed class space

很少出现。

java.lang.OutOfMemoryError: reason stack_trace_with_native_method

很少出现。摘自Orcale JDK Document

If the detail part of the error message is "reason stack_trace_with_native_method" and a stack trace is printed in which the top frame is a native method, then this is an indication that a native method has encountered an allocation failure. The difference between this and the previous message is that the allocation failure was detected in a Java Native Interface (JNI) or native method rather than in the JVM code.

沃尔玛支付中台实际案例

我在沃尔玛中国的科技部工作的时候，负责过支付中台的研发，我接手的时候还是一个刚起步的系统。我负责的一年半时间中，接入门店从2家扩展到全国200家门店。日支付单量从7、8千到80~100万的规模。为全国的山姆会员店自助收银机、沃尔玛大卖场自助收银机、线上山姆会籍系统提供支付退款结算能力。中间的过程不是一帆风顺，在一个元旦假期还遇到OOM的线上事故（后面排查出是前同事的老代码导致），造成门店大面积停用自助收银机，顾客被迫转向人工收银和小程序线上缴费等其它支付通道。

问题表现

第一次发生OOM问题时候，排查日志发现OOM前十分钟，日志显示请求进来的线程都在运行到某个时刻全部被hoding。再也没有日志输出，原本业务代码中正常时刻会输出日志。直到OOM错误出现。整个服务表现为不可用状态。后来导出的jstack日志显示所有线程都是BLOCKED状态。观察日志发现线程号貌似增长到50+。Kevin判断是请求外部接口时遇到了很大的延迟导致线程没释放而外部请求堆积越来越多，最终消耗完了内存。

于是按照这个判断给HTTP接口加上限流和告警监控，毕竟没有办法干预外部第三方支付接口。以为事情就解决了，但是......

在元旦假期的时候下午5点支付中台又发生了OOM。6g的堆内存，4g的old gen全部拉满，观察听云old gen从昨天一直满的到现在。查看full gc频率，基本20分钟内发生200+次full gc，查看日志也是显示 GC overhead limit exceeded error 代表应用98%的时间都在执行GC，并且每次GC回收空间小于堆内存的2% 基本就是应用不可用的状态了！

门店也反馈收银支付十分慢，表现就是卡死！周一被军训和被吊打是免不了的了。最后排查发现是前同事擅自改了银联SDK，把CertUtil从静态类改成对象，每次银联请求时都创建对象，直接触发了底层的一个坑。

排查过程

基于基础知识我们知道，OOM的类别中GC overhead limit exceeded error，很大概率是老年代堆内存发生了泄漏，导致GC一直没办法有效释放对象，进而引发不断地Full GC，整个服务用户进程的CPU时间都用在GC线程上了，用户线程反而得不到CPU时间，服务就假死了。立即新启动几个服务节点顶上，新节点内存会缓慢的上升直至OOM，中间有一段可用时间，可以恢复服务能力。

排查内存泄漏，一般无法从代码看出来哪里泄漏了。所以我们得想办法拿到内存快照，用：jmap -dump:live,format=b,file=filename.bin pid

这个命令可以导出堆内存中存活的对象，因为我们排查内存泄漏所以只要求存活对象。使用前注意：jmap为了收集准确的堆内存使用情况会暂停jvm的用户线程和gc线程。所以造成STW。具体STW时长取决于导出的堆内存大小正相关。

关于jmap是否会造成STW可看stackoverflow一篇文章：

java - Is a JVM stopped while executing jmap? - Stack Overflow

jmap导致stw造成生产事故的例子：

memory - Java : Get heap dump without jmap or without hanging the application - Stack Overflow

其中文章内提了一些避免STW同时获取堆内存快照的做法，例如用gdb命令。fork进程，然后在子进程dump，fork可能会占用大量额外内存在主进程同时对同一个地址空间的内存大量写动作，就会有copy-on-wirte发生，会分配新内存页copy旧的内存页让主进程在新的内存页写入。

以上做法其实都不推荐，也没有实践过。正确且成熟的做法应该是在网关层或负载层把机器节点摘掉，验证没有流量后，再使用jmap导出堆内存快照，这时候你想怎么搞就怎么搞。

当晚等到新节点内存涨到一定规模后，即将发生FGC，摘流用jmap导出内存快照，下载到本地分析。每台服务器两个快照，一共4个。最大的快照8.4G。把快照下到本地，用MAT打开分析。提前要调整好MAT的maxHeapSize，不然MAT无法装载快照。

把快照导入后，8.4G大概加载了30分钟，然后就按照提示选择 Leak Suspects 分析，完毕后会给出内存对象占用空间的饼图，并且给出 problem a b 等推测泄漏对象/类。基本逐个查看泄漏对象的details，例如看这个对象的dominator tree等等

使用MAT分析泄漏点

本次事故中，在Problem Suspect 中很明显可以看到是一个 JceSecurity对象占了5.2G内存，这肯定是不正常的。果然就是内存泄漏了。details中在支配树中看到JceSecurity有一个IdentityHashMap内部用的Object[]数组保存Entry。这个数组中有6000+个BouncyCastleProvider对象，总共占了5.2G内存。为什么这个对象不会被回收？进一步看这个对象的 Path to GC roots，排除所有弱引用、虚引用。可以看到gc root就是JceSecurity对象，这个对象MAT提示是System class，是一个GC root不会被回收的。

结合源码看，JceSecurity里的map是一个static final修饰，map是常量的，也就是6000+多个provider对象被map持有强引用所以一直释放不了。

OK！这就很明显的泄漏就是这个provider对象了，但是这里只找到了泄漏对象。这个对象我也不认识，也不记得代码里哪里用到了它。

根据网上的教程，也没通过MAT查找到源码级别哪个地方泄漏了provider，幸运地在代码里全局搜索BouncyCastleProvider，很快在银联的SDK中找到这个对象的使用。并且是Security.add(new BouncyCastleProvider()) 这样明显的代码。再看这段代码是每次创建CertUtils对象会执行的代码。很自然怀疑是这个地方，于是在本地复现，简单的死循环调用 Security.add(new BouncyCastleProvider())，通过VMVisual监控JVM进程的堆内存变化，很正常的释放，provider对象数量涨到一定程度又降下去了。

难道不是这里？最后在QA服务器，压测银联的查询接口，jstat监控堆内存的使用量，几十分钟后发现old gen一直无法释放内存，并且开始频繁full gc。dump了内存快照到本地查看，果然和生产的快照显示一样，是JceSecurity占了大部分内存！

那么就可以确定是银联CertUtil的问题，查看官网的原对象使用，人家是静态类，会在static代码块调用一次 Security.add(new BouncyCastleProvider())。但是我们的代码是每次创建CertUtil造成每次调用Security.add(new BouncyCastleProvider())。

但问题是为什么死循环没复现泄漏问题呢？后来查资料可能是没有使用加解密代码，并且用VMVisual查看JceSecurity对象没有生成，虽然产生了很多provider但因为没有强引用，都被GC了。