平臺(tái)遷移到云平臺(tái)后，交易逐步恢復(fù)正常，在日常監(jiān)控業(yè)務(wù)情況時(shí)，發(fā)現(xiàn)一個(gè)業(yè)務(wù)突然出現(xiàn)大量異常，本文記錄排查過程。
1. 發(fā)現(xiàn)問題
下圖紅色部分，為大量報(bào)出異常的應(yīng)用，排查發(fā)現(xiàn)，錯(cuò)誤出現(xiàn)在處理交易通知的時(shí)候。在系統(tǒng)收到通知后，回繼續(xù)邏輯，然后將結(jié)果放入MQ中，由通知系統(tǒng)下發(fā)給商戶。問題就出在消息寫入MQ的結(jié)果上，代碼中判斷寫入狀態(tài)為 SendStatus.SEND_OK時(shí)，寫入成功，但是現(xiàn)在執(zhí)行了異常流程，更奇怪的是，后續(xù)業(yè)務(wù)并沒有受影響。
2. 分析與排查
現(xiàn)在知道了以下前提：
- MQ寫入狀態(tài)不是：SendStatus.SEND_OK
- 后續(xù)業(yè)務(wù)正常，說明消息實(shí)際是寫入成功了
2.1 RocketMq的投遞狀態(tài)
FLUSH_DISK_TIMEOUT
如果 Broker 設(shè)置MessageStoreConfig的FlushDiskType=SYNC_FLUSH(默認(rèn)是ASYNC_FLUSH)，并且代理沒有在MessageStoreConfig的syncFlushTimeout(默認(rèn)是5秒)時(shí)間內(nèi)完成刷盤，您將獲得這個(gè)狀態(tài)。FLUSH_SLAVE_TIMEOUT
如果 Broker 的角色是 SYNC_MASTER (默認(rèn)是ASYNC_MASTER)，并且 Slave Broker 沒有在MessageStoreConfig的syncFlushTimeout(默認(rèn)是5秒)時(shí)間內(nèi)完成同步，您將得到這個(gè)狀態(tài)。SLAVE_NOT_AVAILABLE
消息發(fā)送成功，但是此時(shí)Slave不可用。如果Broker服務(wù)器的角色是同步Master，即SYNC_MASTER（默認(rèn)是異步Master服務(wù)器即ASYNC_MASTER），但沒有配置slave Broker服務(wù)器，則將返回該狀態(tài)——無Slave服務(wù)器可用。SEND_OK
SEND_OK 并不意味著它是可靠的。為了確保沒有信息會(huì)丟失，應(yīng)啟用 SYNC_MASTER 或 SYNC_FLUSH
從以上可以猜測(cè)，系統(tǒng)當(dāng)前的投遞狀態(tài)應(yīng)該是“ SLAVE_NOT_AVAILABLE”，但是由于日志沒有打印投遞異常時(shí)的具體狀態(tài)值，所以要想驗(yàn)證具體的狀態(tài)，只能想其他辦法了。
2.2 arthas 查看方法變量的值
Arthas 是Alibaba開源的Java診斷工具，深受開發(fā)者喜愛。
當(dāng)你遇到以下類似問題而束手無策時(shí)，Arthas可以幫助你解決：
這個(gè)類從哪個(gè) jar 包加載的？為什么會(huì)報(bào)各種類相關(guān)的 Exception？
我改的代碼為什么沒有執(zhí)行到？難道是我沒 commit？分支搞錯(cuò)了？
遇到問題無法在線上 debug，難道只能通過加日志再重新發(fā)布嗎？
線上遇到某個(gè)用戶的數(shù)據(jù)處理有問題，但線上同樣無法 debug，線下無法重現(xiàn)！
是否有一個(gè)全局視角來查看系統(tǒng)的運(yùn)行狀況？
有什么辦法可以監(jiān)控到JVM的實(shí)時(shí)運(yùn)行狀態(tài)？
怎么快速定位應(yīng)用的熱點(diǎn)，生成火焰圖？
目前業(yè)務(wù)雖然報(bào)錯(cuò)，但是實(shí)際邏輯還是完整的，為了最小化影響，不能采取緊急的修復(fù)，所以決定使用arthas觀察一下相關(guān)方法的內(nèi)部變量值，看看投遞狀態(tài)到底是什么。
首先，找到報(bào)錯(cuò)的代碼處，添加一個(gè)日志打印出投遞狀態(tài)，然后將類編譯。
if (Objects.nonNull(sendResult) && sendResult.getSendStatus() == SendStatus.SEND_OK) {
result = true;
}
else {
// 新增異常日志
logger.error("error sendStatus:{}", (Object)sendResult.getSendStatus());
}
然后將編譯好的類，上傳到服務(wù)器，按照arthas的操作指南，定位到要調(diào)試的應(yīng)用。
$ $ java -jar arthas-boot.jar
* [1]: 35542
[2]: 71560 my-app.jar
my-app進(jìn)程是第2個(gè)，則輸入2，再輸入回車/enter。Arthas會(huì)attach到目標(biāo)進(jìn)程上，并輸出日志：
[INFO] Try to attach process 71560
[INFO] Attach process 71560 success.
[INFO] arthas-client connect 127.0.0.1 3658
,---. ,------. ,--------.,--. ,--. ,---. ,---.
/ O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'
wiki: https://arthas.aliyun.com/doc
version: 3.0.5.20181127201536
pid: 71560
time: 2018-11-28 19:16:24
$
redefine
加載外部的.class文件，redefine jvm已加載的類。
這里，我們用重新編譯好的添加了日志打印的類，替換jvm里的類。
在arthas終端界面，執(zhí)行命令：
redefine /tmp/YourClass.class
替換完成后，觀察應(yīng)用日志，發(fā)現(xiàn)投遞狀態(tài)確實(shí)為“ SLAVE_NOT_AVAILABLE”/
2.3 檢測(cè)RocketMq雙主集群
在控制臺(tái)可見，集群能夠正常的識(shí)別，但是消息記錄中，slave節(jié)點(diǎn)確實(shí)都為0，問題確實(shí)存在。
經(jīng)過運(yùn)維的再三排查，說集群配置沒有問題。再經(jīng)過數(shù)個(gè)小時(shí)的強(qiáng)迫性排查后，在晚上運(yùn)維給出了一個(gè)讓人啼笑皆非的原因：
????????????????????????????????????????????
??slave節(jié)點(diǎn)的10911端口沒有開放，導(dǎo)致無法與master實(shí)時(shí)同步??
????????????????????????????????????????????
年輕人，希望你“耗子尾汁”！
年輕人，希望你“耗子尾汁”??！
年輕人，希望你“耗子尾汁”?。。?/p>
3. 收獲
在排錯(cuò)過程中，不要完全相信任何人，特別是運(yùn)維。
要避免燈下黑的現(xiàn)象。
