在日常后端开发中,部分业务都是接收MQ消息,在消费消息的过程中,会调用外部的Dubbo接口,根据接口返回数据,做一些业务逻辑处理.如下图
模型.jpg
上面会涉及两类线程,一类是MQ线程,一类是Dubbo线程.
Dubbo接口调用超时也是经常会发生的事情,这篇文章中,我们模拟的情况是,让Dubbo接口调用超时,图中红线所示.然后一直向MQ消费者发送消息,我们观察线程和堆栈的变化.
模型-1.jpg
仓库代码
https://github.com/infuq/MQ-Dubbo-FullGC
如果需要运行上述代码,还需要部署Zookeeper和RocketMQ环境.
工程结构如下图
结构图.jpg
Dubbo提供者的接口超时时间设置的是5s.如下图
Dubbo提供者.jpg
而在提供者的实现方法中,让线程睡眠20秒,从而达到调用者调用接口超时目的.如下图
接口超时.jpg
接下来按顺序启动它们
首先启动Dubbo提供者(DubboProvider类).
接着启动MQConsumer, 同时需要给它配置VM启动参数
-Xms90M -Xmx90M -XX:+PrintGCDetails
启动参数.jpg
最后启动MQProducer, 它会一直发送消息.
所有的都启动完成之后, 借助JDK自带的jvisualvm.exe工具观察MQConsumer的堆栈信息.
排查工具.jpg
观察MQConsumer的堆栈信息,会发现老年代会一直增长,当老年代快增长到顶端时,手动dump堆栈信息,用于接下来分析堆的情况.
快达到满.jpg
手动dump.jpg
同时观察MQConsumer的控制台, 会有FullGC产生,而且很多次.
FullGC产生.jpg
大体流程就是上面描述. 发现的表象是老年代一直在增长,伴随着发生了FullGC,那么原因是什么?
通过MemoryAnalyzer来分析下之前dump的堆栈文件.
打开文件之后,点击Dominator_Tree.
分析1.jpg
接口超时.jpg
继续点击
分析2.jpg
分析3.jpg
发现数量最多的是MessageClientExt这个类对象.它是和消息有关.
分析5.jpg
右击,选择with outgoing references
分析6.jpg
任意展开一个对象,查看body的内容就是MQProducer发送的消息体内容.
分析7.jpg
也就是说,随着MQProducer生产者一直发送消息, MQConsumer消费者的堆空间中存储着大量的未被消费的消息.
由于Dubbo接口调用超时,阻塞住了MQ消费消息的线程,而MQ生产者一直在生产消息,可消费消息的速度太慢(由于Dubbo调用超时间接导致),最终消息都被放在老年代堆空间中,引起频繁FullGC.
链式反应.jpg
通过查看MQ源码
// 源码位置
org.apache.rocketmq.client.impl.consumer.ConsumeMessageConcurrentlyService
无界队列.jpg
存放消息的队列是一个无界队列,也就是说,只要消息生产者生产消息的速度比消费者消费消息的速度快很多很多,最终一定会发生FullGC,更严重发生OOM.至于消费者消费消息的速度为什么慢,比如上面的情况,调用Dubbo接口耗时太久等原因.这里要说一点的是,导致Dubbo接口耗时太久的重要一点是因为Dubbo中需要查询数据库耗时太久(慢SQL).
数据库.jpg
RocketMQ和Dubbo, 导致FullGC的原因以及造成FullGC的地方还有很多,接下来的文章也会一一列举出来.
针对这篇文章,也会抽个时间录播一个视频演示给大家看.
网友评论