生產(chǎn)故障｜Kafka消息發(fā)送延遲達到幾十秒的罪魁禍?zhǔn)拙谷皇?..

作者： 丁威 2022-01-04 08:33:33

開發(fā)

架構(gòu)

Kafka 通過對日志分析發(fā)現(xiàn)存在大面積分區(qū)Leader選舉，__consumer_offsets主題的分區(qū)也大量進行分區(qū)Leader選舉，從而導(dǎo)致消息發(fā)送幾乎停止，大量消費組觸發(fā)重平衡，整個集群接近癱瘓，最終確定了根因：Broker節(jié)點與Zookeeper會話超時，觸發(fā)大量分區(qū)重新選舉。

羅平網(wǎng)站制作公司哪家好，找成都創(chuàng)新互聯(lián)！從網(wǎng)頁設(shè)計、網(wǎng)站建設(shè)、微信開發(fā)、APP開發(fā)、成都響應(yīng)式網(wǎng)站建設(shè)公司等網(wǎng)站項目制作，到程序開發(fā)，運營維護。成都創(chuàng)新互聯(lián)從2013年創(chuàng)立到現(xiàn)在10年的時間，我們擁有了豐富的建站經(jīng)驗和運維經(jīng)驗，來保證我們的工作的順利進行。專注于網(wǎng)站建設(shè)就選成都創(chuàng)新互聯(lián)。

以前我在知其然而知其所以然，為什么Kafka在2.8版本中會“拋棄”Zookeeper一文中闡述了為什么官方要廢棄Zookeeper，當(dāng)時我記得有讀者反駁說zookeeper非常穩(wěn)定，基本不會出現(xiàn)什么問題，筆者在雙十一期間遇到的問題，就證明了Zookeeper的“脆弱性”，而zookeeper的脆弱性將對Kafka集群造成嚴(yán)重的影響。

1、故障現(xiàn)象

筆者在雙十一期間負(fù)責(zé)的kafka集群的響應(yīng)時間飆升到了10～30s，嚴(yán)重影響消息的寫入。

通過對日志分析發(fā)現(xiàn)存在大面積分區(qū)Leader選舉，__consumer_offsets主題的分區(qū)也大量進行分區(qū)Leader選舉，從而導(dǎo)致消息發(fā)送幾乎停止，大量消費組觸發(fā)重平衡，整個集群接近癱瘓，最終確定了根因：Broker節(jié)點與Zookeeper會話超時，觸發(fā)大量分區(qū)重新選舉。

本文借此故障，與大家一起剖析一下Zookeeper在Kafka中起了哪些作用，以及確定“罪魁禍?zhǔn)住钡倪^程，希望給大家排查問題能帶來一定的啟發(fā)。

2、Zookeeper在Kafka中具有舉足輕重的作用

在正式進入故障分析之前，我們首先介紹一下Zookeeper在kafka架構(gòu)設(shè)計中所起的角色。

核心理念：kafka的設(shè)計者對待Zookeeper的使用是非常謹(jǐn)慎的，即需要依靠Zookeeper進行控制器選舉，Broker節(jié)點故障實時發(fā)現(xiàn)，但又盡量降低對Zookeeper的依賴。

基于Zookeeper進行的程序開發(fā)，我們一般可以通過查看zookeeper中的目錄布局，可以窺探出哪些功能是依靠Zookeeper完成，Kafka在Zookeeper中的存儲目錄結(jié)構(gòu)如下圖所示：

上述各個節(jié)點，其背后都關(guān)聯(lián)著Kafka一個核心工作機制，大家可以順藤摸瓜進行探究，本文需要重點介紹/brokers這個目錄的布局與作用，目錄詳情如下：

• /controller Kafka控制器的信息，Kafka控制器的選舉依靠zookeeper。
• /brokers/ids/{id} 在持久節(jié)點/brokers/ids下創(chuàng)建眾多的臨時節(jié)點，每一個節(jié)點，表示一個Broker節(jié)點，節(jié)點的內(nèi)容存儲了Broker的基本信息，例如端口、版本、監(jiān)聽地址等。
• /brokers/topics/{topic}/partitions/{partition}/state

在kafka2.8版本一下，Kafka中topic中的路由信息最終持久化在zookeeper中，每一個broker節(jié)點啟動后會在內(nèi)存中緩存一份數(shù)據(jù)。/brokers節(jié)點每一個子節(jié)點表示一個具體的主題，主題的元數(shù)據(jù)主要包括分區(qū)的個數(shù)與每一個分區(qū)的狀態(tài)信息。每一個分區(qū)的狀態(tài)信息主要包括：

• controller_epoch 當(dāng)前集群控制器的epoch，表示controller選舉的次數(shù)，我們可以理解為controller的“版本號”。
• leader 當(dāng)前分區(qū)Leader所在的broker id。
• Leader_epoch 分區(qū)的leader_epoch，表示分區(qū)Leader選舉的次數(shù)，從0開始，每發(fā)生一次分區(qū)leader選舉該值就會加一，kafka通過引入leader epoch機制解決低版本依靠依賴水位線表示副本進度可能造成的數(shù)據(jù)丟失與數(shù)據(jù)不一致問題，這個將在后續(xù)文章中深入剖析。
• isr 分區(qū)的isr集合。
• version 存儲狀態(tài)分區(qū)狀態(tài)數(shù)據(jù)結(jié)構(gòu)的版本號，這個字段大家可以忽略

在Zookeeper中有一種同樣的“設(shè)計模式”，就是可以通過在zookeeper中創(chuàng)建臨時節(jié)點+事件監(jiān)聽機制，從而實現(xiàn)數(shù)據(jù)的實時動態(tài)感知，以/brokers/ids為例進行闡述：

• Kafka broker進程啟動時會向zookeeper創(chuàng)建一個臨時節(jié)點/brokers/ids/{id}，其中id為broker的編號
• Kafka Broker進程停止后，創(chuàng)建的臨時節(jié)點在broker與zookeeper的會話超時后會被自動刪除，產(chǎn)生節(jié)點刪除事件
• Kafka controller 會自動監(jiān)聽/brokers/ids 目錄的節(jié)點新增與刪除事件，一旦broker下線、上線，controller都會實時感知，從而采取必要處理。

經(jīng)過上面的初步介紹，Kafka對zookeeper的依賴還是非常大的，特別是Kafka控制器的選舉、broker節(jié)點的存活狀態(tài)等都依賴zookeeper。

Kafka 控制器可以看出是整個kafka集群的“大腦”，如果它出現(xiàn)異動，其影響范圍之廣，影響程度之大可想而知，接下來的故障分析會給出更直觀的展現(xiàn)。

溫馨提示：本文主要是一個故障分析過程，后續(xù)關(guān)于kafka控制器如何選舉、leader_epoch副本同步機制等會在《Kafka原理與實戰(zhàn)》專欄中一一介紹，敬請關(guān)注。

3、問題分析

一看到消息發(fā)送響應(yīng)時間長，我的第一反應(yīng)是查看線程棧，是不是有鎖阻塞，但查看線程堆棧發(fā)現(xiàn)Kafka用于處理請求的線程池大部分都阻塞在獲取任務(wù)處，表明“無活可干”狀態(tài)：

說明客戶端端消息發(fā)送請求都沒有到達Kafka的排隊隊列，并且專門用于處理網(wǎng)絡(luò)讀寫的線程池也很空閑，那又是為什么呢?

消息發(fā)送端延遲超級高，但服務(wù)端線程又極度空閑，有點詭異?

繼續(xù)查看服務(wù)端日志，發(fā)現(xiàn)了大量主題(甚至連系統(tǒng)主題__consumer_offsets主題也發(fā)生了Leader選舉)，日志如下：

核心日志：start at Leader Epoch 大量分區(qū)在進行Leader選舉。

Kafka中中只有Leader分區(qū)能處理讀、寫請求,follower分區(qū)只是從leader分區(qū)復(fù)制數(shù)據(jù)，在Leader節(jié)點宕機后參與leader選舉，故分區(qū)在進行Leader選舉時無法處理客戶端的寫入請求，而發(fā)送端又有重試機制，故消息發(fā)送延遲很大。

那到底在什么情況下會觸發(fā)大量主題進行重新選舉呢?

我們找到當(dāng)前集群的Controler節(jié)點，查看state-change.log中，發(fā)現(xiàn)如下日志：

出現(xiàn)了大量分區(qū)的狀態(tài)從OnlinePartition變更為OfflinePartition。

溫馨提示：根據(jù)日志我們可以去查看源碼，找到輸出這些方法的調(diào)用鏈，就可以順藤摸瓜去找針對性的日志。

繼續(xù)查看Controler節(jié)點下的controller.log中發(fā)現(xiàn)關(guān)鍵日志：

核心日志解讀：

• [Controller id=1] Broker failure callback for 8 (kafka.controller.KafkaController) 控制器將節(jié)點8從集群的在線中移除，控制器為什么會將節(jié)點8移除呢?

接下來順藤摸瓜，去看一下節(jié)點8上的日志如下圖所示：

核心日志解讀：原來broker與zookeeper的會話超時，導(dǎo)致臨時節(jié)點被移除。

先不探究會話為什么會超時，我們先來看一下會話超時，會給Kafka集群帶來什么嚴(yán)重影響。

/brokers/ids下任意一個節(jié)點被刪除，Kafka控制器都能及時得到，并執(zhí)行對應(yīng)的處理。

這里需要分兩種情況考慮。

3.1 普通Broker節(jié)點被移除

處理入口為：KafkaController的onBrokerFailure方法，代碼詳情如下圖所示：

一個普通的broker在zk中被移除，Kafka控制器會將該節(jié)點上分配的所有分區(qū)的狀態(tài)從OnlinePartition變更為OfflinePartition，從而觸發(fā)分區(qū)的重新選舉。

擴展知識點：__consumer_offsets分區(qū)如果進行Leader重新選舉，大面積的消費組會觸發(fā)重平衡，背后的機制：

消費組需要在Broker端進行組協(xié)調(diào)器選舉，選舉算法如下：消費組的名稱的hashcode與主題 __ consumer_offsets的隊列總數(shù)取模，取余數(shù)，映射成 __consumer_offsets 分區(qū)，該分區(qū)的leader在哪個broker節(jié)點，該節(jié)點則會充當(dāng)消費組的組協(xié)調(diào)器。

一旦該分區(qū)的Leader發(fā)生變化，對應(yīng)的消費組必須重新選舉新的組協(xié)調(diào)器，從而觸發(fā)消費組的重平衡。

3.2 Controller節(jié)點被移除

如果zookeeper中移除的broker id 為 Kafka controller，其影響會更大，主要的入口如下圖所示：

如果是controller節(jié)點會話超時,臨時節(jié)點/controller節(jié)點會被刪除，從而會觸發(fā)Kafka controller選舉，最終所有的broker節(jié)點都會收到節(jié)點/controller的刪除、新增或節(jié)點數(shù)據(jù)變化的通知，KafkaController的onControllerFailover方法會被執(zhí)行，與會將于zookeeper相關(guān)的事件監(jiān)聽器重新注冊、分區(qū)狀態(tài)機、副本狀態(tài)機都會停止并重新啟動，各個分區(qū)會觸發(fā)自動leader分區(qū)選舉。

可以這樣形容：一朝天子一朝臣，全部重新來過。

3.3 zookeeper會話超時根因排查

查看服務(wù)端日志，可以看到如下日志：

核心日志解讀：Closed socket connection for client ... 表示連接被客戶端主動關(guān)閉。

那為什么客戶端會主動關(guān)閉心跳呢?心跳處理的套路就是客戶端需要定時向服務(wù)端發(fā)送心跳包，服務(wù)端在指定時間內(nèi)沒有收到或處理心跳包，則會超時。

要想一探究竟，唯一的辦法：閱讀源碼 ，通過研讀Zookeeper客戶端源碼，發(fā)現(xiàn)存在這樣一個設(shè)計：客戶端會把所有的請求先放入一個隊列中，然后通過一個發(fā)送線程(SendThread)從隊列中獲取請求，發(fā)送到服務(wù)端，關(guān)鍵代碼如下：

如果存在大量的zk更新操作，心跳包可能會處理不及時，而在出現(xiàn)zookeeper session會話超時之前，集群在大面積ISR擴張與收縮，頻繁更新zk，從而觸發(fā)了客戶端端心跳超時，這個問題也可以通過如下代碼進行復(fù)現(xiàn)：

經(jīng)過這波分析，由于zookeeper會話超時，導(dǎo)致大量分區(qū)重新選舉，最終導(dǎo)致消息發(fā)送延遲很大，并且消費組大面積重平衡的根本原因就排查清楚了，本期分享就到此為止，我們下期見。

文章名稱：生產(chǎn)故障｜Kafka消息發(fā)送延遲達到幾十秒的罪魁禍?zhǔn)拙谷皇?..
當(dāng)前URL：http://uogjgqi.cn/article/dpoophh.html