美文网首页
记一次定位线上项目OOM问题

记一次定位线上项目OOM问题

作者: Yellowtail | 来源:发表于2022-02-28 23:23 被阅读0次

    背景

    工作这些年也定位过不少OOM,但是之前都是有点迷迷糊糊地,似懂非懂;有时能定位出来,有时定位不出来;
    在网上也看到了不少博客,大概率是遇到了OOM,拿到内存dump文件,经过一顿分析发现问题在哪里,然后解决,文件和代码之间的联系是怎么建立起来的,都是寥寥数语随便带过
    这次又遇到了OOM,下定决心,一定要先理清思路再动手,要总结方法论,没想到最后按照思路还真的定位出来了,所以方法论也就被总结出来了,分享给大家

    方法论

    1. 找到所有活着的线程和爆出OOM的线程,都是嫌疑犯
    2. 逐一分析线程,缩小嫌疑犯范围
    3. 找到最大的对象
    4. 根据对象的信息(如类、字段、属性值)和线程信息,进一步缩小代码范围
    5. 由果索因,已知这段代码有问题,推导出来具体是哪一步出的问题
    6. 发现问题,修复问题

    0x0 准备工作

    • java_pid1.hprof
      内存dump文件,我们的项目是通过jvm参数来设置发生OOM的时候会自动dump的,jvm 参数是 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/ms/jvm/oom/,当然没有设置参数也可以手动dump
    • JProfiler(或者 eclipse 的 mat)

    0x1 观察线程

    OOM 是因为空间不够了,那么为什么空间不够呢?只有两个可能

    1. 分配的太少了,本来就不够
    2. 分配的够用,只是被用完了

    分配太少导致OOM常见于启动失败,而 我们的服务 已经运行了很久了,所以是第二个而原因
    那么被谁用完了呢?肯定是有一个线程在持有这些对象,阻止了GC的回收,导致内存都用完,进而导致 OOM (反推也成立,如果导致OOM的线程没有活着,那么它持有的对象就会被GC标记为可回收,进而被释放,也就不会发生OOM)

    大多数情况下,分析我们的业务线程就行,线程名称是以 http-nio-8080-exec-xxx 开头的,这个是 tomcat 默认的命名方式

    经过分析,有三个线程是活跃的


    线程
    • 323
    • 345
    • 362

    接下来依次看一下线程堆栈

    0x2 逐一分析线程

    323

    323

    可以看到: 这个线程刚刚进入 filter 阶段,controller 都没有进去,啥事都没做,所以可以排除

    345

    345

    可以看到:这个线程已经处理完了 controller 的逻辑,正在进行拦截器的 afterCompletion 处理,还在对 StringBuilder 进行 append,有嫌疑

    362

    362

    可以看到:这个线程爆出了 OOM 异常,且阶段和 345 差不多,都是处理完了 controller,在afterCompletion的阶段出了问题,有嫌疑

    Tips: 虽然是362爆出的 OOM,但是目前为止还只是嫌疑犯,不一定就是罪魁祸首,也有可能只是压倒骆驼的最后一根稻草,具体信息得进一步排查

    0x3 Biggest Object

    OOM常见两种情况

    1. 堆heap 爆了
    2. metaspace 爆了

    我们这里是知道是堆爆了(因为日志是:java.lang.OutOfMemoryError: Java heap space

    我们再来看一下内存里消耗内存最大的东西是什么

    image.png

    一般来说,如果出现了我们自己的对象,那么基本就是它;如果没有出现,就还需要进一步的定位
    这里我们可以看到出现了 com.xxxxxx.vo.SkmrVO,是我们公司的类, 基本可以确定就是这个对象太大,导致了OOM

    这个对象我们是用来包裹 controller 的 返回值的(code data 那些字段),那么返回值是什么呢?用工具看一下

    右键,use selected objects,然后直接 ok

    第一步 第二步

    可以看到下图所示的内容


    image.png

    根据图中1、2、3的信息,可以推导出来,内存里有至少一个很大的对象,类型是 SkmrVO<List<TeamUsersDocument>>, 因为 SkmrVO 是我们用来包裹返回值的,那么这个 controller 的方法返回值是 List<TeamUsersDocument>

    且看到 size = 57451, 很明显,OOM 就是因为 这个 list 里面元素太多了导致的

    0x4 缩小代码范围

    有了这些信息,我们就可以缩小范围,查看代码,有两个方法满足,还需要进一步的确认(实在抱歉,这一步不能放截图,因为都是公司代码)

    日志

    看日志的目的是: 进一步缩小代码范围
    前面确认了两个嫌疑犯 345 362,分别看一下日志(这里不放图了)
    经过对比,两个线程都执行了同一行代码 xxxService:72

    那我们接下来看一下 这行代码的调用者有没有上面分析出来的方法
    用 IDEA 的 Call Hierarchy 可以看到调用链,再进行搜索,可以发现这行代码和我们找到的某一个方法之间存在调用关系(不能放图)

    image.png

    也就是说,我们在这里已经找到了一个唯一的代码入口

    0x5 由果索因,确定OOM 根因

    已知这个方法有问题,且知道是因为 list 元素太多导致的,根据这些信息,去认真看代码
    此时,可以把每一行代码都当初嫌疑犯来看待,问一问自己:这行代码会导致这个问题么?
    就这样逐一阅读代码,逐一排除,很快就发现了问题所在,原来是 sql 没有写 limit

    0x6 修复

    这个没什么好说的,见机行事

    相关文章

      网友评论

          本文标题:记一次定位线上项目OOM问题

          本文链接:https://www.haomeiwen.com/subject/hralrrtx.html