News
您的位置：
今年筆者支撐的某項目一個部署HBASE的大規模集群中發生了連續的宕機事件，對業務造成嚴重影響。每次宕機后，啟動消耗時間都很長，導致業務出現中斷。其最關鍵的問題是，連續宕機且原因不明，所以大概率存在再次宕機的風險，在根因沒有定位出來的情況下，這個故障就是達摩克利斯之劍依然懸在半空，誰也不知道什么時候會落下來。下面的篇幅就依此故障排查分析過程為主線展開。一、故障線索，機會出現該HBASE集群發生的嚴重宕機事件，具體表現為管理節點HMaster異常退出，并且超過一半的RegionServer也出現宕機退出，導致業務生產中斷。運維人員根據常規步驟進行啟動集群操作，之后進行故障分析定位，由于日志級別設置為DEBUG級別，日志刷新速度較快，重啟后沒有及時進行備份轉存，故障的時間點的日志沒有辦法獲取，這給查找故障原因造成了很大的麻煩。就在大家面對缺少關鍵日志，不知道該如何進行故障分析復盤的時候，在不到24小時的時間里面，集群出現了又一次宕機！現象是和第一次是一樣的，也是HMaster異常退出，期間也有大量的RegionServer出現宕機。雖然說連續的故障帶來客戶的嚴重不滿，但是也給了我們揭開故障根因面紗的大好機會。二、問題排查，迷霧重重有了前期的教訓，這一次次故障產生后，立即在第一時間將HBASE的相關日志都轉儲保存好，然后就馬上著手進行分析和定位。這次故障表象實在有些特殊，HBASE的日志反應的是Zookeeper連接異常：?這個時候所有的思路焦點都聚集到Zookeeper的這個異常點上面，為什么會出現Session expired呢？Zookeeper是不是出現了什么異常的情況?之前集群也出現過HBASE的故障，因為Zookeeper連接超時導致，當時進行過以下舉措解決:
1.Hbase連接Zookeeper的會話超時調大(120S)。重啟ZK與Hbase；ipa 升級完成后再操作；
2.ZK連接數監控，當前最大連接數600，超過80%告警；臨時調整最大連接數—已經調整；
3. JVM 參數優化。
所以比較肯定，故障應該還是出在Zookeeper上，所以第一時間分析ZK的日志。但是ZK在整個故障過程中，始終沒有出現異常及宕機行為，這個就給問題定位帶來很大的不確定性了，因為Zookeeper正常，即使是HBASE的日志顯示連接ZK異常，但這個時候依然沒有辦法定位到具體的原因是由哪個參數哪個配置導致的，也就是說真正有說服力的原因是沒有定位到，這樣肯定是沒有辦法結案，而且系統隨時可能再次宕機，危機仍在。只能再次分析Zookeeper的日志，查找可能出現異常的原因。通過ZK的日志，發現到一個情況，某幾臺主機連接數特別多，一天下來都有上百萬次連接了，這個根據經驗來看是不正常的，是不是因為訪問量過大導致異常呢？迅速地，進行了對ZK的各項指標進行全面的監控，查找可能的連接異常。排查異常連接數據的主機是哪些程序發出的在所內模擬對ZK進行高負載的連接，測試穩定性然而結果并不順利，主機沒有部署特別的程序，僅是HADOOP集群的計算節點，內測也進行過百萬次級別的高負載連接壓測，ZK沒有出現異常。三、拔云見日，真相大白在經過一天的艱苦研究后，終于看到了曙光！通過分析日志，發現連接Zookeeper的sessionid是有異常的。HMaster和Zookeeper是通過session維持連接的，這里日志顯示了sessionId 是：0xff8201f4b7b63a73檢測所有的ZK服務器的日志，又發現了一段信息：這個sessionid，不是HMaster的主機，是10.26.9.35 發出的，也就是說sessionid出現了沖突的情況。而由于sessionid出現了沖突，并且修改了原session的元數據信息，導致Master連接ZK的長連接出現了過期異常，無法正常續約，HMaster退出。那接下來的事情就明了：查明白為什么ZK的sessionid會出現沖突首先檢測ZK產生sessionid的源代碼：這里肯定看到是通過時間和ZK的實例ID作為基準進行生成的，現在的問題就是同樣的ID會參數相同的開始ID段。通過對這段代碼進行測試，就發現了問題，無論送的是什么id過來，結果都是一樣的，這樣不同的ZK實例，必定會產生相同的sessionid，也就是說是一個BUG來了！仔細分析了這段代碼，發現的是帶符號右移，導致溢出了，然后馬上檢查了后續的版本，發現并進行了修復：代碼確實很少，就是 >>8 變成了 >>>8符號移位日常使用比較少，確實容易出錯：Java提供了兩種右移運算符：“>>” 和">>>"。其中，“>>”被稱為有符號右移運算符，“>>>”被稱為無符號右移運算符，它們的功能是將參與運算的對象對應的二進制數右移指定的位數。二者的不同點在于“>>”在執行右移操作時，若參與運算的數字為正數，則在高位補0；若為負數，則在高位補1。而“>>>”則不同，無論參與運算的數字為正數或為負數，在執運算時，都會在高位補0。上述的問題在于，左移24位，再右移8位后，當前時間出現了溢出，導致變成負數，真相大白。ZK的更新補丁說明：ZOOKEEPER-1622 session ids will be negative in the year 2022確實到了2022年后，由于sessionid出現負數，導致所有的ZK實例都會產生相同的sessionid初始值，所以才出現沖突。四、故障解決由于是ZOOKEEPER的BUG導致，所以后續還是必然還是會有可能再次出現異常，所以根本原因必須要對ZK打補丁，才能徹底解決。在沒有進行充分驗證的情況下，只能通過避免程序到ZK的頻繁連接，要求對應用程序進行整改，才能降低BUG被觸發的風險，并且再更新之前每天進行系統及業務巡檢。經過一個業務周期運行觀察，系統穩定運行。五、經驗總結這次的故障定位是一波三折，付出了很大的努力才最終完成問題的定位。由于是組件的BUG引起，并且在2022年才會觸發，這個在之前多年的運維HADOOP集群還是第一回出現。故障分析處理過程中分析日志包括 ：HBASE的MASTER，REGIONSERVER實例日志，ZOOKEEPER的5臺主機實例日志，YARN調度程序運行記錄日志。通過這次故障分析可以看出，往往造成原因多方面的，也體現了大數據生態體系復雜性，不同組件的兼容和協同能力是至關重要的，需要研發和運維團隊有較強的生態和源代碼把控能力，而不是簡單的把開源組件堆起即可使用。幾點寄語：01故障發生后，現場需要第一時間保留所有的日志02需要從故障發生點的異常日志里面，查找有價值的信息03需要通過整合所有的日志文件，進行綜合分析，大數據集群相對復雜，所有的需要綜合分析所有的組件信息，才能在復雜的環境中定位出真正的問題
排查異常連接數據的主機是哪些程序發出的
在所內模擬對ZK進行高負載的連接，測試穩定性
浩鯨云計算科技股份有限公司 版權所有 2003-2023
蘇ICP備10224443號-6 蘇公網安備 32011402011374號