记一次线上内存溢出排查和处理

1,155 阅读5分钟

事故回忆

1、第一次事故

因为生产存在一个小小的问题需要进行优化处理,所以在处理后经过验证测试无误后发布到生产环境,结果生产环境当天晚上出现了内存溢出,客户方为了不造成大的事故随即重启了应用。第二天客户让我排查所有的改动,修改的代码理论上是不存在内存溢出的可能的,所以后来把问题定位到应用的启动脚本上,因为在发布生产时修改了启动脚本,增加了内存限制参数-Xms2048M -Xmx4096M。然后重新将脚本恢复到之前的,重新启动了应用。

不过这里我始终留下了一个疑问,这个项目到底哪里存在内存溢出的情况,死循环是没有的,那就是晚上的定时任务,数据量太大导致。所以在草草熟悉了项目代码之后,确实定时任务可能会处理大数据量的情况,但是4G内存被占满了还是令我吃惊,但是也没有再多想。

2、第二次事故

我们的项目是依赖了SDK,SDK里面有一些标准化的功能,因为生产上又发现了一个问题,需要SDK进行更新,所以项目本身的代码是没有做什么调整的,只是重新打了包进行部署。然而当天晚上又出现了内存溢出的情况。于是乎客户自行将版本进行了回退。到了第二天客户又重新让我排查该问题,但是SDK修改的内容据同事反馈只是加了一个try ... catch ..., 所以应该也不是这块的问题。但是仍旧没有堆栈信息,无法找到具体出现问题的代码。

3、 第三次事故

第三次事故实际上是因为其他问题引起的。因为线上网络出现了问题,程序中报错broke pipe,导致服务瘫痪,双方成立专项问题处理小组,其中从两方面着手(1)网络上排查 (2)可能引起该问题的代码临时优化。在优化了代码后重新打了包部署,但是 broke pipe异常仍旧存在,最后排查是因为网络问题导致。但是优化的代码也不打算回退了。但是到了晚上又出现了内存溢出的情况。这次我很坚决的认定不是修改的代码导致,肯定是其他问题导致。就算回退了代码,问题暂时得以解决,后续更新时该问题又会出现,因为SDK我们是不分版本的,我们无法控制,但是测试环境又无法复现,所以需要依靠生产环境来发现和解决该问题。为了在出现内存溢出时能够及时的回复正常,于是在启动脚本中使用了-XX:+HeapDumpOnOutOfMemoryError参数来记录堆栈信息,以便在出现内存溢出时客户自行重启服务还能够保留堆栈信息。

堆栈信息

拿到堆栈信息后,文件有4G,使用MAT工具打开(期间由于文件太大一致打开失败,还修改了.ini文件内存限制),其中看到了下面这个场景:

image.png

由此看见肯定是和mysql交互处出现了问题,继续跟踪BufferRow对象。

image.png

从上面这个信息就可以很清楚的看到是哪里出了问题,和mid_method_execute_info有关系是跑不掉了。然后让客户去查看了这个表的数据,发现有快1700万条数据(惊愕)。然后根据该表找相关代码,发现晚上11点时有个定时任务会去查询这个表里面除最近15天的数据(大概有1500万条数据),并且是查询所有字段。基本就确认是此处有问题了。

最后同SDK相关功能开发同事沟通后,确认该表数据只是历史数据,该项目可以删除掉,所以直接在线上执行脚本清空了相关表的数据(还有其他3个表数据,最多的有4千万)。于是后续项目正常运行再无内存溢出情况出现。

问题复盘和疑问

  1. 是SDK的问题,为什么之前能正常运行,而每次打完新包就会出现问题? 第一次出现问题是因为修改了启动脚本的内存限制,所以出现了内存溢出;后来打新包时已经有一个多月了,生产环境产生了大量的数据,所以跑任务时就会内存溢出,但是用旧版本就不会出现内存溢出,这个是因为后来的新包的SDK里面将原来的每月28号跑一次的定时任务改成了每天晚上11点跑,所以新包当天晚上就会出现问题,而老版本需要等到当月28号才会出现问题。而第一次出现问题时恰好就是4.28号,恰好还修改了脚本内存限制。

  2. 如果生产环境不是特别急切的需要恢复,可以不要立即重启,先拿到堆栈之后重启 运行中的进程获取堆栈信息使用命令:jmap -dump:live,format=b,file=./heapdump.hprof pid。 但是如果堆栈信息比较多,比如4G的话可能需要比较长的时间才能完成。