事故复盘
原来以为内存溢出这种事情只会发生在书本上,没想到在我们生产环境发生了,而且是618,P0事故安排上了。先回顾一下内存溢出排查的基本思路,然后再来复盘一下内存溢出发生的原因
先来看一下事故发生前和事故发生后JVM的情况,我们新生代用的是ParNew垃圾收集器,老年代用的是CMS垃圾收集器
13:00-13:10这段时间的情况,系统正常运行
每分钟GC暂停时间(绿色部分是CMS,黄色部分是ParNew)
每分钟GC次数和GC平均耗时(绿色部分是CMS,黄色部分是ParNew)
新生代和老年代的占用情况
可以看到问题发生之前老年代已经设置的不合理了,偏小了。
14:00-14:10这段时间的情况,14:06系统内存溢出
14:00活动开始,14:05之后每分钟垃圾回收暂停的时间过长,都达到30s了
老年代垃圾回收的时间飙升
是在没有可回收的了,最终老年代被占满,内存溢出
分析dump文件
运维配置了上面说的2个参数,内存溢出时生成了dump文件,用Eclipse Memory Analyzer打开分析一波,上一节我们分享了排查了套路就3个步骤
- 占用内存过大的对象有哪些?(MAT Histogram)
- 这个对象被谁引用?(MAT dominator_tree)
- 定位到具体的代码(MAT thread_overview)
占用内存过大的对象有哪些?
可以看到有个DTO占用的内存太大了,一个DTO不应该占用这么大内存啊,看看是哪个对象引用了这个DTO这个对象被谁引用?
看到被线程池引用了,一个线程池居然占用了900多m空间,这么搞的?难道线程池用的不是有界队列?
可以看到线程池队列能存放的最大数量是10000,目前放了883个任务,这个队列的长度设置的也忒大了把!看包名就猜到是中间件团队将这个DTO放到线程池中,所以就不定位具体的代码了,让中间件团队去看
大概逻辑如上图,中间件团队会通过一个agent拦截应用中方法的执行,并将入参和返回值打印在日志中,flume收集日志后给链路平台,监控平台提供数据。
方法每执行一次打印一次日志,但是日志的打印是异步化的,将参数和返回值封装成任务,放到线程池中执行。由于618方法被高频调用,而其中一类DTO对象很大(一个对象6,7m),任务一旦堆积,很快就是OOM。队列的最大值被设置为10000,但是当放了883个任务的时候已经OOM了
解决方案:增大老年代的大小,后续减少大对象的封装