MQ消息重复投递问题
consumeTimeout设置每条消息消费的最大超时时间,超过这个时间,这条消息将会被视为消费失败,等下次重新投递再次消费. 每个业务需要设置一个合理的值. 单位(分钟).
consumeTimeout默认值15分钟
com.aliyun.openservices.shade.com.alibaba.rocketmq.client.consumer.DefaultMQPushConsumer#consumeTimeout
消费端是一个导出服务, MQ线程执行导出业务代码. 导出耗时在20分钟以上, 老年代内存持续飙高, 发生OOM.
日志位置:
Window系统 C:\Users\用户名\logs\ons.log
Linux系统 /{user.home}/logs/ons.log
登录消费端容器, 查看ons.log日志, 消费端发生OOM
Jenkins打包引用了低版本的jar,低版本的jar没有对应的方法. 业务监听处理MQ只捕获Exception,没有捕获Error异常
消费端已经消费成功, 但Broker仍然重复投递.
根据以上分析, 造成Broker重复投递的可能性, 从两个角度分析
1.从消费端角度分析,包括以下3点:
1.1消费端消息被处理时间超过15分钟(consumeTimeout默认15分钟)
1.2消费端发生OOM
1.3消费端发生Error异常
1.4消费端重启容器
2.从Broker角度分析, 消息已经消费成功, 但仍然被重复投递.
1.消息重试
2.消息重试
3.客户端配置
4.订阅消息
<dependency>
<groupId>com.aliyun.openservices</groupId>
<artifactId>ons-client</artifactId>
<version>1.8.8.8.Final</version>
</dependency>
consumeTimeout设置每条消息消费的最大超时时间,超过这个时间,这条消息将会被视为消费失败,等下次重新投递再次消费. 每个业务需要设置一个合理的值. 单位(分钟).
consumeTimeout默认值15分钟
com.aliyun.openservices.shade.com.alibaba.rocketmq.client.consumer.DefaultMQPushConsumer#consumeTimeout
消费端是一个导出服务, MQ线程执行导出业务代码. 导出耗时在20分钟以上, 老年代内存持续飙高, 发生OOM.
日志位置:
Window系统 C:\Users\用户名\logs\ons.log
Linux系统 /{user.home}/logs/ons.log
登录消费端容器, 查看ons.log日志, 消费端发生OOM
2023-08-17 20:10:28,028 INFO RocketmqRemoting - createChannel: connect remote host[MQ_INST_1106705442396860_BXXINmp6.cn-hangzhou.mq-internal.aliyuncs.com:8080] success, AbstractBootstrap$PendingRegistrationPromise@7f4fc5a0(success)
2023-08-17 20:10:28,028 WARN RocketmqClient - consumeMessage exception: java.lang.OutOfMemoryError: Java heap space Group: MQ_INST_1106705442396860_BXXINmp6%GID_WISP_EXPORT_TEST Msgs: [MessageExt [brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=1, storeSize=979, queueOffset=0, sysFlag=0, bornTimestamp=1692273495088, bornHost=/10.128.133.71:10911, storeTimestamp=1692273869358, storeHost=/100.103.52.24:8080, msgId=6467341800001F9000000B2EC94727B9, commitLogOffset=12295573284793, bodyCRC=356915524, reconsumeTimes=1, preparedTransactionOffset=0, version=MESSAGE_VERSION_V1, toString()=Message [topic=TEST, flag=0, properties={x-datadog-sampling-priority=1, CONSUME_START_TIME=1692273910119, __BORNHOST=172.16.217.96:35898, INSTANCE_ID=MQ_INST_1106705442396860_BXXINmp6, TIMER_OUT_MS=1692273498000, __FQN_TOPIC=MQ_INST_1106705442396860_BXXINmp6%TEST, x-datadog-parent-id=5093310345290086160, RETRY_TOPIC=MQ_INST_1106705442396860_BXXINmp6%TEST, __MESSAGE_DECODED_TIME=1692273910118, KEYS=391680444670128128, MSG_REGION=cn-hangzhou, TIMER_DELIVER_MS=1692273498087, UNIQ_KEY=AC10D9600007324C64CD56AEC8300030, 1ST_POP_TIME=1692273866324, TRACE_ON=true, TIMER_DEQUEUE_MS=1692273499042, x-datadog-trace-id=4880352449951899680, __STARTDELIVERTIME=1692273498087, TIMER_ENQUEUE_MS=1692273495000, MIN_OFFSET=0, REAL_TOPIC=MQ_INST_1106705442396860_BXXINmp6%TEST, POP_CK=1 1692273910080 60000 0 1 hz-share20-02 0 1, MAX_OFFSET=3, TAGS=CREATE_EXPORT_TASK_NOTICE, REAL_QID=3}, body=37]]] MQ: MessageQueue [topic=MQ_INST_1106705442396860_BXXINmp6%TEST, brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=1]
2023-08-17 20:10:28,028 WARN RocketmqClient - consumeMessage return null, Group: MQ_INST_1106705442396860_BXXINmp6%GID_WISP_EXPORT_TEST Msgs: [MessageExt [brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=1, storeSize=979, queueOffset=0, sysFlag=0, bornTimestamp=1692273495088, bornHost=/10.128.133.71:10911, storeTimestamp=1692273869358, storeHost=/100.103.52.24:8080, msgId=6467341800001F9000000B2EC94727B9, commitLogOffset=12295573284793, bodyCRC=356915524, reconsumeTimes=1, preparedTransactionOffset=0, version=MESSAGE_VERSION_V1, toString()=Message [topic=TEST, flag=0, properties={x-datadog-sampling-priority=1, CONSUME_START_TIME=1692273910119, __BORNHOST=172.16.217.96:35898, INSTANCE_ID=MQ_INST_1106705442396860_BXXINmp6, TIMER_OUT_MS=1692273498000, __FQN_TOPIC=MQ_INST_1106705442396860_BXXINmp6%TEST, x-datadog-parent-id=5093310345290086160, RETRY_TOPIC=MQ_INST_1106705442396860_BXXINmp6%TEST, __MESSAGE_DECODED_TIME=1692273910118, KEYS=391680444670128128, MSG_REGION=cn-hangzhou, TIMER_DELIVER_MS=1692273498087, UNIQ_KEY=AC10D9600007324C64CD56AEC8300030, 1ST_POP_TIME=1692273866324, TRACE_ON=true, TIMER_DEQUEUE_MS=1692273499042, x-datadog-trace-id=4880352449951899680, __STARTDELIVERTIME=1692273498087, TIMER_ENQUEUE_MS=1692273495000, MIN_OFFSET=0, REAL_TOPIC=MQ_INST_1106705442396860_BXXINmp6%TEST, POP_CK=1 1692273910080 60000 0 1 hz-share20-02 0 1, MAX_OFFSET=3, TAGS=CREATE_EXPORT_TASK_NOTICE, REAL_QID=3}, body=37]]] MQ: MessageQueue [topic=MQ_INST_1106705442396860_BXXINmp6%TEST, brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=1]
2023-08-17 20:10:28,028 INFO RocketmqRemoting - createChannel: begin to connect remote host[100.103.52.24:8080] asynchronously
Jenkins打包引用了低版本的jar,低版本的jar没有对应的方法. 业务监听处理MQ只捕获Exception,没有捕获Error异常
2023-11-08 15:18:54,054 WARN RocketmqClient - consumeMessage exception: java.lang.NoSuchMethodError: com.xxx.open.platform.common.dto.Result.getRawData()Ljava/lang/String;, com.xxx.open.platform.sync.service.strategy.push.AbstractPushStrategy.updatePushRecordFail(AbstractPushStrategy.java:208) Group: MQ_INST_1106705442396860_BXXINmp6%GID_SERVICE_OPEN_PLATFORM_SYNC_PROD Msgs: [MessageExt [brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=1, storeSize=4200, queueOffset=383, sysFlag=0, bornTimestamp=1699424559589, bornHost=/10.128.133.71:10911, storeTimestamp=1699427934645, storeHost=/100.103.52.24:8080, msgId=6467341800001F9000000E858C806D61, commitLogOffset=15966750666081, bodyCRC=2107284636, reconsumeTimes=12, preparedTransactionOffset=0, version=MESSAGE_VERSION_V1, toString()=Message [topic=OPEN_PLATFORM_PROD, flag=0, properties={x-datadog-sampling-priority=2, TRACE_ON=true, x-datadog-origin=rum, CONSUME_START_TIME=1699427934652, x-datadog-trace-id=15109858784157195082, __STARTDELIVERTIME=1699424559589, __BORNHOST=192.168.0.7:5379, INSTANCE_ID=MQ_INST_1106705442396860_BXXINmp6, __FQN_TOPIC=%RETRY%MQ_INST_1106705442396860_BXXINmp6%GID_SERVICE_OPEN_PLATFORM_SYNC_PROD_MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, MIN_OFFSET=0, x-datadog-parent-id=5461850263327541565, x-datadog-tags=_dd.p.dm=-1, POP_CK=3677 1699427934647 60000 5 1 hz-share20-02 0 3677, RETRY_TOPIC=MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, __MESSAGE_DECODED_TIME=1699427934650, MAX_OFFSET=385, KEYS=AIRR4moZSj70231108142239579, MSG_REGION=cn-hangzhou, UNIQ_KEY=0A04013100071BF0F6F627224DE54E97, 1ST_POP_TIME=1699424559703, TAGS=receive}, body=3339]]] MQ: MessageQueue [topic=MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=1]
2023-11-08 15:18:54,054 WARN RocketmqClient - consumeMessage return null, Group: MQ_INST_1106705442396860_BXXINmp6%GID_SERVICE_OPEN_PLATFORM_SYNC_PROD Msgs: [MessageExt [brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=1, storeSize=4200, queueOffset=383, sysFlag=0, bornTimestamp=1699424559589, bornHost=/10.128.133.71:10911, storeTimestamp=1699427934645, storeHost=/100.103.52.24:8080, msgId=6467341800001F9000000E858C806D61, commitLogOffset=15966750666081, bodyCRC=2107284636, reconsumeTimes=12, preparedTransactionOffset=0, version=MESSAGE_VERSION_V1, toString()=Message [topic=OPEN_PLATFORM_PROD, flag=0, properties={x-datadog-sampling-priority=2, TRACE_ON=true, x-datadog-origin=rum, CONSUME_START_TIME=1699427934652, x-datadog-trace-id=15109858784157195082, __STARTDELIVERTIME=1699424559589, __BORNHOST=192.168.0.7:5379, INSTANCE_ID=MQ_INST_1106705442396860_BXXINmp6, __FQN_TOPIC=%RETRY%MQ_INST_1106705442396860_BXXINmp6%GID_SERVICE_OPEN_PLATFORM_SYNC_PROD_MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, MIN_OFFSET=0, x-datadog-parent-id=5461850263327541565, x-datadog-tags=_dd.p.dm=-1, POP_CK=3677 1699427934647 60000 5 1 hz-share20-02 0 3677, RETRY_TOPIC=MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, __MESSAGE_DECODED_TIME=1699427934650, MAX_OFFSET=385, KEYS=AIRR4moZSj70231108142239579, MSG_REGION=cn-hangzhou, UNIQ_KEY=0A04013100071BF0F6F627224DE54E97, 1ST_POP_TIME=1699424559703, TAGS=receive}, body=3339]]] MQ: MessageQueue [topic=MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=1]
2023-11-08 15:18:55,055 WARN RocketmqClient - consumeMessage exception: java.lang.NoSuchMethodError: com.xxx.open.platform.common.dto.Result.getRawData()Ljava/lang/String;, com.xxx.open.platform.sync.service.strategy.push.AbstractPushStrategy.updatePushRecordFail(AbstractPushStrategy.java:208) Group: MQ_INST_1106705442396860_BXXINmp6%GID_SERVICE_OPEN_PLATFORM_SYNC_PROD Msgs: [MessageExt [brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=0, storeSize=3723, queueOffset=357, sysFlag=1, bornTimestamp=1699426187954, bornHost=/10.128.133.83:10911, storeTimestamp=1699427935145, storeHost=/100.103.52.24:8080, msgId=6467341800001F90000012E098906F5B, commitLogOffset=20755841576795, bodyCRC=902818159, reconsumeTimes=9, preparedTransactionOffset=0, version=MESSAGE_VERSION_V1, toString()=Message [topic=OPEN_PLATFORM_PROD, flag=0, properties={x-datadog-sampling-priority=1, TRACE_ON=true, CONSUME_START_TIME=1699427935152, x-datadog-trace-id=6908933930403372124, __STARTDELIVERTIME=1699426187953, __BORNHOST=192.168.0.7:19232, INSTANCE_ID=MQ_INST_1106705442396860_BXXINmp6, __FQN_TOPIC=%RETRY%MQ_INST_1106705442396860_BXXINmp6%GID_SERVICE_OPEN_PLATFORM_SYNC_PROD_MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, MIN_OFFSET=0, x-datadog-parent-id=4425668439989415671, x-datadog-tags=_dd.p.dm=-1, POP_CK=3234 1699427935148 60000 0 1 hz-share20-01 0 3234, RETRY_TOPIC=MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, __MESSAGE_DECODED_TIME=1699427935150, MAX_OFFSET=359, KEYS=AIRRyCAwz0fY231108144947940, MSG_REGION=cn-hangzhou, UNIQ_KEY=0A04013B00071BF0F6F6273B26B21179, 1ST_POP_TIME=1699426188030, TAGS=receive}, body=18925]]] MQ: MessageQueue [topic=MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=0]
2023-11-08 15:18:55,055 WARN RocketmqClient - consumeMessage return null, Group: MQ_INST_1106705442396860_BXXINmp6%GID_SERVICE_OPEN_PLATFORM_SYNC_PROD Msgs: [MessageExt [brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=0, storeSize=3723, queueOffset=357, sysFlag=1, bornTimestamp=1699426187954, bornHost=/10.128.133.83:10911, storeTimestamp=1699427935145, storeHost=/100.103.52.24:8080, msgId=6467341800001F90000012E098906F5B, commitLogOffset=20755841576795, bodyCRC=902818159, reconsumeTimes=9, preparedTransactionOffset=0, version=MESSAGE_VERSION_V1, toString()=Message [topic=OPEN_PLATFORM_PROD, flag=0, properties={x-datadog-sampling-priority=1, TRACE_ON=true, CONSUME_START_TIME=1699427935152, x-datadog-trace-id=6908933930403372124, __STARTDELIVERTIME=1699426187953, __BORNHOST=192.168.0.7:19232, INSTANCE_ID=MQ_INST_1106705442396860_BXXINmp6, __FQN_TOPIC=%RETRY%MQ_INST_1106705442396860_BXXINmp6%GID_SERVICE_OPEN_PLATFORM_SYNC_PROD_MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, MIN_OFFSET=0, x-datadog-parent-id=4425668439989415671, x-datadog-tags=_dd.p.dm=-1, POP_CK=3234 1699427935148 60000 0 1 hz-share20-01 0 3234, RETRY_TOPIC=MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, __MESSAGE_DECODED_TIME=1699427935150, MAX_OFFSET=359, KEYS=AIRRyCAwz0fY231108144947940, MSG_REGION=cn-hangzhou, UNIQ_KEY=0A04013B00071BF0F6F6273B26B21179, 1ST_POP_TIME=1699426188030, TAGS=receive}, body=18925]]] MQ: MessageQueue [topic=MQ_INST_1106705442396860_BXXINmp6%OPEN_PLATFORM_PROD, brokerName=rmq-gateway-share-02-cn-hangzhou-0, queueId=0]
消费端已经消费成功, 但Broker仍然重复投递.
根据以上分析, 造成Broker重复投递的可能性, 从两个角度分析
1.从消费端角度分析,包括以下3点:
1.1消费端消息被处理时间超过15分钟(consumeTimeout默认15分钟)
1.2消费端发生OOM
1.3消费端发生Error异常
1.4消费端重启容器
2.从Broker角度分析, 消息已经消费成功, 但仍然被重复投递.
1.消息重试
2.消息重试
3.客户端配置
4.订阅消息