记一次OOM异常的排查经历(jstack、MAT)

1,095 阅读10分钟

问题背景

服务介绍

首先简单介绍下异常服务的背景。服务的背景可以概括为是一个消息队列的消费端服务,订阅上游消息队列的信息后,在本服务中对信息进行加工最后入库,如下图虚线中的部分。

服务背景

服务整体是 分布式 部署的,有若干个分布式部署的实例,如图共三个。每个实例负责承包消费一部分 partition,对于每个partition都启动一个receive线程 + 3个process线程用来对消息队列中的数据进行 接收 + 转换,最终以业务上需要的格式入库。服务中每个partition消费的细节如下:

  1. receive线程接收kafka订阅到的消息,并且将其存入本地消息队列msgQueue(一个LinkedBlockingQueue),receive线程的伪代码如下。
while(running):
    Msg msg = kakfa.receive()
    msgQueue.offer(msg)
  1. 每个msgQueue启动3个process线程处理消费,然后将结果存入另一个bizQueue(也是一个JDK内部的LinkedBlockingQueue),processor的流程也很简单,如下。
while(running):
    Msg rawMsg = msgQueue.poll();
    ProcessedMsg processed = process(rawMsg); # 经过各种转化与加工,处理成业务需要的格式
    bizQueue.offer(processed);
  1. 定时任务30ms执行一次,负责将bizQueue中的消息取出并且入库。

问题

关于服务的背景中,读者可能会有以下几个问题。

  1. 为什么要用kakfa这样的消息队列?
    是基于业务的背景,kafka队列中数据的消费方并不是只有本文中的服务这一种,还有很多其它的服务也在用着同样的消息,进行着其它的消息处理工作。这也正是利用到了消息队列的 解耦[^1] 的特性。同时,这也是为什么本服务中要在第2步进行消息的 转化与加工,因为消息的消费方有多个,不同消费方关注的内容不同,本服务中需要对队列中的消息进行提取与加工,只提取业务上关系的部分。

  2. 为什么服务内部处理的时候要用内存消息队列? 可以看到服务中共使用了两个内部的消费队列(msgQueue与bizQueue),这两个消息队列存在意义是解决 处理速度不匹配 的问题,从kafka拉取消息很快,但是消息加工可能会较慢,因此需要msgQueue来缓冲消息;同理,消息的加工可能较慢,但是入库的操作非常慢,这时也需要bizQueue来缓冲消费。

  3. 3个processor处理的时候,是否会有消息顺序性的问题? 分布式队列中一个很重要的问题就是 消息顺序消费问题[^1](例如转账通知短信一定要在转账完成后再发送),而其中解决局部消息有序的方式就是确保一个partition中的消息都是被顺序消费处理的。但是本文中在处理消息时使用了3个processor并行处理,操作系统四大特性中的 异步性[^2] 显然无法保证消费的顺序执行,但是本文中的业务对消息的顺序性并不敏感,因此可以这样使用。对于消息顺序性敏感的场景需要注意。

问题现象 & 排查步骤

问题现象

书归正文,本次OOM问题的现象为,在服务重启运行一段时间后会因为OutOfMemoryError导致服务断流(即停止消费),即出现了 内存溢出 的现象,疑似存在 内存泄漏 的可能。

内存溢出与内存泄漏,内存溢出是结果OutOfMemoryError,内存泄漏是可能导致内存溢出的原因,可能因为某些本该回收的对象因为代码问题等某些原因无法被GC回收,这种不该存留的对象越来越多,最终堵满内存(就像浴室下水的头发)。
但是并不是所有OOM问题都是因为内存泄漏,有可能就是内存不够,例如本文的问题最终定位为性能不足的问题。

排查步骤

dump内存

最开始的时候当然是优先采用八字真言:“多喝热水,重启试试”。

多喝热水,重启试试 多喝热水,重启试试

在反复重启又反复出现OOM问题后,我们发现问题并不简单,看来需要认真排查一下服务的问题。 眉头一皱 问题并不简单

第一步,调整JVM启动参数在OOM发生时自动dump

正常运行的服务的内存是无法看出有任何异常情况的,而当服务已经OOM之后,如果没有try-catch这种情况的话,一般线程就会崩溃停止任务的执行,相当于Java直接掀了桌子,这之后的内存信息也没有了任何参考价值,只有当正在发生OOM那一刻的内存才是最有分析意义的。
于是我们调整了JVM的启动参数,增加了-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/server/dump.hprof,参数的含义是让JVM在发生OOM时自动生成jstack的dump文件到指定目录下。

第二步,linux的MAT分析工具

修改好参数后,重启服务,果然不久问题就复现了,并且成功产出了一份dump.hprof文件,接下来需要进行文件分析,需要用到ecplise的MAT工具,我们平常使用的都是windows版的MAT,有着完善的操作功能,但是线上服务的内存dump文件有8G,而线上生产环境往往使用的linux的操作系统,因此就需要我们将这份文件传到windows机器上,传输的过程会浪费太多宝贵的排查时间。因此笔者选择直接在linux上执行MAT分析内存。

在网上搜索 linux MAT 后,发现都是互相copy-paste的一份博客,可以通过上官网下载linux版的MAT,然后执行 ./ParseHeapDump.sh生成几MB的zip打包的内存分析结果html网页文件(linux MAT的使用方法网上千篇一律复制了同一份博客,本文不再赘述),然后下载zip文件,打开其中的index.html网页后,可以粗略的看到内存的占用概况。

dump_Leak_Suspects

通过分析其中的Class HistogramTop Consumersdump_Leak_Suspects,已经基本可以确定,就是服务中这些LinkedBlockingQueue中保存了过多的数据(每个Queue高达300M),从而导致了OOM问题的发生。那么问题来了,通过上文中背景的描述我们知道,服务中分别有两处使用了LinkedBlockingQueue,到底是哪一个呢?通过linux MAT生成的概览我无法获取到更加详细的信息,网上的搜索结果也是千篇一律的复制同一份博客,根本没有提到这个问题。

Class Histogram

Top Consumers

第三步,果然还是需要用windows MAT,将dump文件从linux传入windows

基于linux dump出的结果,我们已经将犯罪嫌疑人锁定在了msgQueuebizQueue这两个队列上,但是目前linux生成的dump文件无法支持笔者进一步的分析。于是笔者又回到了第二步一开始的问题,如何将8G的linux文件传输到自己的windows机器上?

经过一系列搜索后,笔者总结出如下几种办法:

  1. 用sz功能,但是windows的sz功能有文件大小限制,如果直接使用sz会收到这样的弹窗提示 不支持sz 4G以上的文件 经过笔者的一轮搜索后,发现解决的办法只能是通过cat dump.hprof | split -b 2G - dump.hprof命令将文件切割开,挨个sz过来后,在windows上执行cmd命令copy /B dump.hprof.a + dump.hprof.b + dump.hprof.c dump.hprof合并到一起

  2. 通过python -m SimpleHTTPServer,前提是linux机器上有python环境,这样的话会启动一个小型的http服务器,然后在windows的地址栏输入linuxhost:8000,下载dump文件

笔者采用了后者。

第四步,MAT内存分析过程与结论

综上,我们知道了问题出在LinkedBlockingQueue,也下载到了dump文件,通过windows的MAT工具打开分析dump文件后,我们可以进一步确认到底是哪个queue堆满了。 通过dominator tree,我们看到了占用百分比最高的几个LinkedBlockingQueue。

dominator tree

通过查看这些LinkedBlockingQueue的incoming references,我们定位到原来是msgQueue。

incoming references

通过对上面的背景分析可知,如果是bizQueue堆积,很有可能是步骤3阻塞,导致bizQueue产生的消息迟迟没有消费。现在既然是msgQueue的堆积,那么最有可能的是三个processor处理的过程中阻塞。这时候又用到了内存dump的thread_overview(线程栈dump)功能,processor线程在启动的时候有特殊的命名,通过线程名搜索到并观察了每个线程的执行状态后,笔者发现,processor线程并没有阻塞的嫌疑。

thread_overview

那么综上排查到现在为止,所有的可能性都排除之后,只有一个可能性,即 不是消费的太慢了,而是生产的太快了,通过对代码历史注释的理解和内存栈的分析,笔者发现,当前从kafka中获取的每个消息包中共有100个消息,而历史注释中表示每个消息包中一般40条消息,也就是说kafka上游最近调大了每个包的消息数量,从而导致同样轮询速度的receiver同时间写入msgQueue的消息量变大了,下游消费不及时,导致了OOM。

通过对服务的实例进行扩容操作(扩容100/40=2.5倍),再观察了一段时间后,OOM问题成功得到解决。

MAT的几个术语解释

  1. incoming references 和 outcoming references
public class Foo {
    private LinkedBlockingQueue msgQueue;
}

对于上面的Foo类的对象来说,指向关系是 Foo --> msgQueue,因此对于Foo的视角来说,out refercences是msgQueue,对于msgQueue来说,in references是Foo

  1. shallow heap 与 retained heap 同样以上面的Foo类为例,对Foo类产生的对象foo来说,其实foo本身就只是 一个对象头+一大堆相关参数+一个执行msgQueue的指针(64bit) 的数据而已,这个就是shallow heap。但是如果能够将foo回收掉,那么msgQueue也能 级联 回收掉,那么将回收掉Foo+msgQueue的全部内存,这就是retained heap
    举例子就好像一个人身上可能只有几块钱,这是shallow钱,但是他的手机、银行卡、名下的资产等等由他的身份指向的资产可能有几个亿,这就是retained钱。

结论与反思

虽然最后的结论很简单,对实例进行了横向扩容就可以解决,但是排查的过程与经验是宝贵的。同时,我们要反思,为什么会出现这样的情况。通过代码可以看到,msgQueue的capacity容量是固定限制为3000的。 OQL msgQueue的capacity

但是从内存dump文件的分析来看,仅仅使用了285个就导致内存OOM了,就算是LinkedBlockingQueue中的包的大小被扩充了2.5倍,之前的方式285*2.5=712.5个元素的时候仍然能撑爆内存

msgQueue的capacity

本身如果msgQueue的capacity大小限制合理的话,会在达到容量上限的时候阻塞receiver的接收操作,等待下游的消费,即使消费速度变慢,但是也还是能够使得流式系统正常运行的。因此,本次case的根本原因在于LinkedBlockingQueue容量capacity设置的不合理导致。

references

  1. ^ 《分布式消息中间件实践》
  2. ^ 《深入理解计算机系统》