现象

线上某个服务有接口十分慢,通过监控链路查看发现,中间的 GAP 时刻十分大,实践接口并没有耗费许多时刻,而且在那段时刻里有许多这样的恳求。

一次线上OOM问题分析

原因剖析

先从监控链路剖析了一波,发现恳求是已经打到服务上了,处理之前不知道为什么等了 3s,猜想是不是机器其时负载太大了,通过 QPS 监控查看发现,在接口慢的时分 CPU 忽然增高,一起也频频的 GC ,而且时刻很长,但是恳求量并不大,而且这台机器很快就因为 Heap满了而被下掉了。

一次线上OOM问题分析

去看了下日志,公然有 OOM 的报错,但是从报错信息上并没办法找到 Root Cause。

system error: org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: Java heap space   at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1055)   at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)   at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)   at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)   at javax.servlet.http.HttpServlet.service(HttpServlet.java:681)

另外开发同学供给了头绪,在发生问题的时分在跑一个大批量的一次性 JOB,怀疑是不是这个 JOB 导致的,立刻把 JOB 代码拉下来剖析了下,JOB 做了分批处理,代码也没有发现什么问题。

尽管咱们体系加了下面的 JVM 参数,但是因为容器部署的原因,这些文件在 pod 被 kill 掉之后没办法保存下来。

-XX:+HeapDumpOnOutOfMemoryError -XX:ErrorFile=/logs/oom_dump/xxx.log -XX:HeapDumpPath=/logs/oom_dump/xxx.hprof

这个现象是最近呈现的,猜想是最近提交的代码导致的,于是去剖析了最近提交的所有代码,很不幸的都没有发现问题。。。

在剖析代码的进程中,该服务又无规律的呈现了两次 OOM,只好联络运维同学优先给这个服务加了 EFS (Amazon 文件体系)等候下次呈现能捉住这个问题。

刚挂载完 EFS,很幸运的就碰到了体系呈现 OOM 的问题。

dump 出来的文件足有 4.8G,话不多说祭出 jvisualvm 进行剖析,剖析工具都被这个dump文件给搞挂了也报了个java.lang.OutOfMemoryError: Java heap space,加载成功之后就给出了导致OOM的线程。

一次线上OOM问题分析

找到了具体报错的代码行号,翻一下事务代码,竟然是一个查询数据库count操作,这能有啥问题?

细心看了下里边有个foreach遍历userId的操作,莫非这个userId的数组十分大?

一次线上OOM问题分析

找到class按照巨细排序,占用最多的是一个 byte 数组,有 1.07G,char 数组也有1.03G,byte 数组都是数字,直接查看 char 数组吧,点进去查看具体内容,公然是那条count句子,一条 SQL 1.03G 不可思议。。。

一次线上OOM问题分析

一次线上OOM问题分析

这个userId的数据完全是外部传过来的,并没有做什么操作,从监控上看,这个入参有 64M,立刻联络对应体系排查为啥会传这么多用户过来查询,通过一番排查确认他们有个bug,会把所有用户都发过来查询。。。到此问题排查清楚。

解决方案

对方体系控制传入userId的数量,咱们自己的体系也对userId做一个约束,问题排查进程比较困难,修改方案总是那么的简单。

别急,还有一个

看到这个问题,就想起之前咱们还有一个同样类似的问题导致的毛病。

也是忽然收到许多告警,还有机器 down 机的告警,翻开 CAT 监控看的时分,发现内存已经被打满了。

一次线上OOM问题分析

操作和上面的是相同的,拿到 dump 文件之后进行剖析,不过这是一个漫长的进程,因为 down了好几台机器,最大的文件有12GB。

通过 MAT 剖析 dump 文件发现有几个巨大的 String(了解的滋味,了解的配方)。

一次线上OOM问题分析

接下来就是早具体的代码位置了,去查看了下日志,这台机器已经触发自我维护机制了,把代码的具体位置带了出来。

通过剖析代码发现,代码中的逻辑是查询 TIDB(是有同步延迟的),发现在极端情况下会呈现将用户表悉数数据加载到内存中的现象。

一次线上OOM问题分析

于是找 DBA 拉取了对应时刻段 TIDB 的慢查询,公然命中了。

一次线上OOM问题分析

总结

面对 OOM 问题假如代码不是有明显的问题,下面几个JVM参数适当有用,尤其是在容器化之后。

-XX:+HeapDumpOnOutOfMemoryError -XX:ErrorFile=/logs/oom_dump/xxx.log -XX:HeapDumpPath=/logs/oom_dump/xxx.hprof

另外提一个参数也很有用,正常来说假如程序呈现 OOM 之后,就是有代码存在内存走漏的风险,这个时分即便能对外供给服务,其实也是有风险的,或许造成更多的恳求有问题,所以该参数十分有必要,可以让 K8S 快速的再拉起来一个实例。

-XX:+ExitOnOutOfMemoryError

另外,针对这两个十分类似的问题,对于 SQL 句子,假如监测到没有where条件的全表查询应该默认增加一个适宜的limit作为约束,避免这种问题拖垮整个体系。