RocketMQ消费端大量重复消息原因分享

仓储中心生产RocketMQ消费端大量重复消息原因分享

一、线上问题简单回顾

1.1、线上问题大致经过

7月3日，监控预警POD自动重启、业务也反馈仓储相关功能使用异常；在未找到原因的情况下先采取了回滚版本（前一天有发布版本）和几次重启服务尝试，发现服务启动后很快又不可用；期间同步分析查看日志发现有个消息ID不断有消费日志且数量巨大，查看消费者业务代码逻辑发现存在较多数据库事务操作，使用了Seate，且单据明细较大处理耗时大。

至此基本定位问题直接原因：某个消费者接收到了大量重复消息，在处理大量重复消息时把数据库线程耗尽，导致其它业务访问异常。

临时处理方案：在咨询运维无法删除MQ某个消息的情况下，采取修改消费端代码先忽略处理该消息ID后重新发布后系统恢复正常。

1.2、大家所熟知的MQ消费处理逻辑

且线上其它常见重试消息情况也如上图逻辑如此：reconsumeTimes未超过16（0-16一共17次）。

1.3、线上问题的非常见异常情况

相同消息ID重试次数超过16次，且同一个重试次数存在多条消息 。

1.4、猜测可能的原因

1）reconsumeTimes值更新有问题：没有在每次重试后+1，导致其不断发送重试消息。

2）消费超时时发送的重试消息reconsumeTimes次数为0，而每次重试消息又无法成功消费（无法响应结果），导致其进入死循环不断发送重试消息。后面分析发现都不是，且没有其他思路。

二、原因分析

2.1、想办法复现问题

分析前先简单了解什么是消息队列的offset值：消费偏移量offset就是记录消费者的消费进度的。也是rocketmq保证消息不会重复消费的核心。

在没有合理怀疑对象的情况下，开始想办法模拟生产情况复现问题，比较幸运的是问题比较容易就得到了复现。复现过程如下：

1. 模拟消费者消费超时，想观察MQ是如何处理的。（这个模拟开始未发现问题，其实如果服务重启会有上述类似问题，下面会有补充说明）

做这个模拟时发现，消费超时默认设定是15分钟，到了超时时间消费者并不会中断消费线程，而是有另外一个线程定时监控消费超过15分钟还没有结果的消息，并发送重试消息到MQ服务端，同时reconsumeTimes会+1。模拟结果与我们所熟知的消费超时重试一样，与线上问题不相符，继续模拟。

1. 模拟消费者还在消费消息的情况下关闭服务，观察是否会有重复消息。

发现消费中的消息被中断后，offset值未+1，下次重启时还是之前消息，并没有生成重试的消息。与线上问题不相符，继续模拟。

1. 模拟消费者还在消费（有业务异常）消息的情况下关闭服务，观察是否会有重复消息。

发现重启服务后有重复消息，原消息还在，并且有一条重试消息（异常情况有点类似生产问题了）。于是再多次重启服务，发现重复消息呈2倍数增长，很快超过16条，并且同一个重试次数存在多条消息，基本可以确认和生产情况一致了。

于是针对这个场景抓住两个关键点：JVM退出、消费异常进行源码分析，分析这两点处理逻辑发现：

JVM退出时：调用的是DefaultMQPushConsumerImpl#shutdown(long)，该方法有关键两步：1）关停消费者线程池。2）同步本地offset值给MQ服务端；

消费异常时：处理消费结果时会发送一条重试消息给服务端。

所以这个时候初步怀疑这里发送重试消息导致重复了，但是这里还是有两个疑问：1）服务退出了，为什么代码逻辑还会走到发送重试消息这里，且相关日志也并没有打印在控制台。2）原消息为什么没有标记为已消费。

反复分析无果后，始终怀疑JVM退出时消费代码逻辑会继续往下走，日志未打印是否因为在服务退出时log.info/log.warn等日志输出无效（这个很干扰判断）。为了验证从GitHub拉取相同版本RocketMQ代码加上System.out.println()日志输出后重新本地install发布到本地Maven仓库。得到的结果是：确实在服务重启时消费处理的业务逻辑会继续往下走，会走到发送重试消息的代码逻辑。

1. 模拟消费者还在消费（有业务异常）消息的情况下强制（kill -9）退出服务，观察是否会有重复消息

为了进一步验证上一步的结论，我们再做了一个补充场景的验证，发现在强制重启时，基本不存在该问题（在finally中抛异常或使用idea的双击退出也存在该问题）。

基于上述四个场景的模拟基本得出结论：MQ消费端，在JVM退出时，消费中的消息；offset最新值未成功同步给MQ服务端，且消费处理的逻辑会继续往下走，在有业务异常情况下会发送重试消息给服务端，导致消息重复，在服务不断重启的情况下重复消息会呈2倍数增长。

2.2、针对分析结果对源码加更多日志验证

继续查看源码分析：为什么消息请求的执行队列被drop掉了，在哪里drop掉的。我们找到了DefaultMQPushConsumerImpl#shutdown方法，这个方法是在JVM退出时调用的，继续加日志打印。

2.3、问题真正原因

JVM退出时调用的org.apache.rocketmq.client.impl.consumer.DefaultMQPushConsumerImpl#shutdown(long)方法，无法让程序逻辑严格按代码执行。

2.4、回过头来看与本次相关的消费者核心业务逻辑时序图

5.3与6.1的执行顺序未被保证

2.5、了解源码后再来看JVM退出时消费者在不同情况下可能出现的问题

结合源码和已复现出的异常情况再对不同情况消费梳理分析

情况3：复现了该问题（比较简单不做过多解释），消费者只要做好幂等处理，消息不会成倍增长，不会有太大问题。

情况2：前面已复现了该问题，下面会有解决方案的介绍。

情况1：前面复现结果与我们结合源代码分析的结论不一致，下面再次做了验证发现：（上面没有复现到是没有掐准时间点）

1）超时中断时有异常：超时后消费端会发送重试消息，JVM退出时原消息offset又未更新，异常又会发送重试消息，存在3条（含原消息）重复的情况，比情况2更严重，但需要消费者消费都超过15分钟，下面会有解决方案的介绍。

2）超时中断时没有异常：超时后消费端会发送重试消息，JVM退出时原消息offset又未更新，存在重复的情况，但需要消费者消费都超过15分钟，下面会有解决方案的介绍。

2.6、DEV\QA复现验证

先看下K8S滚动发布流程：

• 启动一个新的 pod

• 等待新的 pod 进入 Ready 状态

• 创建 Endpoint，将新的 pod 纳入负载均衡

• 移除与老 pod 相关的 Endpoint，并且将老 pod 状态设置为 Terminating，此时将不会有新的请求到达老 pod

• 给老 pod 发送 SIGTERM 信号，并且等待 terminationGracePeriodSeconds 这么长的时间。(默认为 30 秒，dev/qa也是这个配置)

• 超过 terminationGracePeriodSeconds 等待时间直接强制 kill 进程并关闭旧的 pod

实操发现dev/qa旧pod都是在30秒超时后被强制kill了，旧pod并不一定是优雅退出，遗憾的是试了多次未在dev/qa复现成功。（因本就不可控）

三、解决办法

3.1、分析如何解决

1）如果发送了重试消息，MQ服务端offset必须更新为已消费；或者offset不更新，但不发送重试消息。

2）消费者自己的超时时间不能超过15分钟。（或者说消费者在15分钟内必须要有结果响应）

1. 先找官网的解决方案

查看了RocketMQ Github最新版本（5.1.3）代码和相关的issue并未找到相关解决的代码升级。也查看了官网的常见问题解答。觉得这算是一个bug，于是给RocketMQ Github提了issue。https://github.com/apache/rocketmq/issues/7182

1. 自己想办法解决

如果按第一种解决思路处理只要保证

org.apache.rocketmq.client.impl.consumer.DefaultMQPushConsumerImpl#shutdown(long)方法执行逻辑和代码顺序一致。

如何保证？调大消费者线程池中断等待时间毫秒值。即方法org.apache.rocketmq.client.impl.consumer.ConsumeMessageService#shutdown(long)的入参awaitTerminateMillis的值，默认为0即不等待。

将等待时间调整到200毫秒时本地验证可以解决该问题，为了保证可靠线上建议配置为30秒（30秒退出不了POD被强制kill）；该值设置的比较大时只影响JVM退出时间。

3.2、如何配置

盘古springboot项目统一使用了rocketmq-spirng-boot的AutoConfiguration，而自动配置类并未开放awaitTerminationMillisWhenShutdown值的配置，所以找另外一种配置方式：

1）方式一：对单个可能存在上述异常的消费者配置该参数

Java package tech.zj.quanbu.plmz.osp.wms.common.mq.consumer; import lombok.extern.slf4j.Slf4j; import org.apache.rocketmq.client.consumer.DefaultMQPushConsumer; import org.apache.rocketmq.common.message.MessageExt; import org.apache.rocketmq.spring.annotation.RocketMQMessageListener; import org.apache.rocketmq.spring.core.RocketMQListener; import org.apache.rocketmq.spring.core.RocketMQPushConsumerLifecycleListener; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.stereotype.Component; @Slf4j @Component @RocketMQMessageListener(topic = "TOPIC_BPM_PROCESS_INSTANCE_EVENT", consumerGroup = "PG_WMS_INVENTORY_ADJUST_LIUYUAN", selectorExpression = "PG_WMS_INVENTORY_ADJUST") public class InventoryAdjustBpmConsumer implements RocketMQListener<MessageExt>,RocketMQPushConsumerLifecycleListener {     @Override     public void onMessage(MessageExt message) {         log.info("消费者收到消息：messageId={}，message={}", message.getMsgId(), message);         long millis = 20 * 60 * 1000;         try {             // 模拟程序处理超时             Thread.sleep(millis);         } catch (InterruptedException e) {             e.printStackTrace();         }         System.out.println("当前时间毫秒值【"+System.currentTimeMillis() + "】，Thread【"+                 Thread.currentThread().getName()+"_"+Thread.currentThread().getId()+"】消费者.onMessage.MsgId：" + message.getMsgId());         // 模拟抛异常         int excption = 10/0;     }     @Override     public void prepareStart(DefaultMQPushConsumer consumer) {         // 设置awaitTerminationMillisWhenShutdown值（毫秒值）         consumer.setAwaitTerminationMillisWhenShutdown(200);     } }

2）方式二：全局配置

问题服务采用该配置，本周四上线验证

Java package tech.zj.quanbu.plmz.osp.wms.common.config; import org.apache.rocketmq.spring.support.DefaultRocketMQListenerContainer; import org.springframework.beans.BeansException; import org.springframework.beans.factory.annotation.Value; import org.springframework.context.ApplicationContext; import org.springframework.context.ApplicationContextAware; import org.springframework.context.SmartLifecycle; import org.springframework.context.annotation.Configuration; import java.util.Map; /**  *  全局设置消费者参数：awaitTerminationMillisWhenShutdown配置类  *  awaitTerminationMillisWhenShutdown：关闭使用者时等待消息的最长时间，0（默认）表示无等待。  */ @Configuration public class MQConsumerConfigurtion implements ApplicationContextAware, SmartLifecycle {     private ApplicationContext applicationContext;     @Value("${rocketmq.consumer.awaitTerminationMillisWhenShutdown}")     private long awaitTerminationMillisWhenShutdown;     @Override     public void setApplicationContext(ApplicationContext applicationContext) throws BeansException {         this.applicationContext = applicationContext;     }     /**      * 需要在springbean生命周期函数afterSingletonsInstantiated之后获取，原因请看：org.apache.rocketmq.spring.autoconfigure.ListenerContainerConfiguration      */      @Override     public void start() {         // spring容器中找出所有DefaultRocketMQListenerContainer类，设置awaitTerminationMillisWhenShutdown值（毫秒值）         Map<String, DefaultRocketMQListenerContainer> beansOfType = applicationContext.getBeansOfType(DefaultRocketMQListenerContainer.class);         beansOfType.forEach((k,container)-> {             container.getConsumer().setAwaitTerminationMillisWhenShutdown(awaitTerminationMillisWhenShutdown);         });     }     @Override     public void stop() {     }     @Override     public boolean isRunning() {         return false;     } }

四、可能造成重复消息的其它非常见情况

4.1、消息发送异常时重复发送

消息生产者在消息发送给MQ服务端失败时也会重试，默认会重试两次；

4.2、消费者提交offset失败

上面分析时我们提到，消费者成功消费消息后更新的是消费端消息的offset值；另外有个定时任务同步到服务端；由于是定时任务，所以就可能出现服务器一旦宕机，导致最新消费的offset没有成功告诉RocketMQ服务端的情况；此时，消费进度offset就丢了，那么消费者重启的时候只能从RocketMQ中获取到上一次提交的offset，此时必然会导致消息又出现重复消费的情况。

4.3、重平衡（Rebalance）

重平衡简单理解为：重新分配每个消费者消费的队列。

集群消费模式情况下（RocketMQ默认是集群消费模式），消费者增加、减少，队列数据增加或减少都可能触发重平衡。如下举例消费者增加：

4.4、总结

上述几种重复消费情况，只要我们做好消费端逻辑的幂等处理就可以基本避免；除了上述这些情况，其实还有其它很多场景可能导致消费重复，RocketMQ官方文档也有做类似说明。

所以RocketMQ也并不是我们想象的那么的可靠，所以消费者代码保证业务幂等性很重要。

五、总体的整改建议

1、配置上解决方3.2中的配置，防止服务在不断重启时重复消息成倍增长。

2、消费端消费逻辑不能超过MQ默认超时时间15分钟。

3、消费端代码必须保证业务幂等性。

六、参考资料

官网文档：https://rocketmq.apache.org/zh/docs/4.x

GitHub代码地址：https://github.com/apache/rocketmq

其它资料：https://blog.csdn.net/qq_38730338/article/details/131548212