現(xiàn)象
前天11點左右有幾個業(yè)務(wù)方找過來說生產(chǎn)環(huán)境RocketMQ一直報FLUSH_SLAVE_TIMEOUT異常，查看源碼只知道是主從同步超時，但未找到邏輯上導(dǎo)致這個異常的原因
定位問題
跟運維溝通，了解到在這個時間點開啟了一個topic的一個group的消費，經(jīng)比對跟出現(xiàn)異常的時間匹配上，找對應(yīng)的業(yè)務(wù)方，業(yè)務(wù)方認為這個topic還有其余group在消費，別的group消費沒問題，那這個應(yīng)該也沒啥問題，這聽起來確實也沒法反駁，后面觀察該group單臺消費能力在5000tps的樣子，線上一共有4臺機器，也就是會有20000的tps（剛開啟時有一百多萬的數(shù)據(jù)堆積）
由于這個業(yè)務(wù)恰好那次上線半個小時出了點問題，后面下線了，而這個業(yè)務(wù)業(yè)務(wù)下次上線時間定在3天后，因此準備在壓測環(huán)境測試看能否復(fù)現(xiàn)這個問題，在壓測環(huán)境堆積了200w數(shù)據(jù)后，生產(chǎn)者一直造數(shù)據(jù)，查看broker日志沒有出現(xiàn)FLUSH_SLAVE_TIMEOUT的異常，開啟該業(yè)務(wù)group的消費之后，store.log中一直報FLUSH_SLAVE_TIMEOUT，因此基本可以斷定為是該消費者導(dǎo)致
后面在mq store模塊中加了一些日志，打包到壓測環(huán)境環(huán)境，發(fā)現(xiàn)有大量的延遲消息保存到commitLog，每次壓測之前都是清空了存儲目錄了的，正常來說是不會有延遲消息的，后發(fā)現(xiàn)延遲消息都是該業(yè)務(wù)消費者的延遲消息，也就是說這個業(yè)務(wù)消費消息一直失敗，然后一直sendback到broker，也就是以20000tps的速率發(fā)送消息到broker，但就算producer端發(fā)送壓力大，據(jù)以前的經(jīng)驗，也應(yīng)該是BROKER_BUSY，沒辦法，只能去看主從同步的源碼
主從同步流程如下：
正常來說groupTransferService喚醒都是代表當前請求已經(jīng)同步到slave了，失敗也應(yīng)該是超時（超過5s），但日志顯示是沒超過5s直接返回的失敗，也就是圖中的步驟4進行了5次無效喚醒
handleHA方法中封裝GroupCommitRequest到groupTransferService，后面發(fā)現(xiàn)連著的兩個request的寫入位置差別很大，大于實際消息體的長度，再次加上一些log打包之后發(fā)現(xiàn)，這兩個消息中間有很多的延遲消息被put到了commitLog，延遲消息在put之前調(diào)用的msgInner.setWaitStoreMsgOK(false)，而handleHA中判斷該值為true才會封裝GroupCommitRequest到groupTransferService,也就是說第一條正常同步的消息跟第二條同步異常的消息中間由于插入了大量的延遲消息，而每次主從同步默認最大只同步32k數(shù)據(jù)，每同步一次數(shù)據(jù)slave上報一次offset，只要這中間延遲的消息多就一定會導(dǎo)致slave上報超過5次導(dǎo)致的無效喚醒
備注：mq主從配置為SYNC_MASTER,ASYNC_FLUSH
