生产事故-记一次特殊的OOM排查

0x01 事故背景

2023年3月10日14时19分，C公司开发人员向A公司开发人员反映某开放接口从2023年3月10日14时许开始无法访问和使用。该系统为某基础数据接口服务，基于 HTTP 协议进行通信。按照惯例，首先排查网络是否异常，经运维人员检查，证明网络连通性没有问题。A公司开发组于2023年3月10日14时30分通知运维人员重启应用服务，期间短暂恢复正常。但是，很快，十分钟后，电话再次响起，告知服务又出现异常，无法访问。为了避免影响进一步扩大，A公司决定将程序紧急回滚至上一稳定版本。回滚后，系统业务功能恢复正常。短暂松一口气后，开始排查问题。

0x02 事故分析

让运维拷贝和固定了更新前后的系统日志和应用包。根据前面的故障现象，初步猜测是内存问题，好在应用启停脚本中增加了参数-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/app/logs/app.dump（对于无法在生产环境上使用jstack、jmap等命令直接查错的——事实上大多数时候都不能，dump文件显得尤为重要），果不其然，日志目录下出现了app.dump文件，在日志中搜索，找到了若干处内存溢出错误java.lang.OutOfMemoryError: Java heap space，但是令人费解的是每次出现OOM错误的位置居然都不一样，事情逐渐变得复杂起来。

用MAT(Memory Analyzer Tool)工具打开转储文件，原以为会发现某个类型对象占用大量的内存，结果出乎意料，Histogram（直方图）中显示活跃对象居然只有100多M！尝试 Calculate Precise Retained Size（计算精确大小），计算结果与前面相差不大。检查 Outgoing References （追踪引用对象）和 Incoming References（追踪被引用对象）也未见明显异常，令人头大。

擦擦汗，日志已经明确提示我们java.lang.OutOfMemoryError: Java heap space，首先肯定这是一个堆内存空间引起的问题，可能的原因有：

• 内存加载数据量过大

  例如不受行数限制的数据库查询语句，或者不限制字节数的文件读取等，事故系统显然没有这些情况；

• 内存泄漏（资源未关闭/无法回收）

  当系统存在大量未关闭的 IO 资源，或者错误使用ThreadLocal等场景时也会发生OOM，经排查，也不存在这种情况；

• 系统内存不足

  系统内存不足以支撑当前业务场景所需要的内存，过小的机器内存或者不合理的JVM内存参数。

如果排除所有合理选项，最不合理那个会不会就是答案呢？遂开始检查机器的内存，根据运维的说法，机器内存为16GB，top命令查看java进程占用内存约为7.8GB，看起来似乎没毛病。

但是随后另一个同事注意到了一个事情，最后一次系统升级的时候，改动过应用启停脚本，对比旧版本的脚本，发现差异部分就是内存参数：

旧版本原为：

-Xms8g -Xmx8g -Xmn3g

新版本改为：

-Xms8g -Xmx8g -Xmn8g

看到这里，屏幕前的一众同事都无语啊……

0x03 事故原因

为什么-Xmn参数设置成与-Xmx参数一样的大小会导致OOM呢？该项目使用的JDK版本为1.8，看看JDK 8的内存模型：

不难发现，Heap Space Size = Young Space Size + Old Space Size，而-Xmn参数控制的正是 Young 区的大小，当堆区被 Young Gen 完全挤占，又有对象想要升代到 Old Gen 时，发现 Old 区空间不足，于是触发 Full GC，触发 Full GC 以后呢，通常又会面临两种情况：

• Young 区又刚好腾出来一点空间，对象又不用放到 Old 区里面了，皆大欢喜
• Young 区空间还是不够，对象还是得放到 Old 区，Old 区空间不够，卒，喜提OOM
• 诶，就是奔着 Old 区去的，管你 Young 不 Young，Old 区空间不够，卒，喜提OOM

这个就解释了为什么系统刚刚启动时，会有一个短时间正常工作的现象，随后，当某段程序触发 Old Gen 升代时，就会发生随机的OOM错误。那么什么时候对象会进入老年代呢？这里也很有意思，不妨结合日志里面出现OOM的地方，对号入座：

• 经历足够多次数 GC 依然存活的对象
• 申请一个大对象（比如超过 Eden 区一半大小）
• GC 后 Eden 区对象大小超过 S 区之和
• Eden 区 + S0 区 GC 后，S1 区放不下