一次 RocketMQ 程式自動退出排查經驗分享（實戰篇）

1、背景

公司一個 RocketMQ 叢集由4主4從組成，突然其中3臺伺服器“竟然”在同一時間下線，其監控顯示如下：

依次檢視三臺機器的監控圖形，時間戳幾乎完美“吻合”，不可思議吧。

2、故障分析

出現問題，先二話不說，馬上重啟各伺服器，儘快恢復叢集，降低對業務的影響，接下來開始對日誌進行分析。

Java 程式自動退出(rocketmq 本身就是一個java程式)，一種最常見的問題是由於記憶體溢位或由於記憶體洩漏導致程式傳送Crash等。由於我們的啟動引數中未配置-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/opt/jvmdump 這兩個引數，不能直接根據 是否生成 dump 檔案，那退而求其次去檢視其GC日誌，將GC日誌下載到本地，然後可以使用一個線上gc日誌分析工具：gceasy.io/ ，將 gc 日誌上傳後會給出圖形化的展示，其圖如下：

發現垃圾回收很正常。

既然 Java 程式不是由於記憶體溢位等問題導致的退出，那又會是什麼原因呢？那我們來看一下那個點的broker的日誌，其關鍵日誌截圖如下：

發現 broker 日誌中有列印出 shutdownHook，表示在程式退出之前執行了啟動時註冊時的退出鉤子函式，說明 broker 是正常停止的，並且也不可能是 kill -9 命令，肯定是顯示的執行了 shutodown 或 kill 命令，於是立馬使用 history 命令 檢視歷史命令，都未在指定時間執行過該命令，並且切換到 root 命令後，同樣使用 history 命令，並未發現端倪。

但我始終相信，肯定是執行了手動執行了 kill 命令導致程式退出的，經過網上查詢查，得知可以通過查閱系統日誌/var/log/messages 來檢視系統命令的呼叫，於是乎把日誌檔案下載到本地，開始搜尋 kill 關鍵字，發現如下日誌：

發現最近一次 kill 命令是在25號的凌晨1點多，停止 rocketmq 叢集，並使用 bin/mqbroker -c conf/broker-b.conf & 進行了重新啟動。

這個命令是有問題的，沒有使用 nohup ，如果會話失效，該程式就會被退出，為了驗證，我們再查一下程式退出時的日誌：

發現在故障發生點確實有 Removed 相關的日誌。

故障原因基本分析到位了，運維在啟動的時候沒有使用 nohup 來啟動，故馬上排查剛啟動的叢集的方式，重新重啟剛啟動的 Broker。

RocketMQ優雅重啟小建議：

1. 首先將 broker 的寫許可權關閉，命令如下：

   bin/mqadmin updateBrokerConfig -b 192.168.x.x:10911 -n 192.168.x.x:9876 -k brokerPermission -v 4
   複製程式碼

2. 通過 rocketmq-console 檢視該broker的寫入TPS，當寫入TPS降為0後，再使用 kill pid 關閉 rocketmq 程式。溫馨提示：將broker的寫許可權關閉後，非順序訊息不會立馬拒絕，而是需要等客戶端路由資訊更新後，不會在往該broker上傳送訊息，故這個過程需要等待。

3. 啟動 rocketmq

   nohup bin/mqbroker -c conf/broker-a.conf  /dev/null  2>&1 &
   複製程式碼

   注意：nohup。

4. 恢復該節點的寫許可權

   bin/mqadmin updateBrokerConfig -b 192.168.x.x:10911 -n 192.168.x.x:9876 -k brokerPermission -v 6
   複製程式碼

本文的故障分析與處理就介紹到這裡，本文重點講解了故障的分析過程以及 RocketMQ Broker 優雅停機的方案。

如果本文對您有所幫助的話，麻煩幫忙點個贊，謝謝。

---

作者介紹：《RocketMQ技術內幕》作者，維護公眾號：中介軟體興趣圈，目前主要發表了原始碼閱讀java集合、JUC(java併發包)、Netty、ElasticJob、Mycat、Dubbo、RocketMQ、mybaits等系列原始碼。