三年之久的 etcd3 數(shù)據(jù)不一致 bug 分析
etcd 作為 Kubernetes 集群的元數(shù)據(jù)存儲(chǔ),是被業(yè)界廣泛使用的強(qiáng)一致性 KV 存儲(chǔ),但近日被挖掘出一個(gè)存在 3 年之久的數(shù)據(jù)不一致 bug——client 寫(xiě)入后無(wú)法在異常節(jié)點(diǎn)讀取到數(shù)據(jù),即數(shù)據(jù)丟失。本文介紹了我們是如何從問(wèn)題分析、大膽猜測(cè)、嚴(yán)謹(jǐn)驗(yàn)證、排除、工程化復(fù)現(xiàn),從 raft 到 boltdb,從源碼定制再到 chaos monkey,一步步定位并解決 etcd 數(shù)據(jù)不一致 bug 的詳細(xì)流程,并將解決方案提交給社區(qū),移植到 etcd 3.4/3.3 生產(chǎn)環(huán)境分支。希望通過(guò)本文,能夠揭開(kāi) etcd 的神秘面紗,讓大家對(duì) etcd 的原理和問(wèn)題定位有一個(gè)較為深入的了解。
問(wèn)題背景
詭異的 K8S 滾動(dòng)更新異常
筆者某天收到同事反饋,測(cè)試環(huán)境中 K8S 集群進(jìn)行滾動(dòng)更新發(fā)布時(shí)未生效。通過(guò) kube-apiserver 查看發(fā)現(xiàn),對(duì)應(yīng)的 Deployment 版本已經(jīng)是最新版,但是這個(gè)最新版本的 Pod 并未創(chuàng)建出來(lái)。
針對(duì)該現(xiàn)象,我們最開(kāi)始猜測(cè)可能是 kube-controller-manager 的 bug 導(dǎo)致,但是觀察 controller-manager 日志并未發(fā)現(xiàn)明顯異常。第一次調(diào)高 controller-manager 的日志等級(jí)并進(jìn)行重啟操作之后,似乎由于 controller-manager 并沒(méi)有 watch 到這個(gè)更新事件,我們?nèi)匀粵](méi)有發(fā)現(xiàn)問(wèn)題所在。此時(shí),觀察 kube-apiserver 日志,同樣也沒(méi)有出現(xiàn)明顯異常。
于是,再次調(diào)高日志等級(jí)并重啟 kube-apiserver,詭異的事情發(fā)生了,之前的 Deployment 正常滾動(dòng)更新了!
etcd 數(shù)據(jù)不一致 ?
由于從 kube-apiserver 的日志中同樣無(wú)法提取出能夠幫助解決問(wèn)題的有用信息,起初我們只能猜測(cè)可能是 kube-apiserver 的緩存更新異常導(dǎo)致的。正當(dāng)我們要從這個(gè)切入點(diǎn)去解決問(wèn)題時(shí),該同事反饋了一個(gè)更詭異的問(wèn)題——自己新創(chuàng)建的 Pod,通過(guò) kubectl查詢 Pod 列表,突然消失了!納尼?這是什么騷操作?經(jīng)過(guò)我們多次測(cè)試查詢發(fā)現(xiàn),通過(guò) kubectl 來(lái) list pod 列表,該 pod 有時(shí)候能查到,有時(shí)候查不到。那么問(wèn)題來(lái)了,K8s api 的 list 操作是沒(méi)有緩存的,數(shù)據(jù)是 kube-apiserver 直接從 etcd 拉取返回給客戶端的,難道是 etcd 本身出了問(wèn)題?
眾所周知,etcd 本身是一個(gè)強(qiáng)一致性的 KV 存儲(chǔ),在寫(xiě)操作成功的情況下,兩次讀請(qǐng)求不應(yīng)該讀取到不一樣的數(shù)據(jù)。懷著不信邪的態(tài)度,我們通過(guò) etcdctl 直接查詢了 etcd 集群狀態(tài)和集群數(shù)據(jù),返回結(jié)果顯示 3 個(gè)節(jié)點(diǎn)狀態(tài)都正常,且 RaftIndex 一致,觀察 etcd 的日志也并未發(fā)現(xiàn)報(bào)錯(cuò)信息,唯一可疑的地方是 3 個(gè)節(jié)點(diǎn)的 dbsize 差別較大。接著,我們又將 client 訪問(wèn)的 endpoint 指定為不同節(jié)點(diǎn)地址來(lái)查詢每個(gè)節(jié)點(diǎn)的 key 的數(shù)量,結(jié)果發(fā)現(xiàn) 3 個(gè)節(jié)點(diǎn)返回的 key 的數(shù)量不一致,甚至兩個(gè)不同節(jié)點(diǎn)上 Key 的數(shù)量差最大可達(dá)到幾千!而直接通過(guò) etcdctl 查詢剛才創(chuàng)建的 Pod,發(fā)現(xiàn)訪問(wèn)某些 endpoint 能夠查詢到該 pod,而訪問(wèn)其他 endpoint 則查不到。至此,基本可以確定 etcd 集群的節(jié)點(diǎn)之間確實(shí)存在數(shù)據(jù)不一致現(xiàn)象。
問(wèn)題分析和排查過(guò)程
遇事不決問(wèn)Google
強(qiáng)一致性的存儲(chǔ)突然數(shù)據(jù)不一致了,這么嚴(yán)重的問(wèn)題,想必日志里肯定會(huì)有所體現(xiàn)。然而,可能是 etcd 開(kāi)發(fā)者擔(dān)心日志太多會(huì)影響性能的緣故,etcd 的日志打印的比較少,以至于我們排查了 etcd 各個(gè)節(jié)點(diǎn)的日志,也沒(méi)有發(fā)現(xiàn)有用的報(bào)錯(cuò)日志。甚至是在我們調(diào)高日志級(jí)別之后,仍沒(méi)有發(fā)現(xiàn)異常信息。
作為一個(gè)21世紀(jì)的程序員,遇到這種詭異且暫時(shí)沒(méi)頭緒的問(wèn)題,第一反應(yīng)當(dāng)然是先 Google 一下啦,畢竟不會(huì) StackOverFlow 的程序員不是好運(yùn)維!Google 輸入“etcd data inconsistent” 搜索發(fā)現(xiàn),并不是只有我們遇到過(guò)該問(wèn)題,之前也有其他人向 etcd 社區(qū)反饋過(guò)類似問(wèn)題,只是苦于沒(méi)有提供穩(wěn)定的復(fù)現(xiàn)方式,最后都不了了之。如 issue
- https://github.com/etcd-io/etcd/issues/9630
- https://github.com/etcd-io/etcd/issues/10407
- https://github.com/etcd-io/etcd/issues/10594
- https://github.com/etcd-io/etcd/issues/11643
由于這個(gè)問(wèn)題比較嚴(yán)重,會(huì)影響到數(shù)據(jù)的一致性,而我們生產(chǎn)環(huán)境中當(dāng)前使用了數(shù)百套 etcd 集群,為了避免出現(xiàn)類似問(wèn)題,我們決定深入定位一番。
etcd 工作原理和術(shù)語(yǔ)簡(jiǎn)介
在開(kāi)始之前,為方便讀者理解,這里先簡(jiǎn)單介紹下 etcd 的常用術(shù)語(yǔ)和基本讀寫(xiě)原理。
術(shù)語(yǔ)表:
etcd 是一個(gè)強(qiáng)一致性的分布式 KV 存儲(chǔ),所謂強(qiáng)一致性,簡(jiǎn)單來(lái)說(shuō)就是一個(gè)寫(xiě)操作成功后,從任何一個(gè)節(jié)點(diǎn)讀出來(lái)的數(shù)據(jù)都是最新值,而不會(huì)出現(xiàn)寫(xiě)數(shù)據(jù)成功后讀不出來(lái)或者讀到舊數(shù)據(jù)的情況。etcd 通過(guò) raft 協(xié)議來(lái)實(shí)現(xiàn) leader 選舉、配置變更以及保證數(shù)據(jù)讀寫(xiě)的一致性。下面簡(jiǎn)單介紹下 etcd 的讀寫(xiě)流程:
寫(xiě)數(shù)據(jù)流程(以 leader 節(jié)點(diǎn)為例,見(jiàn)上圖):
- etcd 任一節(jié)點(diǎn)的 etcd server 模塊收到 Client 寫(xiě)請(qǐng)求(如果是 follower 節(jié)點(diǎn),會(huì)先通過(guò) Raft 模塊將請(qǐng)求轉(zhuǎn)發(fā)至 leader 節(jié)點(diǎn)處理)。
- etcd server 將請(qǐng)求封裝為 Raft 請(qǐng)求,然后提交給 Raft 模塊處理。
- leader 通過(guò) Raft 協(xié)議與集群中 follower 節(jié)點(diǎn)進(jìn)行交互,將消息復(fù)制到follower 節(jié)點(diǎn),于此同時(shí),并行將日志持久化到 WAL。
- follower 節(jié)點(diǎn)對(duì)該請(qǐng)求進(jìn)行響應(yīng),回復(fù)自己是否同意該請(qǐng)求。
- 當(dāng)集群中超過(guò)半數(shù)節(jié)點(diǎn)((n/2)+1 members )同意接收這條日志數(shù)據(jù)時(shí),表示該請(qǐng)求可以被Commit,Raft 模塊通知 etcd server 該日志數(shù)據(jù)已經(jīng) Commit,可以進(jìn)行 Apply。
- 各個(gè)節(jié)點(diǎn)的 etcd server 的 applierV3 模塊異步進(jìn)行 Apply 操作,并通過(guò) MVCC 模塊寫(xiě)入后端存儲(chǔ) BoltDB。
- 當(dāng) client 所連接的節(jié)點(diǎn)數(shù)據(jù) apply 成功后,會(huì)返回給客戶端 apply 的結(jié)果。
讀數(shù)據(jù)流程:
- etcd 任一節(jié)點(diǎn)的 etcd server 模塊收到客戶端讀請(qǐng)求(Range 請(qǐng)求)
- 判斷讀請(qǐng)求類型,如果是串行化讀(serializable)則直接進(jìn)入 Apply 流程
- 如果是線性一致性讀(linearizable),則進(jìn)入 Raft 模塊
- Raft 模塊向 leader 發(fā)出 ReadIndex 請(qǐng)求,獲取當(dāng)前集群已經(jīng)提交的最新數(shù)據(jù) Index
- 等待本地 AppliedIndex 大于或等于 ReadIndex 獲取的 CommittedIndex 時(shí),進(jìn)入 Apply 流程
- Apply 流程:通過(guò) Key 名從 KV Index 模塊獲取 Key 最新的 Revision,再通過(guò) Revision 從 BoltDB 獲取對(duì)應(yīng)的 Key 和 Value。
初步驗(yàn)證
通常集群正常運(yùn)行情況下,如果沒(méi)有外部變更的話,一般不會(huì)出現(xiàn)這么嚴(yán)重的問(wèn)題。我們查詢故障 etcd 集群近幾天的發(fā)布記錄時(shí)發(fā)現(xiàn),故障前一天對(duì)該集群進(jìn)行的一次發(fā)布中,由于之前 dbsize 配置不合理,導(dǎo)致 db 被寫(xiě)滿,集群無(wú)法寫(xiě)入新的數(shù)據(jù),為此運(yùn)維人員更新了集群 dbsize 和 compaction 相關(guān)配置,并重啟了 etcd。重啟后,運(yùn)維同學(xué)繼續(xù)對(duì) etcd 手動(dòng)執(zhí)行了 compact 和 defrag 操作,來(lái)壓縮 db 空間。通過(guò)上述場(chǎng)景,我們可以初步判斷出以下幾個(gè)可疑的觸發(fā)條件:
- dbsize 滿
- dbsize 和 compaction 配置更新
- compaction 操作和 defrag 操作
- 重啟 etcd
出了問(wèn)題肯定要能夠復(fù)現(xiàn)才更有利于解決問(wèn)題,正所謂能夠復(fù)現(xiàn)的 bug 就不叫 bug。復(fù)現(xiàn)問(wèn)題之前,我們通過(guò)分析 etcd 社區(qū)之前的相關(guān) issue 發(fā)現(xiàn),觸發(fā)該 bug 的共同條件都包含執(zhí)行過(guò) compaction 和 defrag 操作,同時(shí)重啟過(guò) etcd 節(jié)點(diǎn)。因此,我們計(jì)劃首先嘗試同時(shí)模擬這幾個(gè)操作,觀察是否能夠在新的環(huán)境中復(fù)現(xiàn)。為此我們新建了一個(gè)集群,然后通過(guò)編寫(xiě)腳本向集群中不停的寫(xiě)入和刪除數(shù)據(jù),直到 dbsize 達(dá)到一定程度后,對(duì)節(jié)點(diǎn)依次進(jìn)行配置更新和重啟,并觸發(fā) compaction 和 defrag 操作。然而經(jīng)過(guò)多次嘗試,我們并沒(méi)有復(fù)現(xiàn)出類似于上述數(shù)據(jù)不一致的場(chǎng)景。
抽絲剝繭,初現(xiàn)端倪
緊接著,在之后的測(cè)試中無(wú)意發(fā)現(xiàn),client 指定不同的 endpoint 寫(xiě)數(shù)據(jù),能夠查到數(shù)據(jù)的節(jié)點(diǎn)也不同。比如,endpoint 指定為 node1 進(jìn)行寫(xiě)數(shù)據(jù),3個(gè)節(jié)點(diǎn)都可以查到數(shù)據(jù);endpoint 指定為 node2 進(jìn)行寫(xiě)數(shù)據(jù),node2 和 node3 可以查到;endpoint 指定為 node3 寫(xiě)數(shù)據(jù),只有 node3 自己能夠查到。具體情況如下表:
于是我們做出了初步的猜測(cè),有以下幾種可能:
- 集群可能分裂了,leader 未將消息發(fā)送給 follower 節(jié)點(diǎn)。
- leader 給 follower 節(jié)點(diǎn)發(fā)送了消息,但是 log 異常,沒(méi)有對(duì)應(yīng)的 command 。
- leader 給 follower 節(jié)點(diǎn)發(fā)送了消息,有對(duì)應(yīng)的 command,但是 apply 異常,操作還未到 KV Index 和 boltdb 就異常了。
- leader 給 follower 節(jié)點(diǎn)發(fā)送了消息, 有對(duì)應(yīng)的 command,但是 apply 異常,KV Index 出現(xiàn)了問(wèn)題。
- leader 給 follower 節(jié)點(diǎn)發(fā)送了消息, 有對(duì)應(yīng)的 command,但是 apply 異常,boltdb 出現(xiàn)了問(wèn)題。
為了驗(yàn)證我們的猜測(cè),我們進(jìn)行了一系列測(cè)試來(lái)縮小問(wèn)題范圍:首先,我們通過(guò) endpoint status 查看集群信息,發(fā)現(xiàn) 3 個(gè)節(jié)點(diǎn)的 clusterId,leader,raftTerm,raftIndex 信息均一致,而 dbSize 大小和 revision 信息不一致。clusterId 和 leader 一致,基本排除了集群分裂的猜測(cè),而 raftTerm 和 raftIndex 一致,說(shuō)明 leader 是有向 follower 同步消息的,也進(jìn)一步排除了第一個(gè)猜測(cè),但是 WAL落盤(pán)有沒(méi)有異常還不確定。dbSize 和 revision 不一致則進(jìn)一步說(shuō)明了 3 個(gè)節(jié)點(diǎn)數(shù)據(jù)已經(jīng)發(fā)生不一致了。
其次,由于 etcd 本身提供了一些 dump 工具,例如 etcd-dump-log 和 etcd-dump-db。我們可以像下圖一樣,使用 etcd-dump-log dump 出指定 WAL 文件的內(nèi)容,使用 etcd-dump-db dump 出 db 文件的數(shù)據(jù),方便對(duì) WAL 和 db 數(shù)據(jù)進(jìn)行分析。
于是,我們向 node3 寫(xiě)了一條便于區(qū)分的數(shù)據(jù),然后通過(guò) etcd-dump-log 來(lái)分析 3 個(gè)節(jié)點(diǎn)的 WAL,按照剛才的測(cè)試,endpoint 指定為 node3 寫(xiě)入的數(shù)據(jù),通過(guò)其他兩個(gè)節(jié)點(diǎn)應(yīng)該查不到的。但是我們發(fā)現(xiàn) 3 個(gè)節(jié)點(diǎn)都收到了 WAL log,也就是說(shuō) WAL 并沒(méi)有丟,因此排除了第二個(gè)猜測(cè)。
接下來(lái)我們 dump 了 db 的數(shù)據(jù)進(jìn)行分析,發(fā)現(xiàn) endpoint 指定為 node3 寫(xiě)入的數(shù)據(jù),在其他兩個(gè)節(jié)點(diǎn)的 db 文件里找不到,也就是說(shuō)數(shù)據(jù)確實(shí)沒(méi)有落到 db,而不是寫(xiě)進(jìn)去了查不出來(lái)。
既然 WAL 里有而 db 里沒(méi)有,因此很大可能是 apply 流程異常了,數(shù)據(jù)可能在 apply 時(shí)被丟棄了。
由于現(xiàn)有日志無(wú)法提供更有效的信息,我們打算在 etcd 里新加一些日志來(lái)更好地幫助我們定位問(wèn)題。etcd 在做 apply 操作時(shí),trace 日志會(huì)打印超過(guò)每個(gè)超過(guò) 100ms 的請(qǐng)求,我們首先把 100ms 這個(gè)閾值調(diào)低,調(diào)整到 1ns,這樣每個(gè) apply 的請(qǐng)求都能夠記錄下來(lái),可以更好的幫助我們定位問(wèn)題。
編譯好新版本之后,我們替換了其中一個(gè) etcd 節(jié)點(diǎn),然后向不同 node 發(fā)起寫(xiě)請(qǐng)求測(cè)試。果然,我們發(fā)現(xiàn)了一條不同尋常的錯(cuò)誤日志:"error":"auth:revision in header is old",因此我們斷定問(wèn)題很可能是因?yàn)?mdash;—發(fā)出這條錯(cuò)誤日志的節(jié)點(diǎn),對(duì)應(yīng)的 key 剛好沒(méi)有寫(xiě)進(jìn)去。
搜索代碼后,我們發(fā)現(xiàn) etcd 在進(jìn)行 apply 操作時(shí),如果開(kāi)啟了鑒權(quán),在鑒權(quán)時(shí)會(huì)判斷 raft 請(qǐng)求 header 中的 AuthRevision,如果請(qǐng)求中的 AuthRevision 小于當(dāng)前 node 的AuthRevision,則會(huì)認(rèn)為 AuthRevision 太老而導(dǎo)致 Apply 失敗。
- func (as *authStore) isOpPermitted(userName string, revision uint64, key, rangeEnd []byte, permTyp authpb.Permission_Type) error {
- // ...
- if revision < as.Revision() {
- return ErrAuthOldRevision
- }
- // ...
- }
這樣看來(lái),很可能是不同節(jié)點(diǎn)之間的 AuthRevision 不一致了,AuthRevision 是 etcd 啟動(dòng)時(shí)直接從 db 讀取的,每次變更后也會(huì)及時(shí)的寫(xiě)入 db,于是我們簡(jiǎn)單修改了下 etcd-dump-db工具,將每個(gè)節(jié)點(diǎn) db 內(nèi)存儲(chǔ)的 AuthRevision 解碼出來(lái)對(duì)比了下,發(fā)現(xiàn) 3 個(gè)節(jié)點(diǎn)的 AuthRevision 確實(shí)不一致,node1 的 AuthRevision 最高,node3 的 AuthRevision 最低,這正好能夠解釋之前的現(xiàn)象,endpoint 指定為 node1 寫(xiě)入的數(shù)據(jù),3 個(gè)節(jié)點(diǎn)都能查到,指定為 node3 寫(xiě)入的數(shù)據(jù),只有 node3 能夠查到,因?yàn)?AuthRevision 較低的節(jié)點(diǎn)發(fā)起的 Raft 請(qǐng)求,會(huì)被 AuthRevision 較高的節(jié)點(diǎn)在 Apply 的過(guò)程中丟棄掉(如下表)。
源碼之前,了無(wú)秘密?
目前為止我們已經(jīng)可以明確,新寫(xiě)入的數(shù)據(jù)通過(guò)訪問(wèn)某些 endpoint 查不出來(lái)的原因是由于 AuthRevision 不一致。但是,數(shù)據(jù)最開(kāi)始發(fā)生不一致問(wèn)題是否是由 AuthRevision 造成,還暫時(shí)不能斷定。為什么這么說(shuō)呢?因?yàn)?AuthRevision 很可能也是受害者,比如 AuthRevision 和數(shù)據(jù)的不一致都是由同一個(gè)原因?qū)е碌?,只不過(guò)是 AuthRevision 的不一致放大了數(shù)據(jù)不一致的問(wèn)題。但是,為更進(jìn)一步接近真相,我們先假設(shè) AuthRevision 就是導(dǎo)致數(shù)據(jù)不一致的罪魁禍?zhǔn)祝M(jìn)而找出導(dǎo)致 AuthRevision 不一致的真實(shí)原因。
原因到底如何去找呢?正所謂,源碼之前了無(wú)秘密,我們首先想到了分析代碼。于是,我們走讀了一遍 Auth 操作相關(guān)的代碼(如下),發(fā)現(xiàn)只有在進(jìn)行權(quán)限相關(guān)的寫(xiě)操作(如增刪用戶/角色,為角色授權(quán)等操作)時(shí),AuthRevision 才會(huì)增加。AuthRevision 增加后,會(huì)和寫(xiě)權(quán)限操作一起,寫(xiě)入 backend 緩存,當(dāng)寫(xiě)操作超過(guò)一定閾值(默認(rèn) 10000 條記錄)或者每隔100ms(默認(rèn)值),會(huì)執(zhí)行刷盤(pán)操作寫(xiě)入 db。由于 AuthRevision 的持久化和創(chuàng)建用戶等操作的持久化放在一個(gè)事務(wù)內(nèi),因此基本不會(huì)存在創(chuàng)建用戶成功了,而 AuthRevision 沒(méi)有正常增加的情況。
- func (as *authStore) UserAdd(r *pb.AuthUserAddRequest) (*pb.AuthUserAddResponse, error) {
- // ...
- tx := as.be.BatchTx()
- tx.Lock()
- defer tx.Unlock() // Unlock時(shí)滿足條件會(huì)觸發(fā)commit操作
- // ...
- putUser(tx, newUser)
- as.commitRevision(tx)
- return &pb.AuthUserAddResponse{}, nil
- }
- func (t *batchTxBuffered) Unlock() {
- if t.pending != 0 {
- t.backend.readTx.Lock() // blocks txReadBuffer for writing.
- t.buf.writeback(&t.backend.readTx.buf)
- t.backend.readTx.Unlock()
- if t.pending >= t.backend.batchLimit {
- t.commit(false)
- }
- }
- t.batchTx.Unlock()
- }
那么,既然 3 個(gè)節(jié)點(diǎn)的 AuthRevision 不一致,會(huì)不會(huì)是因?yàn)槟承┕?jié)點(diǎn)寫(xiě)權(quán)限相關(guān)的操作丟失了,從而沒(méi)有寫(xiě)入 db ?如果該猜測(cè)成立,3 個(gè)節(jié)點(diǎn)的 db 里 authUser 和 authRole 的 bucket 內(nèi)容應(yīng)該有所不同才對(duì)。于是為進(jìn)一步驗(yàn)證,我們繼續(xù)修改了下 etcd-dump-db 這個(gè)工具,加入了對(duì)比不同 db 文件 bucket 內(nèi)容的功能。遺憾的是,通過(guò)對(duì)比發(fā)現(xiàn),3 個(gè)節(jié)點(diǎn)之間的 authUser 和 authRole bucket 的內(nèi)容并沒(méi)有什么不同。
既然節(jié)點(diǎn)寫(xiě)權(quán)限相關(guān)的操作沒(méi)有丟,那會(huì)不會(huì)是命令重復(fù)執(zhí)行了呢?查看異常時(shí)間段內(nèi)日志時(shí)發(fā)現(xiàn),其中包含了較多的 auth 操作;進(jìn)一步分別比對(duì) 3 個(gè)節(jié)點(diǎn)的 auth 操作相關(guān)的日志又發(fā)現(xiàn),部分節(jié)點(diǎn)日志較多,而部分節(jié)點(diǎn)日志較少,看起來(lái)像是存在命令重復(fù)執(zhí)行現(xiàn)象。由于日志壓縮,雖然暫時(shí)還不能確定是重復(fù)執(zhí)行還是操作丟失,但是這些信息能夠?yàn)槲覀兒罄m(xù)的排查帶來(lái)很大啟發(fā)。
我們繼續(xù)觀察發(fā)現(xiàn),不同節(jié)點(diǎn)之間的 AuthRevison雖有差異,但是差異較小,而且差異值在我們壓測(cè)期間沒(méi)有變過(guò)。既然不同節(jié)點(diǎn)之間的 AuthRevision 差異值沒(méi)有進(jìn)一步放大,那么通過(guò)新增的日志基本上也看不出什么問(wèn)題,因?yàn)椴灰恢卢F(xiàn)象的出現(xiàn)很可能是在過(guò)去的某個(gè)時(shí)間點(diǎn)瞬時(shí)造成的。這就造成我們?nèi)绻胍l(fā)現(xiàn)問(wèn)題根因,還是要能夠復(fù)現(xiàn) AuthRevison 不一致或者數(shù)據(jù)不一致問(wèn)題才行,并且要能夠抓到復(fù)現(xiàn)瞬間的現(xiàn)場(chǎng)。
問(wèn)題似乎又回到了原點(diǎn),但好在我們目前已經(jīng)排除了很多干擾信息,將目標(biāo)聚焦在了 auth 操作上。
混沌工程,成功復(fù)現(xiàn)
鑒于之前多次手動(dòng)模擬各種場(chǎng)景都沒(méi)能成功復(fù)現(xiàn),我們打算搞一套自動(dòng)化的壓測(cè)方案來(lái)復(fù)現(xiàn)這個(gè)問(wèn)題,方案制定時(shí)主要考慮的點(diǎn)有以下幾個(gè):
- 如何增大復(fù)現(xiàn)的概率?
根據(jù)之前的排查結(jié)果,很有可能是 auth 操作導(dǎo)致的數(shù)據(jù)不一致,因此我們實(shí)現(xiàn)了一個(gè) monkey 腳本,每隔一段時(shí)間,會(huì)向集群寫(xiě)入隨機(jī)的用戶、角色,并向角色授權(quán),同時(shí)進(jìn)行寫(xiě)數(shù)據(jù)操作,以及隨機(jī)的重啟集群中的節(jié)點(diǎn),詳細(xì)記錄每次一操作的時(shí)間點(diǎn)和執(zhí)行日志。
- 怎樣保證在復(fù)現(xiàn)的情況下,能夠盡可能的定位到問(wèn)題的根因?
根據(jù)之前的分析得出,問(wèn)題根因大概率是 apply 過(guò)程中出了問(wèn)題,于是我們?cè)?apply 的流程里加入了詳細(xì)的日志,并打印了每次 apply 操作committedIndex、appliedIndex、consistentIndex 等信息。
- 如果復(fù)現(xiàn)成功,如何能夠在第一時(shí)間發(fā)現(xiàn)?
由于日志量太大,只有第一時(shí)間發(fā)現(xiàn)問(wèn)題,才能夠更精確的縮小問(wèn)題范圍,才能更利于我們定位問(wèn)題。于是我們實(shí)現(xiàn)了一個(gè)簡(jiǎn)單的 metric-server,每隔一分鐘拉取各個(gè)節(jié)點(diǎn)的 key 數(shù)量,并進(jìn)行對(duì)比,將差異值暴露為 metric,通過(guò) prometheus 進(jìn)行拉取,并用 grafana 進(jìn)行展示,一旦差異值超過(guò)一定閾值(寫(xiě)入數(shù)據(jù)量大的情況下,就算并發(fā)統(tǒng)計(jì)各個(gè)節(jié)點(diǎn)的 key 數(shù)量,也可能會(huì)有少量的差異,所以這里有一個(gè)容忍誤差),則立刻通過(guò)統(tǒng)一告警平臺(tái)向我們推送告警,以便于及時(shí)發(fā)現(xiàn)。
方案搞好后,我們新建了一套 etcd 集群,部署了我們的壓測(cè)方案,打算進(jìn)行長(zhǎng)期觀察。結(jié)果第二天中午,我們就收到了微信告警——集群中存在數(shù)據(jù)不一致現(xiàn)象。
于是,我們立刻登錄壓測(cè)機(jī)器進(jìn)行分析,首先停掉了壓測(cè)腳本,然后查看了集群中各個(gè)節(jié)點(diǎn)的 AuthRevision,發(fā)現(xiàn) 3 個(gè)節(jié)點(diǎn)的 AuthRevision 果然不一樣!根據(jù) grafana 監(jiān)控面板上的監(jiān)控?cái)?shù)據(jù),我們將數(shù)據(jù)不一致出現(xiàn)的時(shí)間范圍縮小到了 10 分鐘內(nèi),然后重點(diǎn)分析了下這 10 分鐘的日志,發(fā)現(xiàn)在某個(gè)節(jié)點(diǎn)重啟后,consistentIndex 的值比重啟前要小。然而 etcd 的所有 apply 操作,冪等性都依賴 consistentIndex 來(lái)保證,當(dāng)進(jìn)行 apply 操作時(shí),會(huì)判斷當(dāng)前要 apply 的 Entry 的 Index 是否大于 consistentIndex,如果 Index 大于 consistentIndex,則會(huì)將 consistentIndex 設(shè)為 Index,并允許該條記錄被 apply。否則,則認(rèn)為該請(qǐng)求被重復(fù)執(zhí)行了,不會(huì)進(jìn)行實(shí)際的 apply 操作。
- // applyEntryNormal apples an EntryNormal type raftpb request to the EtcdServer
- func (s *EtcdServer) applyEntryNormal(e *raftpb.Entry) {
- shouldApplyV3 := false
- if e.Index > s.consistIndex.ConsistentIndex() {
- // set the consistent index of current executing entry
- s.consistIndex.setConsistentIndex(e.Index)
- shouldApplyV3 = true
- }
- // ...
- // do not re-apply applied entries.
- if !shouldApplyV3 {
- return
- }
- // ...
- }
也就是說(shuō),由于 consistentIndex 的減小,etcd 本身依賴它的冪等操作將變得不再冪等,導(dǎo)致權(quán)限相關(guān)的操作在 etcd 重啟后被重復(fù) apply 了,即一共apply 了兩次!
問(wèn)題原理分析
為何 consistentIndex 會(huì)減小?走讀了 consistentIndex 相關(guān)代碼后,我們終于發(fā)現(xiàn)了問(wèn)題的根因:consistentIndex 本身的持久化,依賴于 mvcc 的寫(xiě)數(shù)據(jù)操作;通過(guò) mvcc 寫(xiě)入數(shù)據(jù)時(shí),會(huì)調(diào)用 saveIndex 來(lái)持久化 consistentIndex 到 backend,而 auth 相關(guān)的操作,是直接讀寫(xiě)的 backend,并沒(méi)有經(jīng)過(guò) mvcc。這就導(dǎo)致,如果做了權(quán)限相關(guān)的寫(xiě)操作,并且之后沒(méi)有通過(guò) mvcc 寫(xiě)入數(shù)據(jù),那么這期間 consistentIndex 將不會(huì)被持久化,如果這時(shí)候重啟了 etcd,就會(huì)造成權(quán)限相關(guān)的寫(xiě)操作被 apply 兩次,帶來(lái)的副作用可能會(huì)導(dǎo)致 AuthRevision 重復(fù)增加,從而直接造成不同節(jié)點(diǎn)的 AuthRevision 不一致,而 AuthRevision 不一致又會(huì)造成數(shù)據(jù)不一致。
- func putUser(lg *zap.Logger, tx backend.BatchTx, user *authpb.User) {
- b, err := user.Marshal()
- tx.UnsafePut(authUsersBucketName, user.Name, b) // 直接寫(xiě)入Backend,未經(jīng)過(guò)MVCC,此時(shí)不會(huì)持久化consistentIndex
- }
- func (tw *storeTxnWrite) End() {
- // only update index if the txn modifies the mvcc state.
- if len(tw.changes) != 0 {
- tw.s.saveIndex(tw.tx) // 當(dāng)通過(guò)MVCC寫(xiě)數(shù)據(jù)時(shí),會(huì)觸發(fā)consistentIndex持久化
- tw.s.revMu.Lock()
- tw.s.currentRev++
- }
- tw.tx.Unlock()
- if len(tw.changes) != 0 {
- tw.s.revMu.Unlock()
- }
- tw.s.mu.RUnlock()
- }
再回過(guò)頭來(lái),為什么數(shù)據(jù)不一致了還可以讀出來(lái),而且讀出來(lái)的數(shù)據(jù)還可能不一樣?etcd 不是使用了 raft 算法嗎,難道不能夠保證強(qiáng)一致性嗎?其實(shí)這和 etcd 本身的讀操作實(shí)現(xiàn)有關(guān)。上邊我們已經(jīng)講過(guò),etcd 為了提升讀數(shù)據(jù)的性能,使用了 ReadIndex 操作來(lái)實(shí)現(xiàn)從當(dāng)前節(jié)點(diǎn)讀取數(shù)據(jù),而不是每次都從 leader 讀。而影響 ReadIndex 操作的,一個(gè)是 leader 節(jié)點(diǎn)的 CommittedIndex,一個(gè)是當(dāng)前節(jié)點(diǎn)的 AppliedIndex,etcd 在 apply 過(guò)程中,無(wú)論 apply 是否成功,都會(huì)更新 AppliedIndex,這就造成,雖然當(dāng)前節(jié)點(diǎn) apply 失敗了,但讀操作在判斷的時(shí)候,并不會(huì)感知到這個(gè)失敗,從而導(dǎo)致某些節(jié)點(diǎn)可能讀不出來(lái)數(shù)據(jù);而且 etcd 支持多版本并發(fā)控制,同一個(gè) key 可以存在多個(gè)版本的數(shù)據(jù),apply 失敗可能只是更新某個(gè)版本的數(shù)據(jù)失敗,這就造成不同節(jié)點(diǎn)之間最新的數(shù)據(jù)版本不一致,導(dǎo)致讀出不一樣的數(shù)據(jù)。
影響范圍
該問(wèn)題從 2016 年引入,所有開(kāi)啟鑒權(quán)的 etcd3 集群都會(huì)受到影響,在特定場(chǎng)景下,會(huì)導(dǎo)致 etcd 集群多個(gè)節(jié)點(diǎn)之間的數(shù)據(jù)不一致,并且 etcd 對(duì)外表現(xiàn)還可以正常讀寫(xiě),日志無(wú)明顯報(bào)錯(cuò)。
觸發(fā)條件
- 使用的為 etcd3 集群,并且開(kāi)啟了鑒權(quán)。
- etcd 集群中節(jié)點(diǎn)發(fā)生重啟。
- 節(jié)點(diǎn)重啟之前,有 grant-permission 操作(或短時(shí)間內(nèi)對(duì)同一個(gè)權(quán)限操作連續(xù)多次增刪),且操作之后重啟之前無(wú)其他數(shù)據(jù)寫(xiě)入。
- 通過(guò)非重啟節(jié)點(diǎn)向集群發(fā)起寫(xiě)數(shù)據(jù)請(qǐng)求。
修復(fù)方案
了解了問(wèn)題的根因,修復(fù)方案就比較明確了,我們只需要在 auth 操作調(diào)用 commitRevision 后,觸發(fā) consistentIndex 的持久化操作,就能夠保證 etcd 在重啟的時(shí)候 consistentIndex 的本身的正確性,從而保證 auth 操作的冪等性。具體的修復(fù)方式我們已經(jīng)向 etcd 社區(qū)提交了 PR #11652,目前這個(gè)特性已經(jīng) backport 到 3.4,3.3 等版本,將會(huì)在最近一個(gè) release 更新。
那么如果數(shù)據(jù)已經(jīng)不一致了怎么辦,有辦法恢復(fù)嗎?在 etcd 進(jìn)程沒(méi)有頻繁重啟的情況下,可以先找到 authRevision 最小的節(jié)點(diǎn),它的數(shù)據(jù)應(yīng)該是最全的,然后利用 etcd 的 move-leader 命令,將 leader 轉(zhuǎn)移到這個(gè)節(jié)點(diǎn),再依次將其他節(jié)點(diǎn)移出集群,備份并刪除數(shù)據(jù)目錄,然后將節(jié)點(diǎn)重新加進(jìn)來(lái),此時(shí)它會(huì)從 leader 同步一份最新的數(shù)據(jù),這樣就可以使集群其他節(jié)點(diǎn)的數(shù)據(jù)都和 leader 保持一致,即最大可能地不丟數(shù)據(jù)。
升級(jí)建議
需要注意的是,升級(jí)有風(fēng)險(xiǎn),新版本雖然解決了這個(gè)問(wèn)題,但由于升級(jí)過(guò)程中需要重啟 etcd,這個(gè)重啟過(guò)程仍可能觸發(fā)這個(gè) bug。因此升級(jí)修復(fù)版本前建議停止寫(xiě)權(quán)限相關(guān)操作,并且手動(dòng)觸發(fā)一次寫(xiě)數(shù)據(jù)操作之后再重啟節(jié)點(diǎn),避免因?yàn)樯?jí)造成問(wèn)題。
另外,不建議直接跨大版本升級(jí),例如從 etcd3.2 → etcd3.3。大版本升級(jí)有一定的風(fēng)險(xiǎn),需謹(jǐn)慎測(cè)試評(píng)估,我們之前發(fā)現(xiàn)過(guò)由 lease 和 auth 引起的另一個(gè)不一致問(wèn)題,具體可見(jiàn) issue #11689,以及相關(guān) PR #11691。
問(wèn)題總結(jié)
導(dǎo)致該問(wèn)題的直接原因,是由于 consistentIndex 在進(jìn)行權(quán)限相關(guān)操作時(shí)未持久化,從而導(dǎo)致 auth 相關(guān)的操作不冪等,造成了數(shù)據(jù)的不一致。
而造成 auth 模塊未持久化 consistentIndex 的一個(gè)因素,是因?yàn)?consistentIndex 目前是在 mvcc 模塊實(shí)現(xiàn)的,并未對(duì)外暴露持久化接口,只能通過(guò)間接的方式來(lái)調(diào)用,很容易漏掉。為了優(yōu)化這個(gè)問(wèn)題,我們重構(gòu)了 consistentIndex 相關(guān)操作,將它獨(dú)立為一個(gè)單獨(dú)的模塊,其他依賴它的模塊可以直接調(diào)用,一定程度上可以避免將來(lái)再出現(xiàn)類似問(wèn)題,具體見(jiàn) PR #11699。
另一方面,etcd 的 apply 操作本身是個(gè)異步流程,而且失敗之后沒(méi)有打印任何錯(cuò)誤日志,很大程度上增加了排障的難度,因此我們后邊也向社區(qū)提交了相關(guān) PR #11670,來(lái)優(yōu)化 apply 失敗時(shí)的日志打印,便于定位問(wèn)題。
造成問(wèn)題定位困難的另一個(gè)原因,是 auth revision 目前沒(méi)有對(duì)外暴露 metric 或者 api,每次查詢只能通過(guò) etcd-dump-db 工具來(lái)直接從 db 獲取,為方便 debug,我們也增加了相關(guān)的 metric 和 status api,增強(qiáng)了 auth revision 的可觀測(cè)性和可測(cè)試性。
相關(guān) PR/issue 查看地址
PR #11652 :https://github.com/etcd-io/etcd/pull/11652
issue #11689:https://github.com/etcd-io/etcd/issues/11689
PR #11691:https://github.com/etcd-io/etcd/pull/11691
PR #11699 :https://github.com/etcd-io/etcd/pull/11699
PR #11670 :https://github.com/etcd-io/etcd/pull/11670
metric :https://github.com/etcd-io/etcd/pull/11652/commits/f14d2a087f7b0fd6f7980b95b5e0b945109c95f3
status api :https://github.com/etcd-io/etcd/pull/11659
參考資料
etcd 源碼:https://github.com/etcd-io/etcd
etcd 存儲(chǔ)實(shí)現(xiàn):https://www.codedump.info/post/20181125-etcd-server/
高可用分布存儲(chǔ) etcd 的實(shí)現(xiàn)原理:https://draveness.me/etcd-introduction/
etcd raft 設(shè)計(jì)與實(shí)現(xiàn):https://zhuanlan.zhihu.com/p/51063866,https://zhuanlan.zhihu.com/p/51065416