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

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

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

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

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

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

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

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

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

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

原來，如果客戶端消費失敗后向Broker發(fā)生ACK失敗后，會加入到msgBack失敗隊列中，并重新提交到消費者這邊消費，并且這條消息的位點不會提交，因為有關(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ā)消息積壓。但尷尬的是這個主題平時消息量很少，并沒有通過積壓來發(fā)現(xiàn)該問題。

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

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