使用MAT解析OOM问题

对于排查OOM问题、分析程序堆内存使用情况,最好的方式就是分析堆转储。

堆转储,包含了堆现场全貌和线程栈信息(Java�6�Update�14开始包含)。

使用jstat等工具虽然可以观察堆内存使用情况的变化,但是对程序内到底有多少对象、哪些是大对象还一无所知,也就是说只能看到问题但无法定位问题。而堆转储,就好似得到了病人在某个瞬间的全景核磁影像,可以拿着慢慢分析。

Java的OutOfMemoryError是比较严重的问题,需要分析出根因,所以对生产应用一般都会这样设置JVM参数,方便发生OOM时进行堆转储:

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=.

使用MAT分析OOM问题,一般可以按照以下思路进行:

  1. 通过支配树功能或直方图功能查看消耗内存最大的类型,来分析内存泄露的大概原因;
  2. 查看那些消耗内存最大的类型、详细的对象明细列表,以及它们的引用链,来定位内存泄露的具体点;
  3. 配合查看对象属性的功能,可以脱离源码看到对象的各种属性的值和依赖关系,帮助我们理清程序逻辑和参数;
  4. 辅助使用查看线程栈来看OOM问题是否和过多线程有关,甚至可以在线程栈看到OOM最后一刻出现异常的线程。

比如,我手头有一个OOM后得到的转储文件java_pid29569.hprof,现在要使用MAT的直方图、支配树、线程栈、OQL等功能来分析此次OOM的原因。

首先,用MAT打开后先进入的是概览信息界面,可以看到整个堆是437.6MB:

概览

那么,这437.6MB都是什么对象呢?

如图所示,工具栏的第二个按钮可以打开直方图,直方图按照类型进行分组,列出了每个类有多少个实例,以及占用的内存。可以看到,char[]字节数组占用内存最多,对象数量也很多,结合第二位的String类型对象数量也很多,大概可以猜出(String使用char[]作为实际数据存储)程序可能是被字符串占满了内存,导致OOM。

我们继续分析下,到底是不是这样呢。

image.png

我们继续分析下,到底是不是这样呢。

在char[]上点击右键,选择List�objects->with�incoming�references,就可以列出所有的char[]实例,以及每个char[]的整个引用关系链:

image.png

随机展开一个char[],如下图所示:


image.png

接下来,我们按照红色框中的引用链来查看,尝试找到这些大char[]的来源:

  • 在①处看到,这些char[]几乎都是10000个字符、占用20000字节左右(char是UTF-16,每一个字符占用2字节);
  • 在②处看到,char[]被String的value字段引用,说明char[]来自字符串;
  • 在③处看到,String被ArrayList的elementData字段引用,说明这些字符串加入了一个ArrayList中;
  • 在④处看到,ArrayList又被FooService的data字段引用,这个ArrayList整个RetainedHeap列的值是431MB。

Retained�Heap(深堆)代表对象本身和对象关联的对象占用的内存,Shallow�Heap(浅堆)代表对象本身占用的内存。比如,我们的FooService中的data这个ArrayList对象本身只有16字节,但是其所有关联的对象占用了431MB内存。这些就可以说明,肯定有哪里在不断向这个List中添加String数据,导致了OOM。

左侧的蓝色框可以查看每一个实例的内部属性,图中显示FooService有一个data属性,类型是ArrayList。

如果我们希望看到字符串完整内容的话,可以右键选择Copy->Value,把值复制到剪贴板或保存到文件中:

image.png

这里,我们复制出的是10000个字符a(下图红色部分可以看到)。对于真实案例,查看大字符串、大数据的实际内容对于识别数据来源,有很大意义:

image.png

看到这些,我们已经基本可以还原出真实的代码是怎样的了。

其实,我们之前使用直方图定位FooService,已经走了些弯路。你可以点击工具栏中第三个按钮(下图左上⻆的红框所示)进入支配树界面。这个界面会按照对象保留的RetainedHeap倒序直接列出占用内存最大的对象。

可以看到,第一位就是FooService,整个路径是FooSerice->ArrayList->Object[]->String->char[](蓝色框部分),一共有21523个字符串(绿色方框部分):

image.png

这样,我们就从内存⻆度定位到FooService是根源了。那么,OOM的时候,FooService是在执行什么逻辑呢?

为解决这个问题,我们可以点击工具栏的第五个按钮(下图红色框所示)。打开线程视图,首先看到的就是一个名为main的线程(Name列),展开后果然发现了FooService:


image.png

先执行的方法先入栈,所以线程栈最上面是线程当前执行的方法,逐一往下看能看到整个调用路径。因为我们希望了解FooService.oom()方法,看看是谁在调用它,它的内部又调用了谁,所以选择以FooService.oom()方法(蓝色框)为起点来分析这个调用栈。

往下看整个绿色框部分,oom()方法被OOMApplication的run方法调用,而这个run方法又被SpringAppliction.callRunner方法调用。看到参数中的CommandLineRunner你应该能想到,OOMApplication其实是实现了CommandLineRunner接口,所以是SpringBoot应用程序启动后执行的。

以FooService为起点往上看,从紫色框中的Collectors和IntPipeline,你大概也可以猜出,这些字符串是由Stream操作产生的。再往上看,可以发现在StringBuilder的append操作的时候,出现了OutOfMemoryError异常(黑色框部分),说明这这个线程抛出了OOM异常。

我们看到,整个程序是Spring�Boot应用程序,那么FooService是不是Spring的Bean呢,又是不是单例呢?如果能分析出这点的话,就更能确认是因为反复调用同一个FooService的oom方法,然后导致其内部的ArrayList不断增加数据的。

点击工具栏的第四个按钮(如下图红框所示),来到OQL界面。在这个界面,我们可以使用类似SQL的语法,在dump中搜索数据(你可以直接在MAT帮助菜单搜索OQL�Syntax,来查看OQL的详细语法)。

比如,输入如下语句搜索FooService的实例:

SELECT * FROM org.geekbang.time.commonmistakes.troubleshootingtools.oom.FooService

可以看到只有一个实例,然后我们通过List�objects功能搜索引用FooService的对象:

image.png

得到以下结果:

image.png

可以看到,一共两处引用:

  • 第一处是,OOMApplication使用了FooService,这个我们已经知道了。
  • 第二处是一个ConcurrentHashMap。可以看到,这个HashMap是DefaultListableBeanFactory的singletonObjects字段,可以证实FooService是Spring容器管理的单例的Bean。

你甚至可以在这个HashMap上点击右键,选择Java�Collections->Hash�Entries功能,来查看其内容:

image.png

这样就列出了所有的Bean,可以在Value上的Regex进一步过滤。输入FooService后可以看到,类型为FooService的Bean只有一个,其名字是fooService:


image.png

到现在为止,我们虽然没看程序代码,但是已经大概知道程序出现OOM的原因和大概的调用栈了。我们再贴出程序来对比一下,果然和我们看到得一模一样:

@SpringBootApplication
public class OOMApplication implements CommandLineRunner {

    @Autowired
    FooService fooService;

    public static void main(String[] args) {
        SpringApplication.run(OOMApplication.class, args);
    }

    @Override
    public void run(String... args) throws Exception {
        //程序启动后,不断调用Fooservice.oom()方法
        while (true) {
            fooService.oom();
        }
    }

    @Component
    public class FooService {
        List<String> data = new ArrayList<>();

        public void oom() {
            //往同一个ArrayList中不断加入大小为10KB的字符串
            data.add(IntStream.rangeClosed(1, 10_000)
                    .mapToObj(__ -> "a")
                    .collect(Collectors.joining()));
        }
    }
}

到这里,我们使用MAT工具从对象清单、大对象、线程栈等视⻆,分析了一个OOM程序的堆转储。可以发现,有了堆转储,几乎相当于拿到了应用程序的源码+当时那一刻的快照,OOM的问题无从遁形。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 212,686评论 6 492
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 90,668评论 3 385
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 158,160评论 0 348
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 56,736评论 1 284
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 65,847评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,043评论 1 291
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,129评论 3 410
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,872评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,318评论 1 303
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,645评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,777评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,470评论 4 333
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,126评论 3 317
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,861评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,095评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,589评论 2 362
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,687评论 2 351