kill -9 導(dǎo)致 Kakfa 重啟失敗的慘痛經(jīng)歷！
背景
在 2 月10 號下午大概 1 點(diǎn)半左右，收到用戶方反饋，發(fā)現(xiàn)日志 kafka 集群 A 主題 的 34 分區(qū)選舉不了 leader，
導(dǎo)致某些消息發(fā)送到該分區(qū)時(shí)，會(huì)報(bào)如下 no leader 的錯(cuò)誤信息：
In the middle of a leadership election,
there is currently no leader for this partition and hence it is unavailable for writes.
由于 A 主題 34 分區(qū)的 leader 副本在 broker0，另外一個(gè)副本由于速度跟不上 leader，已被踢出 ISR，
0.11 版本的 kafka 的 unclean.leader.election.enable 參數(shù)默認(rèn)為 false，表示分區(qū)不可在 ISR 以外的副本選舉 leader，導(dǎo)致了 A 主題發(fā)送消息持續(xù)報(bào) 34 分區(qū) leader 不存在的錯(cuò)誤，且該分區(qū)還未消費(fèi)的消息不能繼續(xù)消費(fèi)了。接下來運(yùn)維在 kafka-manager 查不到 broker0 節(jié)點(diǎn)了處于假死狀態(tài)，但是進(jìn)程依然還在，重啟了好久沒見反應(yīng)，然后通過 kill -9 命令殺死節(jié)點(diǎn)進(jìn)程后，接著重啟失敗了，導(dǎo)致了如下問題：
Kafka 日志分析
查看了 KafkaServer.log 日志，發(fā)現(xiàn) Kafka 重啟過程中，產(chǎn)生了大量如下日志：
發(fā)現(xiàn)大量主題索引文件損壞并且重建索引文件的警告信息，定位到源碼處：
kafka.log.OffsetIndex#sanityCheck
按我自己的理解描述下：
Kafka 在啟動(dòng)的時(shí)候，會(huì)檢查 kafka 是否為 cleanshutdown，判斷依據(jù)為 ${log.dirs} 目錄中是否存在 .kafka_cleanshutDown 的文件，如果非正常退出就沒有這個(gè)文件，接著就需要 recover log 處理，在處理中會(huì)調(diào)用 sanityCheck() 方法用于檢驗(yàn)每個(gè) log sement 的 index 文件，確保索引文件的完整性：
entries：由于 kafka 的索引文件是一個(gè)稀疏索引，并不會(huì)將每條消息的位置都保存到 .index 文件中，因此引入了 entry 模式，即每一批消息只記錄一個(gè)位置，因此索引文件的 entries = mmap.position / entrySize； lastOffset：最后一塊 entry 的位移，即 lastOffset = lastEntry.offset； baseOffset：指的是索引文件的基偏移量，即索引文件名稱的那個(gè)數(shù)字。
索引文件與日志文件對應(yīng)關(guān)系圖如下：
判斷索引文件是否損壞的依據(jù)是：
_entries == 0 || _lastOffset > baseOffset = false // 損壞
_entries == 0 || _lastOffset > baseOffset = true // 正常
這個(gè)判斷邏輯我的理解是：
entries 索引塊等于零時(shí)，意味著索引沒有內(nèi)容，此時(shí)可以認(rèn)為索引文件是沒有損壞的；當(dāng) entries 索引塊不等于 0，就需要判斷索引文件最后偏移量是否大于索引文件的基偏移量，如果不大于，則說明索引文件被損壞了，需要用重新構(gòu)建。那為什么會(huì)出現(xiàn)這種情況呢？
我在相關(guān) issue 中似乎找到了一些答案：
https://issues.apache.org/jira/browse/KAFKA-1112
https://issues.apache.org/jira/browse/KAFKA-1554
總的來說，非正常退出在舊版本似乎會(huì)可能發(fā)生這個(gè)問題？
有意思的來了，導(dǎo)致開機(jī)不了并不是這個(gè)問題導(dǎo)致的，因?yàn)檫@個(gè)問題已經(jīng)在后續(xù)版本修復(fù)了，從日志可看出，它會(huì)將損壞的日志文件刪除并重建，我們接下來繼續(xù)看導(dǎo)致重啟不了的錯(cuò)誤信息：
問題就出在這里，在刪除并重建索引過程中，就可能出現(xiàn)如上問題，在 issues.apache.org 網(wǎng)站上有很多關(guān)于這個(gè) bug 的描述，我這里貼兩個(gè)出來：
https://issues.apache.org/jira/browse/KAFKA-4972
https://issues.apache.org/jira/browse/KAFKA-3955
這些 bug 很隱晦，而且非常難復(fù)現(xiàn)，既然后續(xù)版本不存在該問題，當(dāng)務(wù)之急還是升級 Kafka 版本，后續(xù)等我熟悉 scala 后，再繼續(xù)研究下源碼，細(xì)節(jié)一定是會(huì)在源碼中呈現(xiàn)。
解決思路分析
針對背景兩個(gè)問題，矛盾點(diǎn)都是因?yàn)?broker0 重啟失敗導(dǎo)致的，那么我們要么把 broker0 啟動(dòng)成功，才能恢復(fù) A 主題 34 分區(qū)。由于日志和索引文件的原因一直啟動(dòng)不起來，我們只需要將損壞的日志和索引文件刪除并重啟即可。但如果出現(xiàn) 34 分區(qū)的日志索引文件也損壞的情況下，就會(huì)丟失該分區(qū)下未消費(fèi)的數(shù)據(jù)，原因如下：
此時(shí) 34 分區(qū)的 leader 還處在 broker0 中，由于 broker0 掛掉了且 34 分區(qū) isr 只有 leader，導(dǎo)致 34 分區(qū)不可用，在這種情況下，假設(shè)你將 broker0 中 leader 的數(shù)據(jù)清空，重啟后 Kafka 依然會(huì)將 broker0 上的副本作為 leader，那么就需要以 leader 的偏移量為準(zhǔn)，而這時(shí) leader 的數(shù)據(jù)清空了，只能將 follower 的數(shù)據(jù)強(qiáng)行截?cái)酁?0，且不大于 leader 的偏移量。這似乎不太合理，這時(shí)候是不是可以提供一個(gè)操作的可能：
在分區(qū)不可用時(shí)，用戶可以手動(dòng)設(shè)置分區(qū)內(nèi)任意一個(gè)副本作為 leader？
后續(xù)集群的優(yōu)化
制定一個(gè)升級方案，將集群升級到 2.x 版本； 每個(gè)節(jié)點(diǎn)的服務(wù)器將 systemd 的默認(rèn)超時(shí)值為 600 秒，因?yàn)槲野l(fā)現(xiàn)運(yùn)維在故障當(dāng)天關(guān)閉 33 節(jié)點(diǎn)時(shí)長時(shí)間沒反應(yīng)，才會(huì)使用 kill -9 命令強(qiáng)制關(guān)閉。 但據(jù)我了解關(guān)閉一個(gè) Kafka 服務(wù)器時(shí)，Kafka 需要做很多相關(guān)工作，這個(gè)過程可能會(huì)存在相當(dāng)一段時(shí)間，而 systemd 的默認(rèn)超時(shí)值為 90 秒即可讓進(jìn)程停止，那相當(dāng)于非正常退出了。 將 broker 參數(shù) unclean.leader.election.enable設(shè)置為 true（確保分區(qū)可從非 ISR 中選舉 leader）；將 broker 參數(shù) default.replication.factor設(shè)置為 3（提高高可用，但會(huì)增大集群的存儲(chǔ)壓力，可后續(xù)討論）；將 broker 參數(shù) min.insync.replicas設(shè)置為 2（這么做可確保 ISR 同時(shí)有兩個(gè)，但是這么做會(huì)造成性能損失，是否有必要？因?yàn)槲覀円呀?jīng)將 unclean.leader.election.enable設(shè)置為 true 了）；發(fā)送端發(fā)送 acks=1（確保發(fā)送時(shí)有一個(gè)副本是同步成功的，但這個(gè)是否有必要，因?yàn)榭赡軙?huì)造成性能損失）。
從源碼中定位到問題的根源
首先把導(dǎo)致 Kafka 進(jìn)程退出的異常棧貼出來：
注：以下源碼基于 kafka 0.11.x 版本。
我們直接從 index 文件損壞警告日志的位置開始：
kafka.log.Log#loadSegmentFiles
從前一篇文章中已經(jīng)說到，Kafka 在啟動(dòng)的時(shí)候，會(huì)檢查kafka是否為 cleanshutdown，判斷依據(jù)為 ${log.dirs} 目錄中是否存在 .kafka_cleanshutDown 的文件，如果非正常退出就沒有這個(gè)文件，接著就需要 recover log 處理，在處理中會(huì)調(diào)用 。在 recover 前，會(huì)調(diào)用 sanityCheck() 方法用于檢驗(yàn)每個(gè) log sement 的 index 文件，確保索引文件的完整性 ，如果發(fā)現(xiàn)索引文件損壞，刪除并調(diào)用 recoverSegment() 方法進(jìn)行索引文件的重構(gòu)，最終會(huì)調(diào)用 recover() 方法：
kafka.log.LogSegment#recover
源碼中相關(guān)變量說明：
log：當(dāng)前日志 Segment 文件的對象； batchs：一個(gè) log segment 的消息壓縮批次； batch：消息壓縮批次； indexIntervalBytes：該參數(shù)決定了索引文件稀疏間隔打底有多大，由 broker 端參數(shù) log.index.interval.bytes決定，默認(rèn)值為 4 KB，即表示當(dāng)前分區(qū) log 文件寫入了 4 KB 數(shù)據(jù)后才會(huì)在索引文件中增加一個(gè)索引項(xiàng)（entry）； validBytes：當(dāng)前消息批次在 log 文件中的物理地址。
知道相關(guān)參數(shù)的含義之后，那么這段代碼的也就容易解讀了：循環(huán)讀取 log 文件中的消息批次，并讀取消息批次中的 baseOffset 以及在 log 文件中物理地址，將其追加到索引文件中，追加的間隔為 indexIntervalBytes 大小。
我們再來解讀下消息批次中的 baseOffset：我們知道一批消息中，有最開頭的消息和末尾消息，所以一個(gè)消息批次中，分別有 baseOffset 和 lastOffset，源碼注釋如下：
其中最關(guān)鍵的描述是：它可以是也可以不是第一條記錄的偏移量。
kafka.log.OffsetIndex#append
以上是追加索引塊核心方法，在這里可以看到 Kafka 異常棧的詳細(xì)信息，Kafka 進(jìn)程也就是在這里被異常中斷退出的（這里吐槽一下，
為什么一個(gè)分區(qū)有損壞，要整個(gè) broker 掛掉？寧錯(cuò)過，不放過？就不能標(biāo)記該分區(qū)不能用，然后讓 broker 正常啟動(dòng)以提供服務(wù)給其他分區(qū)嗎？建議 Kafka 在日志恢復(fù)期間加強(qiáng)異常處理，
不知道后續(xù)版本有沒有優(yōu)化，后面等我拿 2.x 版本源碼分析一波），退出的條件是：
_entries == 0 || offset > _lastOffset = false
也就是說，假設(shè)索引文件中的索引條目為 0，說明索引文件內(nèi)容為空，那么直接可以追加索引，而如果索引文件中有索引條目了，
需要消息批次中的 baseOffset 大于索引文件最后一個(gè)條目中的位移，因?yàn)樗饕募沁f增的，因此不允許比最后一個(gè)條目的索引還小的消息位移。
現(xiàn)在也就很好理解了，產(chǎn)生這個(gè)異常報(bào)錯(cuò)的根本原因，是因?yàn)楹竺娴南⑴沃校形灰票茸詈笏饕灰七€要?。ɑ蛘叩扔冢?。
前面也說過了，消息批次中的 baseOffset 不一定是第一條記錄的偏移量，那么問題是不是出在這里？我的理解是這里有可能會(huì)造成兩個(gè)消息批次獲取到的 baseOffset 有相交的值？
對此我并沒有繼續(xù)研究下去了，但我確定的是，在 kafka 2.x 版本中，append() 方法中的 offset 已經(jīng)改成 消息批次中的 lastOffset 了：
這里我也需要吐槽一下，如果出現(xiàn)這個(gè) bug，意味著這個(gè)問題除非是將這些故障的日志文件和索引文件刪除，否則該節(jié)點(diǎn)永遠(yuǎn)啟動(dòng)不了，這也太暴力了吧？
我花了非常多時(shí)間去專門看了很多相關(guān) issue，目前還沒看到有解決這個(gè)問題的方案？或者我需要繼續(xù)尋找？我把相關(guān) issue 貼出來：
https://issues.apache.org/jira/browse/KAFKA-1211
https://issues.apache.org/jira/browse/KAFKA-3919
https://issues.apache.org/jira/browse/KAFKA-3955
嚴(yán)重建議各位盡快把 Kafka 版本升級到 2.x 版本，舊版本太多問題了，后面我著重研究 2.x 版本的源碼。
下面我從日志文件結(jié)構(gòu)中繼續(xù)分析。
從日志文件結(jié)構(gòu)中看到問題的本質(zhì)
我們用 Kafka 提供的 DumpLogSegments 工具打開 log 和 index 文件：
$ ~/kafka_2.1x-0.11.x/bin/kafka-run-class.sh kafka.tools.DumpLogSegments
--files {log_path}/secxxx-2/00000000000110325000.log > secxxx.log
$ ~/kafka_2.1x-0.11.x/bin/kafka-run-class.sh kafka.tools.DumpLogSegments
--files {log_path}/secxxx-2/00000000000110325000.index > secxxx-index.log
用 less -Nm 命令查看，log 和 index 對比：
如上圖所示，index最后記錄的 offset = 110756715，positioin=182484660，與異常棧顯示的一樣，說明在進(jìn)行追加下一個(gè)索引塊的時(shí)候，發(fā)現(xiàn)下一個(gè)索引塊的 offset 索引不大于最后一個(gè)索引塊的 offset，因此不允許追加，報(bào)異常并退出進(jìn)程，那么問題就出現(xiàn)在下一個(gè)消息批次的 baseOffset，根據(jù) log.index.interval.bytes 默認(rèn)值大小為 4 KB（4096），而追加的條件前面也說了，需要大于 log.index.interval.bytes，因此我們 DumpLogSegments 工具查詢：
從 dump 信息中可知，在 positioin=182484660 往后的幾個(gè)消息批次中，它們的大小加起來大于 4096 的消息批次的 offset=110756804，postion=182488996，它的 baseOffset 很可能就是 110756715，與索引文件最后一個(gè)索引塊的 Offset 相同，因此出現(xiàn)錯(cuò)誤。
接著我們繼續(xù)用 DumpLogSegments 工具查看消息批次內(nèi)容：
我們先查看 offset = 110756715，positioin=182484660 的消息塊詳情：
接著尋找 offset = 110756715，的消息批次塊：
終于找到你了，跟我預(yù)測的一樣！postion=182488996，在將該消息批次追加到索引文件中，發(fā)生 offset 混亂了。
如果還是沒找到官方的處理方案，就只能刪除這些錯(cuò)誤日志文件和索引文件，然后重啟節(jié)點(diǎn)？
非常遺憾，我在查看了相關(guān)的 issue 之后，貌似還沒看到官方的解決辦法，所幸的是該集群是日志集群，數(shù)據(jù)丟失也沒有太大問題。
不過呢，0.11.x 版本屬于很舊的版本了，因此，升級 Kafka 版本才是長久之計(jì)??！我已經(jīng)迫不及待地想擼 kafka 源碼了！
經(jīng)過以上問題分析與排查之后，
我專門對分區(qū)不可用進(jìn)行故障重現(xiàn)，并給出我的一些騷操作來盡量減少數(shù)據(jù)的丟失。
故障重現(xiàn)
下面我用一個(gè)例子重現(xiàn)現(xiàn)分區(qū)不可用且 leader 副本被損壞的例子：
使用 unclean.leader.election.enable = false 參數(shù)啟動(dòng) broker0； 使用 unclean.leader.election.enable = false 參數(shù)啟動(dòng) broker1； 創(chuàng)建 topic-1，partition=1，replica-factor=2； 將消息寫入 topic-1； 此時(shí)，兩個(gè) broker 上的副本都處于 ISR 中，broker0 的副本為 leader 副本； 停止 broker1，此時(shí) topic-1 的 leader 依然時(shí) broker0 的副本，而 broker1 的副本從 ISR 中剔除； 停止 broker0，并且刪除 broker0 上的日志數(shù)據(jù)； 重啟 broker1，topic-1 嘗試連接 leader 副本，但此時(shí) broker0 已經(jīng)停止運(yùn)行，此時(shí)分區(qū)處于不可用狀態(tài)，無法寫入消息； 恢復(fù) broker0，broker0 上的副本恢復(fù) leader 職位，此時(shí) broker1 嘗試加入 ISR，但此時(shí)由于 leader 的數(shù)據(jù)被清除，即偏移量為 0，此時(shí) broker1 的副本需要截?cái)嗳罩荆３制屏坎淮笥?leader 副本，此時(shí)分區(qū)的數(shù)據(jù)全部丟失。
向 Kafka 官方提的建議
在遇到分區(qū)不可用時(shí)，是否可以提供一個(gè)選項(xiàng)，讓用戶可以手動(dòng)設(shè)置分區(qū)內(nèi)任意一個(gè)副本作為 leader？
因?yàn)榧阂坏┰O(shè)置了 unclean.leader.election.enable = false，就無法選舉 ISR 以外的副本作為 leader，在極端情況下僅剩 leader 副本還在 ISR 中，此時(shí) leader 所在的 broker 宕機(jī)了，那如果此時(shí) broker 數(shù)據(jù)發(fā)生損壞這么辦？在這種情況下，能不能讓用戶自己選擇 leader 副本呢？盡管這么做也是會(huì)有數(shù)據(jù)丟失，但相比整個(gè)分區(qū)的數(shù)據(jù)都丟失而言，情況還是會(huì)好很多的。
如何盡量減少數(shù)據(jù)丟失？
首先你得有一個(gè)不可用的分區(qū)（并且該分區(qū) leader 副本數(shù)據(jù)已損失），如果是測試，可以以上故障重現(xiàn) 1-8 步驟實(shí)現(xiàn)一個(gè)不可用的分區(qū)（需要增加一個(gè) broker）：
此時(shí) leader 副本在 broker0，但已經(jīng)掛了，且分區(qū)不可用，此時(shí) broker2 的副本由于掉出 ISR ，不可選為 leader，且 leader 副本已損壞清除，如果此時(shí)重啟 broker0，follower 副本會(huì)進(jìn)行日志截?cái)?，將?huì)丟失該分區(qū)所有數(shù)據(jù)。
經(jīng)過一系列的測試與實(shí)驗(yàn)，我總結(jié)出了以下騷操作，可以強(qiáng)行把 broker2 的副本選為 leader，盡量減少數(shù)據(jù)丟失：
1、使用 kafka-reassign-partitions.sh 腳本對該主題進(jìn)行分區(qū)重分配，當(dāng)然你也可以使用 kafka-manager 控制臺(tái)對該主題進(jìn)行分區(qū)重分配，重分配之后如下：
此時(shí) preferred leader 已經(jīng)改成 broker2 所在的副本了，但此時(shí)的 leader 依然還是 broker0 的副本。需要注意的是，分區(qū)重分配之后的 preferred leader 一定要之前那個(gè)踢出 ISR 的副本，而不是分區(qū)重分配新生成的副本。因?yàn)樾律傻母北酒屏繛?0，如果自動(dòng)重分配不滿足，那么需要編寫 json 文件，手動(dòng)更改分配策略。
2、進(jìn)入 zk，查看分區(qū)狀態(tài)并修改它的內(nèi)容：
修改 node 內(nèi)容，強(qiáng)行將 leader 改成 2（與重分配之后的 preferred leader 一樣），并且將 leader_epoch 加 1 處理，同時(shí) ISR 列表改成 leader，改完如下：
此時(shí)，kafka-manager 控制臺(tái)會(huì)顯示成這樣：
但此時(shí)依然不生效，記住這時(shí)需要重啟 broker 0。
3、重啟 broker0，發(fā)現(xiàn)分區(qū)的 lastOffset 已經(jīng)變成了 broker2 的副本的 lastOffset：
成功挽回了 46502 條消息數(shù)據(jù)，盡管依然丟失了 76053 - 46502 = 29551 條消息數(shù)據(jù)，但相比全部丟失相對好吧！
以上方法的原理其實(shí)很簡單，就是強(qiáng)行把 Kafka 認(rèn)定的 leader 副本改成自己想要設(shè)置的副本，然后 lastOffset 就會(huì)以我們手動(dòng)設(shè)置的副本 lastOffset 為基準(zhǔn)了。
往期推薦
修正版 | QPS過萬，Redis大量連接超時(shí)怎么解決？