生產(chǎn)環(huán)境MQ集群一個非常詭異的消費延遲排查
?1、問題現(xiàn)象
某一天,項目組一個同事向我反饋,他們使用公司的數(shù)據(jù)同步產(chǎn)品將MySQL數(shù)據(jù)同步到MQ集群,然后使用消費者將數(shù)據(jù)再同步到ES,反饋數(shù)據(jù)同步延遲嚴重,但對應的消費組確沒有積壓,但最近最近幾分鐘的數(shù)據(jù)都沒有同步過來。
那問題來了,消費端沒有消費積壓,而且通過查看數(shù)據(jù)同步平臺該通過任務的同步狀態(tài),同樣顯示沒有積壓,那是為什么呢?
遇到這個問題,我們應該冷靜下來,分析一下其大概的數(shù)據(jù)流向圖,梳理后如下圖所示:
通過初步的診斷,從數(shù)據(jù)同步產(chǎn)品查看Binlog同步無延遲、MQ消費無積壓,那為什么最終Es集群中的數(shù)據(jù)與MySQL有高達幾分鐘的延遲呢?
2、問題排查
根據(jù)上圖幾個關鍵組件數(shù)據(jù)同步延遲的檢測,基本就排除了數(shù)據(jù)同步組件、MQ消費端本身消費的問題,問題的癥結應該就是數(shù)據(jù)同步組件成功將數(shù)據(jù)寫入到MQ集群,并且MQ集群返回了寫入成功,但消費端并沒有及時感知這個消息,也就是說消息雖然寫入到MQ集群,但并沒有達到消費隊列。
因為如果數(shù)據(jù)同步組件如果沒有寫入成功,則MySQL Binlog日志就會出現(xiàn)延遲。但如果是MQ消費端的問題,則MQ平臺也會顯示消費組積壓。
那為什么消息服務器寫入成功,但消費組為什么感知不到呢?
首先為了驗證上述結論是否正確,我還特意去看了一下主題的詳細信息:
查看主題的統(tǒng)計信息時發(fā)現(xiàn)當前系統(tǒng)的時間為19:01分, 但主題最新的寫入時間才是18:50,兩者之間相差將近10分鐘。
備注:上述界面是我們公司內部的消息運營管理平臺,其實底層是調用了RocketMQ提供的topicStatus命令。
那這又是怎么造成的呢?
在這里我假設大家對RocketMQ底層的實現(xiàn)原理還不是特別熟悉,在這樣的情況下,我覺得我們應該首先摸清楚topicStatus這個命令返回的minOffset、maxOffset以及l(fā)astUpdate這些是的具體獲取邏輯,只有了解了這些,我們才能尋根究底,最終找到解決辦法。
2.1 問題探究與原理剖析
在這個場景中,我們可以通過對topicStatus命令進行解析,從而探究其背后的實現(xiàn)原理。
當我們在命令行中輸入 sh ./mqadmin topicStatus命令時,最終是調用defaultMQAdminExtImpl的examineTopicStats方法,最終在服務端的處理邏輯定義在AdminBrokerProcessor的getTopicStatsInfo方法中,核心代碼如下:
這里的實現(xiàn)要點:
- 通過MessageStore的getMinOffsetInQueue獲取最小偏移量。
- 通過MessageStore的getMaxOffsetInQueue獲取最大偏移量。
- 最新更新時間為最大偏移量減去一(表示最新一條消息)的存儲時間
故要弄清隊列最大、最小偏移量,關鍵是要看懂getMaxOffsetInQueue或者getMinOffsetInQueue的計算邏輯。
我也注意到分析源碼雖然能直抵真相,但閱讀起來太粗糙,所以我接下來的文章會盡量避免通篇的源碼解讀,取而代之的是只點出源碼的入口處,其旁支細節(jié)將通過時序圖獲流程圖,方便感興趣的讀者朋友去探究,我重點進行知識點的提煉,降低大家的學習成本。
如果大家想成體系的研究RocketMQ,想將消息中間件當成自己職業(yè)的閃光點,強烈建議購買我的兩本關于RocketMQ的數(shù)據(jù):《RocketMQ技術內幕》與《RocketMQ實戰(zhàn)》。
MessageStore的getMaxOffsetInQueue的時序圖如下所示:
從上述時序圖我們可以得知,調用DefaultMessageStore的getMaxOffsetInQueue方法,首先是根據(jù)主題、隊列ID獲取ConsumeQueue對象(在RocketMQ中一個主題的一個隊列會對應一個ConsumeQueue,代表一個消費隊列),也就是這里獲取的偏移量指的是消費者隊列中的偏移量,而不是Commitlog文件的偏移量。
如果是找最大偏移量,就從該隊列中的找到最后一個文件,去獲取器最大的有效偏移量,也就是等于文件的起始偏移量(fileFromOffset)加上該文件當前最大可讀的偏移量(readPosition),故引起這張時序圖一個非常關鍵的點,就是如何獲取消費隊列最大的可讀偏移量,代碼見MappedFile的getReadPosition:
由于ConsumeQueue并沒有 transientStorePoolEnable 機制,數(shù)據(jù)直接寫入到FlieChannel中,故這里的writeBuffer為空,取的是 wrotePosition的值,那ConsumeQueue文件的wrotePosition值在什么地方更新呢?
這個可以通過查看MappedFile中修改wrotePosition的方法appendMessage方法的調用,如下圖所示:
與ConsumeQueue對應的入口主要有兩個:
- ReputMessageService#doReput Commitlog異步轉發(fā)線程,通過該線程異步構建Consumequeue、Index等文件
- Commitlog#recoverAbnormally RocketMQ啟動時根據(jù)Commitlog文件自動恢復Consumequeue文件
今天的主角當然不讓非ReputMessageService莫屬,這里先和大家普及一下一個最基本的知識:RocketMQ為了追求極致的順序寫,會將所有主題的消息順序寫入到一個文件(Commitlog文件),然后異步轉發(fā)到ConsumeQueue(消費隊列文件)、IndexFile(索引文件)。
其轉發(fā)服務就是通過ReputMessageService來實現(xiàn)的。
在深入介紹Commitlog文件的轉發(fā)機制之前,我在這里先問大家一個問題:消息是寫入到內存就轉發(fā)給ConsumeQueue,亦或是刷寫到磁盤后再轉發(fā)呢?
為了方便大家對這個問題的探究,其代碼的核心入口如下圖所示:
這里的關鍵實現(xiàn)要點如下:
- 判斷是否轉發(fā)關鍵條件在于 isCommitlogAvailable()方法返回true
- 根據(jù)轉發(fā)位點reputFromOffset,從Commitlog文件中獲取消息的物理偏移量、消息大小,tags等信息轉發(fā)到消息消費隊列、索引文件。
那isCommitlogAvailable的核心如下所示:
故轉發(fā)的關鍵就在于Commitlog的maxOffset的獲取邏輯了,其實現(xiàn)時序圖如下所示:
這里核心重點是getReadPosition方法的實現(xiàn),在RocketMQ寫Commitlog文件,為了提升寫入性能,引入了內存級讀寫分離機制,具體的實現(xiàn)原理如下圖所示:
具體在實現(xiàn)層面,就是如果transientStorePoolEnable=true,數(shù)據(jù)寫入到堆外內存(writeBuffer)中,然后再提交到FileChannel,提交的位置(commitedPosition來表示)。
大家可以分別看一下改變wrotePosition與committedPposition的調用鏈。
其中wrotePosition的調用鏈如下所示:
可以得知:wrotePosition是消息寫入到內存(pagecache或者堆外內存)都會更新,但一旦開啟了堆外內存機制,并不會取該值,所以我們可以理解為當消息寫入到Pagecache中時,就可以被轉發(fā)到消息消費隊列。
緊接著我們再看一下committedPosition的調用鏈,如下所示:
原來在RocketMQ中,如果開啟了transientStorePoolEnable機制,消息先寫入到堆外內存,然后就會向消息發(fā)送者返回發(fā)送成功,然后會有一個異步線程(CommitRealTimeService)定時將消息(默認200ms一次循環(huán))提交到FileChannel,即更新committedPosition的值,消息就會轉發(fā)給消費隊列,從而消費者就可以進行消費。
2.2 問題原因提煉
經(jīng)過上面的解析,問題應該有所眉目了。
由于我們公司為了提高RocketMQ的資源利用率,提升RocketMQ的寫入性能,我們開啟了transientStorePoolEnable機制,消息發(fā)送端寫入到堆外內存,就會返回寫入成功,這樣MySQL Binlog數(shù)據(jù)同步并不會產(chǎn)生延遲,那這里的問題,無非就2個:
- CommitRealTimeService 線程并沒有及時將堆外內存中的數(shù)據(jù)提交到FileChannel
- ReputMessageService線程沒有及時將數(shù)據(jù)轉發(fā)到消費隊列
由于目前我暫時對底層存儲寫入的原理還認識不夠深入,對相關系統(tǒng)采集指標不夠敏感,當時主要分析了一下線程棧,發(fā)現(xiàn)ReputMessageService線程一直在工作,推測可能是轉發(fā)不及時,這塊我還需要更加深入去研究,如果大家對這塊有其實理解,歡迎留言,我也會在后續(xù)工作中提升這塊的技能,更加深入去理解底層的原理。
也就是目前知道了問題的表象原因,雖然底層原理還未通透,但目前足以指導我們更好的處理問題:將集群內消息寫入大的主題,遷移到其他負載較低的集群,從而降低該集群的寫入壓力,當遷移了幾個主題后,果不其然,消息到達消費隊列接近實時,集群得以恢復。