前天發(fā)完版本好不容易休息一下，又遇到一個(gè)問(wèn)題，項(xiàng)目組反饋說(shuō)RocketMQ的一個(gè)消費(fèi)組一條消息，消費(fèi)了兩次，但兩者之間的間隔超過(guò)了10個(gè)小時(shí)，現(xiàn)象如下圖所示：

這是為什么呢?兩者之間相差了差不多10個(gè)多小時(shí)，是不是這條消息重復(fù)消費(fèi)了16次，但從日志中并沒(méi)有打印出16次消息題，只打印了兩條消息，從日志角度來(lái)看應(yīng)該不是重復(fù)消費(fèi)了16次。

本著不輕易相信日志的原則，我覺(jué)得應(yīng)該去RocketMQ服務(wù)器上看看這條消息存儲(chǔ)的重試次數(shù)，從而推斷出消息是否消費(fèi)失敗而進(jìn)行消費(fèi)重試，正好項(xiàng)目組也提供了消息的Key，根據(jù)消息key、發(fā)送主題名稱(chēng)去查找消息，只能查詢(xún)到一條消息：

說(shuō)明發(fā)送端確實(shí)只發(fā)送了一條消息。

那個(gè)時(shí)候服務(wù)集群并沒(méi)有發(fā)現(xiàn)什么異常，消費(fèi)者沒(méi)有重啟、隊(duì)列也沒(méi)發(fā)生重平衡，不符合RocketMQ會(huì)重復(fù)推送消息給客戶(hù)端的場(chǎng)景，那基本就可以斷定是消息消費(fèi)失敗重啟引起的，但RocketMQ消息消費(fèi)重試重試延遲是采取間隔的，往往第一次重試只需10秒就會(huì)發(fā)生重試，不應(yīng)該是10個(gè)小時(shí)?

為此，我特意根據(jù)Key分別查找了主題SCHEDULE_TOPIC_XXXX與%RETRY%重試主題，發(fā)現(xiàn)這個(gè)key也只有一條消息，說(shuō)明這還僅僅是第一次重試，如下圖：

但從這里可以看到消息寫(xiě)入到SCHEDULE_TOPIC_XXXX的時(shí)間為2022-05-27 22:26:20，然后過(guò)了10s就通過(guò)調(diào)度機(jī)制進(jìn)入到重試主題，并開(kāi)始被消費(fèi)，故進(jìn)行了第一次重試。

擴(kuò)展機(jī)制知識(shí)：RocketMQ并發(fā)消費(fèi)的消費(fèi)者，在客戶(hù)端消費(fèi)失敗后會(huì)向服務(wù)端發(fā)送ACK，根據(jù)重試次數(shù)進(jìn)入到SCHEDULE_TOPIC_XXXX主題不同的隊(duì)列中，每一個(gè)隊(duì)列代表的延遲時(shí)間不一樣，經(jīng)過(guò)一定延遲時(shí)間后再次調(diào)度到消費(fèi)組的重試主題，被消費(fèi)者再次消費(fèi)，實(shí)現(xiàn)時(shí)間間隔的重試，提高重試成功率。

那為什么第一次消費(fèi)是12點(diǎn)51分，為什么這么久才進(jìn)入到Broker的SCHEDULE_TOPIC_XXXX呢?

這個(gè)就是問(wèn)題的關(guān)鍵所在，這個(gè)細(xì)節(jié)我平時(shí)也沒(méi)關(guān)注，故接下來(lái)得分析這段代碼，代碼具體定義在ConsumeMessageConcurrentlyService的processConsumeResult方法中。

原來(lái)，如果客戶(hù)端消費(fèi)失敗后向Broker發(fā)生ACK失敗后，會(huì)加入到msgBack失敗隊(duì)列中，并重新提交到消費(fèi)者這邊消費(fèi)，并且這條消息的位點(diǎn)不會(huì)提交，因?yàn)橛嘘P(guān)鍵代碼：

consumeRequest.getMsgs().removeAll(msgBackFailed);

long offset = consumeRequest.getProcessQueue().removeMessage(consumeRequest.getMsgs());
if (offset >= 0 && !consumeRequest.getProcessQueue().isDropped()) {
   this.defaultMQPushConsumerImpl.getOffsetStore().updateOffset(consumeRequest.getMessageQueue(), offset, true);
}

RocketMQ消費(fèi)位點(diǎn)采取最小位點(diǎn)提交，只要消息存在于本地處理隊(duì)列，位點(diǎn)就不會(huì)提交，從而會(huì)觸發(fā)消息積壓。但尷尬的是這個(gè)主題平時(shí)消息量很少，并沒(méi)有通過(guò)積壓來(lái)發(fā)現(xiàn)該問(wèn)題。

根據(jù)現(xiàn)象與代碼結(jié)合，原因是客戶(hù)端一直消費(fèi)失敗，但向Broker提交ACK一直失敗，直到晚上22:26分才發(fā)送成功，從而才觸發(fā)重新消費(fèi)。

那現(xiàn)在的關(guān)鍵是為什么會(huì)發(fā)生ACK會(huì)失敗呢?這次比較遺憾，因?yàn)轫?xiàng)目組使用的是容器，這塊代碼并沒(méi)有采集到日志集群，導(dǎo)致無(wú)法查看錯(cuò)誤日志，而且所在的集群是正常的，這個(gè)疑問(wèn)后續(xù)等我分析完畢后，再和大家來(lái)分享。