项目场景:
某次打开工程前台页面,个别页面直接提示
GC overhead limit exceeded
伴随着的,其余各个页面响应速度都十分缓慢
排查流程
1. GC查看
初步怀疑是内存溢出,但还需要证据,先进入到后台日志查看下
可以看到后台直接是提示OOM,实锤了内存溢出,我们也可以通过查看GC情况来辅助确定,先看线程id
ps -ef | grep XXXXX(应用名)
得到线程 id26866
然后使用 jstat -gc 26866 5000 进行查看,这个命令的意思是打印线程 26866 的GC 情况,每5秒一次
jstat -gc 26866 5000 • 1
先看倒数第二列:FGCT——full GC time (从应用程序启动到采样时 Full GC 所用的时间(单位秒));
考虑到我是5秒打印一行,,可以看到几乎每时每刻都在做FULL GC,根本没停过,至于FULL GC的效果
可以看这五列
S0 — Heap上的 Survivor space 0 区已使用空间的百分比
S1 — Heap上的 Survivor space 1 区已使用空间的百分比
EU — Heap上的 Eden space 区已使用空间
OU — Heap上的 Old space 区已使用空间
MU — Meta space 区已使用空间
可以看到老年代基本回收不动,新生代能回收,但只能回收一点点,两者都几乎是满空间运行
2. 死锁判断
因为前面判断出GC的问题,死锁有可能占用大量资源无法释放,导致内存溢出,我们先排除是否有线程死锁的情况
jstack 26866
暂未发现其他问题,基本可以排除死锁的情况。那么接下来只能dump下来,对数据进行分析了
3. dump查看
jmap -dump:file=overgc.dump -26866
导出当前堆的情况,存储在文件overgc.dump里。因为我们是开发环境,所以直接从服务器拷贝下来,用jdk自带的jvisualvm来查看该文件
使用jvisualvm打开我们存储的dump文件,此处点击装入快照
因为当时没有截图,所以下面只能以示意图展示,但不影响理解
装载后,通过类,看哪些类占用了太多的空间。一般来说,排名靠前的都是基础的String byte[] 等部分,如果前排有业务类占用太多空间,那么这个类一般就是内存泄漏的罪魁祸首
当时我们发现了某个业务对象的数量达到了10W + ,这在我们的场景中显然是不合理的
然而我们在代码中发现该类有好几个使用的地方,仍旧不好定位,于是切到了jvisualvm的实例部分,通过这些实例去找引用的线程,然后在此处查看线程情况
通过分析发现,大量的对象实例是存在List中的,一个List有6000个该对象实例,然而持有这个list的线程却卡死了,经过线程信息 和 代码的相互印证,证实了,这是再把List作为入参,去同步调用一个第三方接口时,第三方接口迟迟没有返回,导致线程一直处于阻塞。
原因分析:
通过上述证据与代码的相互印证,最后还原了事情的原因:
起因是有同事修改了数据库数据,使得原本某条sql应该查出几十条数据,现在却查出6000条。并且在后续代码中,还要把这6000个数据的List,通过RPC,传给第三方接口。
而第三方接口应该也没压测过这么大的数据量,导致迟迟无法返回结果,使我们的线程一直阻塞,给我们前台的表现就是卡住了。
此时,因为前台没响应,于是前台同事又刷新了几次,相当于重新调了该接口,最后的结果就是大量线程查出6000条数据后阻塞在这里,堆里出现该对象的实例超过10W 个,最终OOM了
解决方案:
1. 临时方案:
把同事修在数据库修改的数据进行还原,使得每次SQL查出几十条数据
2. 解决策略:
- 排查系统里的SQL,为SQL加上分页或行数限制,mysql的话就是limit,这样保证即使数据库出现大量脏数据,也不会全部查出来
- 减少RPC调用的超时时间,原先默认的超时时间是60s ,所以导致我们线程一直在等待返回值,而没有很快报错并释放空间,但对于一个接口来说60s 太长了,即使为了保证接口调通。这个时间用户一般也没耐心等待,最后将RPC的超时时间设定为15s.