现象
线上某个服务有接口十分慢,通过监控链路查看发现,中间的 GAP 时刻十分大,实践接口并没有耗费许多时刻,而且在那段时刻里有许多这样的恳求。
原因剖析
先从监控链路剖析了一波,发现恳求是已经打到服务上了,处理之前不知道为什么等了 3s,猜想是不是机器其时负载太大了,通过 QPS 监控查看发现,在接口慢的时分 CPU 忽然增高,一起也频频的 GC ,而且时刻很长,但是恳求量并不大,而且这台机器很快就因为 Heap满了而被下掉了。
去看了下日志,公然有 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的线程。
找到了具体报错的代码行号,翻一下事务代码,竟然是一个查询数据库的count
操作,这能有啥问题?
细心看了下里边有个foreach
遍历userId
的操作,莫非这个userId
的数组十分大?
找到class
按照巨细排序,占用最多的是一个 byte 数组,有 1.07G,char 数组也有1.03G,byte 数组都是数字,直接查看 char 数组吧,点进去查看具体内容,公然是那条count句子,一条 SQL 1.03G 不可思议。。。
这个userId
的数据完全是外部传过来的,并没有做什么操作,从监控上看,这个入参有 64M,立刻联络对应体系排查为啥会传这么多用户过来查询,通过一番排查确认他们有个bug
,会把所有用户都发过来查询。。。到此问题排查清楚。
解决方案
对方体系控制传入userId
的数量,咱们自己的体系也对userId
做一个约束,问题排查进程比较困难,修改方案总是那么的简单。
别急,还有一个
看到这个问题,就想起之前咱们还有一个同样类似的问题导致的毛病。
也是忽然收到许多告警,还有机器 down 机的告警,翻开 CAT 监控看的时分,发现内存已经被打满了。
操作和上面的是相同的,拿到 dump 文件之后进行剖析,不过这是一个漫长的进程,因为 down了好几台机器,最大的文件有12GB。
通过 MAT 剖析 dump 文件发现有几个巨大的 String
(了解的滋味,了解的配方)。
接下来就是早具体的代码位置了,去查看了下日志,这台机器已经触发自我维护机制了,把代码的具体位置带了出来。
通过剖析代码发现,代码中的逻辑是查询 TIDB(是有同步延迟的),发现在极端情况下会呈现将用户表悉数数据加载到内存中的现象。
于是找 DBA 拉取了对应时刻段 TIDB 的慢查询,公然命中了。
总结
面对 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
作为约束,避免这种问题拖垮整个体系。