055-SQL语句引发的OOM问题排查实践

308次阅读
没有评论

共计 3694 个字符,预计需要花费 10 分钟才能阅读完成。

一次没有WHERE条件的SQL语句引发的OOM问题排查实践!

1、案例背景引入

这个案例也是我们线上曾经出现过的一个真实的生产案例,是一个年轻的工程师在使用mybatis写SQL语句的时候在某些情况下允许不加where条件就可以执行,结果导致一下子查询出来上百万条数据引发了系统的OOM。

这个案例本身是属于比较简单的那种,不涉及太多其他的技术问题,的确就是纯系统代码自身的问题导致的

所以我们拿这个案例来给大家再深入讲讲在使用MAT进行线上内存快照分析时候的一些技巧,相信对大家也是很有用的。

2、关于MAT工具对OOM故障的实践意义

这里给说一句,如果你的系统触发OOM是由于Tomcat、Jetty、RPC框架之类的底层技术,那么MAT对你来说用处并不是那么大

因为你最多就是用MAT找一找占用内存过多的对象,然后结合异常日志调用栈和MAT中的对象引用情况,初步定位一下是底层技术中的哪部分代码导致的内存溢出。

而如果要真正解决内存溢出问题,还得去仔细研究Tomcat、Jetty、RPC框架之类技术的底层源码,结合线上系统的负载情况、访问压力以及GC情况,以及底层技术的源码细节,真正分析清楚发生OOM的原因,然后才能解决。

但是如果OOM主要是由于你自己的系统代码的问题导致的,那么就容易解决的多了

只要依托MAT层层分析,瞬间就可以定位到你代码的问题所在,毕竟你自己写的代码你是最熟悉的,所以你很快就可以解决问题。

3、故障发生现场

我们先来看一下故障发生的现场,某一天突然我们收到反馈说线上一个系统崩溃不可用了,此时当然是立即登录到线上机器去查看日志了,在日志中果然发现了OOM的异常:java.lang.OutOfMemoryError,java heap space。

堆内存溢出了,那我们下一步肯定是把自动导出的内存快照拷贝到自己电脑上,用MAT去分析对应的内存快照了

今天就给大家详细说说真实的生产案例中,如何巧妙的用MAT工具迅速定位问题代码。

4、第一步:检查内存中到底是什么对象太多了

第一步,我们可以用MAT中的一个Histogram功能,去检查一下占用内存最多的对象有哪些

之前给大家介绍过内存泄漏报告的使用,那个功能也是没问题的,也很好用,但是今天给大家介绍另外一套分析的工具和思路,其实原理都是类似的。

分析内存快照,说白了,无非就是找到占用内存最大的对象,然后就是找到谁在引用这个对象,是哪个线程在引用,接着找到创建这些对象的相关代码和方法,然后你就可以一头扎到对应的源码里去分析问题了。

我们先看下面的图,在这个图里,可以点击下图中红圈处的一个按钮,那个就是Histogram按钮,点击过后就会进入另外一个界面。

055-SQL语句引发的OOM问题排查实践

055-SQL语句引发的OOM问题排查实践

接着我们进入Histogram界面,如下图所示:            

055-SQL语句引发的OOM问题排查实践

055-SQL语句引发的OOM问题排查实践

在这个界面中,其实就可以瞬间看到是谁占用内存过多了,比如这里明显是Demo1$Data这个内部类占用了过多的内存。

这里说了,Demo1$Data对象有10000个,此时你有没有一种很好奇的冲动,想要看看这些Demo1$Data对象都是什么东西?

没问题,我们继续接着分析。

5、第二步:深入看看占用内存过多的对象

此时我们可以进入第二步,你可以深入的看看占用内存过多的对象是被谁引用的,哪个线程引用的,他们里面都是什么东西

此时我们可以按照下图,点击红圈处的按钮。

055-SQL语句引发的OOM问题排查实践

055-SQL语句引发的OOM问题排查实践

点击上图的那个红圈处的按钮之后,就会进入一个dominator_tree的界面,他会展示出来当前你JVM中所有的线程,如下图所示:

055-SQL语句引发的OOM问题排查实践

055-SQL语句引发的OOM问题排查实践

在这里,你可以清晰的看到哪些线程创建了过多的对象,比如我们这里排名第一的线程就是:

java.lang.Thread @ 0x5c0020838 main Thread

就是说一个main线程创建了过多的对象

那我们就直接可以展开这个线程,到底他创建了哪些对象?看看下图。

055-SQL语句引发的OOM问题排查实践

055-SQL语句引发的OOM问题排查实践

我们展开main Thread之后,发现里面有一个java.util.ArrayList @ 0x5c00206a8

说明线程创建了一个巨大的ArrayList,我们继续展开这个ArrayList,里面是一个java.lang.Object[]数组,继续展开,就会看到大量的Demo1$Data对象了。

真相大白,其实从dominator_tree界面,我们很快就能找到是哪个线程创建了过多的对象,而且层层展开,就可以看到这个线程创建了哪些对象太多了,就可以跟之前的Histogram界面中占用内存最多的Demo1$Data对上了。

而且这里我们可以轻易看到每个Demo1$Data对象的详细的情况,你可以展开任何一个对象看看。

6、生产案例的追踪

当时对于我们那个线上生产案例而言,到这一步为止,大家猜猜追踪到的是什么东西?

我们当时追踪到这里,发现某个Tomcat的工作线程创建了一大堆的java.lang.HashMap,那么这些java.lang.HashMap中是什么?

我们发现全都是各种从数据库里查出来的字段,你只要展开那个HashMap就能看到你出来放入内存的所有数据。

所以看到这一步基本就很明确了,就是Tomcat的工作线程处理一个请求的时候,发起了一个SQL语句,查出来了大量的数据,每条数据是一个HashMap,就是这大量的数据导致了系统的OOM。

7、第三步:到底是哪一行代码创建了这么多的对象?

找到占用内存最大的对象之后,最后一步就是要定位一下是哪一行代码,或者是哪个方法创建了那么多的对象?

这个又需要另外一个视图了,大家看下图的红圈处。055-SQL语句引发的OOM问题排查实践

点击上图红圈的按钮,会进入一个thread_overview界面,如下图所示,这里会展示出来JVM中所有的线程以及每个线程当时的方法方法调用栈,以及每个方法中创建了哪些对象:

055-SQL语句引发的OOM问题排查实践

055-SQL语句引发的OOM问题排查实践

比如上图,我们会直接看到一个main Thread,他先是执行了一个Demo1.java类中的第12行处的一个Demo1.main()方法,接着这个main方法又执行了一个java.lang.Thread类的sleep()方法,一清二楚。

任何一个线程在此时此刻都执行和调用了哪些方法,都会在这里显示出来。

我们接着展开上图中的Demo1.main()方法,你就可以看到线程调用每个方法的时候创建和引用了哪些对象,如下图所示。

055-SQL语句引发的OOM问题排查实践

055-SQL语句引发的OOM问题排查实践

在上图中,我们发现Demo1.main方法执行的时候创建了一个ArrayList,展开发现是一个java.lang.Object[]数组,再次展开发现就是一大堆的Demo1$Data对象,到此为止,真相大白,一清二楚。

通过上述步骤,你可以快速的定位出来占用内存过多的对象,以及到底是哪个线程创建了这些对象,到底是线程执行哪个方法的时候创建了这些对象,每个对象的细节你都可以看到是什么东西。

8、继续对生产案例进行追踪

采用上述方法,当时我们对生产案例进行追踪,立马就定位到了是系统中的一个业务方法,在执行查询操作的时候,因为没有带上WHERE条件,直接查询出来了全部的上百万的数据,导致了内存的溢出。

此时就直接对那个方法对应的SQL语句进行修改即可,要求他必须每次都带上WHERE条件。

9、经典的MAT步骤:可以套用到全部案例中去

大家应该还记得我们之前的几个案例都直接告诉大家,当时用MAT进行分析的时候,定位到了哪些对象是在哪里被引用的,其实用的都是类似这篇文章里讲解的步骤。

大家可以把这套MAT定位步骤套用到全部案例中去,也可以用到自己自己实际的工作中去。


正文完
 0
yangleduo
版权声明:本站原创文章,由 yangleduo 于2023-05-17发表,共计3694字。
转载说明:除特殊说明外本站文章皆由CC-4.0协议发布,转载请注明出处。