问题背景
诡异的 K8S 滚动更新异样
笔者某天收到共事反馈,测试环境中 K8S 集群进行滚动更新公布时未失效。通过 kube-apiserver 查看发现,对应的 Deployment 版本曾经是最新版,然而这个最新版本的 Pod 并未创立进去。
针对该景象,咱们最开始猜想可能是 kube-controller-manager 的 bug 导致,然而察看 controller-manager 日志并未发现显著异样。第一次调高 controller-manager 的日志等级并进行重启操作之后,仿佛因为 controller-manager 并没有 watch 到这个更新事件,咱们依然没有发现问题所在。此时,察看 kube-apiserver 日志,同样也没有呈现显著异样。
于是,再次调高日志等级并重启 kube-apiserver,诡异的事件产生了,之前的 Deployment 失常滚动更新了!
etcd 数据不统一?
因为从 kube-apiserver 的日志中同样无奈提取出可能帮忙解决问题的有用信息,起初咱们只能猜想可能是 kube-apiserver 的缓存更新异样导致的。正当咱们要从这个切入点去解决问题时,该共事反馈了一个更诡异的问题——本人新创建的 Pod,通过 kubectl 查问 Pod 列表,忽然隐没了!纳尼?这是什么骚操作?通过咱们屡次测试查问发现,通过 kubectl 来 list pod 列表,该 pod 有时候能查到,有时候查不到。那么问题来了,K8s api 的 list 操作是没有缓存的,数据是 kube-apiserver 间接从 etcd 拉取返回给客户端的,难道是 etcd 自身出了问题?
家喻户晓,etcd 自身是一个强一致性的 KV 存储,在写操作胜利的状况下,两次读申请不应该读取到不一样的数据。怀着不信邪的态度,咱们通过 etcdctl 间接查问了 etcd 集群状态和集群数据,返回结果显示 3 个节点状态都失常,且 RaftIndex 统一,察看 etcd 的日志也并未发现报错信息,惟一可疑的中央是 3 个节点的 dbsize 差异较大。接着,咱们又将 client 拜访的 endpoint 指定为不同节点地址来查问每个节点的 key 的数量,后果发现 3 个节点返回的 key 的数量不统一,甚至两个不同节点上 Key 的数量差最大可达到几千!而间接通过 etcdctl 查问方才创立的 Pod,发现拜访某些 endpoint 可能查问到该 pod,而拜访其余 endpoint 则查不到。至此,根本能够确定 etcd 集群的节点之间的确存在数据不统一景象。
问题剖析和排查过程
遇事不决问 Google
强一致性的存储忽然数据不统一了,这么重大的问题,想必日志里必定会有所体现。然而,可能是 etcd 开发者放心日志太多会影响性能的缘故,etcd 的日志打印的比拟少,以至于咱们排查了 etcd 各个节点的日志,也没有发现有用的报错日志。甚至是在咱们调高日志级别之后,仍没有发现异常信息。
作为一个 21 世纪的程序员,遇到这种诡异且临时没脉络的问题,第一反馈当然是先 Google 一下啦,毕竟不会 StackOverFlow 的程序员不是好运维!Google 输出“etcd data inconsistent”搜寻发现,并不是只有咱们遇到过该问题,之前也有其他人向 etcd 社区反馈过相似问题,只是苦于没有提供稳固的复现形式,最初都不了了之。如 issue:
https://github.com/etcd-io/et…
https://github.com/etcd-io/et…
https://github.com/etcd-io/et…
https://github.com/etcd-io/et…
因为这个问题比较严重,会影响到数据的一致性,而咱们生产环境中以后应用了数百套 etcd 集群,为了避免出现相似问题,咱们决定深刻定位一番。
etcd 工作原理和术语简介
在开始之前,为不便读者了解,这里先简略介绍下 etcd 的罕用术语和根本读写原理。
术语表:
etcd 是一个强一致性的分布式 KV 存储,所谓强一致性,简略来说就是一个写操作胜利后,从任何一个节点读出来的数据都是最新值,而不会呈现写数据胜利后读不进去或者读到旧数据的状况。etcd 通过 raft 协定来实现 leader 选举、配置变更以及保证数据读写的一致性。上面简略介绍下 etcd 的读写流程:
写数据流程(以 leader 节点为例,见上图):
- etcd 任一节点的 etcd server 模块收到 Client 写申请(如果是 follower 节点,会先通过 Raft 模块将申请转发至 leader 节点解决)。
- etcd server 将申请封装为 Raft 申请,而后提交给 Raft 模块解决。
- leader 通过 Raft 协定与集群中 follower 节点进行交互,将音讯复制到 follower 节点,于此同时,并行将日志长久化到 WAL。
- follower 节点对该申请进行响应,回复本人是否批准该申请。
- 当集群中超过半数节点((n/2)+1 members)批准接管这条日志数据时,示意该申请能够被 Commit,Raft 模块告诉 etcd server 该日志数据曾经 Commit,能够进行 Apply。
- 各个节点的 etcd server 的 applierV3 模块异步进行 Apply 操作,并通过 MVCC 模块写入后端存储 BoltDB。
- 当 client 所连贯的节点数据 apply 胜利后,会返回给客户端 apply 的后果。
读数据流程:
- etcd 任一节点的 etcd server 模块收到客户端读申请(Range 申请)
- 判断读申请类型,如果是串行化读(serializable)则间接进入 Apply 流程
- 如果是线性一致性读(linearizable),则进入 Raft 模块
- Raft 模块向 leader 收回 ReadIndex 申请,获取以后集群曾经提交的最新数据 Index
- 期待本地 AppliedIndex 大于或等于 ReadIndex 获取的 CommittedIndex 时,进入 Apply 流程
- Apply 流程:通过 Key 名从 KV Index 模块获取 Key 最新的 Revision,再通过 Revision 从 BoltDB 获取对应的 Key 和 Value。
初步验证
通常集群失常运行状况下,如果没有内部变更的话,个别不会呈现这么重大的问题。咱们查问故障 etcd 集群近几天的公布记录时发现,故障前一天对该集群进行的一次公布中,因为之前 dbsize 配置不合理,导致 db 被写满,集群无奈写入新的数据,为此运维人员更新了集群 dbsize 和 compaction 相干配置,并重启了 etcd。重启后,运维同学持续对 etcd 手动执行了 compact 和 defrag 操作,来压缩 db 空间。
通过上述场景,咱们能够初步判断出以下几个可疑的触发条件:
- dbsize 满
- dbsize 和 compaction 配置更新
- compaction 操作和 defrag 操作
- 重启 etcd
出了问题必定要可能复现才更有利于解决问题,正所谓可能复现的 bug 就不叫 bug。复现问题之前,咱们通过剖析 etcd 社区之前的相干 issue 发现,触发该 bug 的独特条件都蕴含执行过 compaction 和 defrag 操作,同时重启过 etcd 节点。因而,咱们打算首先尝试同时模仿这几个操作,察看是否可能在新的环境中复现。为此咱们新建了一个集群,而后通过编写脚本向集群中不停的写入和删除数据,直到 dbsize 达到肯定水平后,对节点顺次进行配置更新和重启,并触发 compaction 和 defrag 操作。然而通过屡次尝试,咱们并没有复现出相似于上述数据不统一的场景。
抽丝剥茧,初现端倪
紧接着,在之后的测试中无心发现,client 指定不同的 endpoint 写数据,可能查到数据的节点也不同。比方,endpoint 指定为 node1 进行写数据,3 个节点都能够查到数据;endpoint 指定为 node2 进行写数据,node2 和 node3 能够查到;endpoint 指定为 node3 写数据,只有 node3 本人可能查到。具体情况如下表:
于是咱们做出了初步的猜想,有以下几种可能:
- 集群可能决裂了,leader 未将音讯发送给 follower 节点。
- leader 给 follower 节点发送了音讯,然而 log 异样,没有对应的 command。
- leader 给 follower 节点发送了音讯,有对应的 command,然而 apply 异样,操作还未到 KV Index 和 boltdb 就异样了。
- leader 给 follower 节点发送了音讯, 有对应的 command,然而 apply 异样,KV Index 呈现了问题。
- leader 给 follower 节点发送了音讯, 有对应的 command,然而 apply 异样,boltdb 呈现了问题。
为了验证咱们的猜想,咱们进行了一系列测试来放大问题范畴:
首先,咱们通过 endpoint status 查看集群信息,发现 3 个节点的 clusterId,leader,raftTerm,raftIndex 信息均统一,而 dbSize 大小和 revision 信息不统一。clusterId 和 leader 统一,根本 排除了集群决裂的猜想 ,而 raftTerm 和 raftIndex 统一,阐明 leader 是有向 follower 同步音讯的,也 进一步排除了第一个猜想,然而 WAL 落盘有没有异样还不确定。dbSize 和 revision 不统一则进一步阐明了 3 个节点数据曾经产生不统一了。
其次,因为 etcd 自身提供了一些 dump 工具,例如 etcd-dump-log 和 etcd-dump-db。咱们能够像下图一样,应用 etcd-dump-log dump 出指定 WAL 文件的内容,应用 etcd-dump-db dump 出 db 文件的数据,不便对 WAL 和 db 数据进行剖析。
于是,咱们向 node3 写了一条便于辨别的数据,而后通过 etcd-dump-log 来剖析 3 个节点的 WAL,依照方才的测试,endpoint 指定为 node3 写入的数据,通过其余两个节点应该查不到的。然而咱们发现 3 个节点都收到了 WAL log,也就是说 WAL 并没有丢,因而 排除了第二个猜想。
接下来咱们 dump 了 db 的数据进行剖析,发现 endpoint 指定为 node3 写入的数据,在其余两个节点的 db 文件里找不到,也就是说数据的确没有落到 db,而不是写进去了查不进去。
既然 WAL 里有而 db 里没有,因而很大可能是 apply 流程异样了,数据可能在 apply 时被抛弃了。
因为现有日志无奈提供更无效的信息,咱们打算在 etcd 里新加一些日志来更好地帮忙咱们定位问题。etcd 在做 apply 操作时,trace 日志会打印超过每个超过 100ms 的申请,咱们首先把 100ms 这个阈值调低,调整到 1ns,这样每个 apply 的申请都可能记录下来,能够更好的帮忙咱们定位问题。
编译好新版本之后,咱们替换了其中一个 etcd 节点,而后向不同 node 发动写申请测试。果然,咱们发现了一条不同寻常的谬误日志:”error”:”auth:revision in header is old”,因而咱们判定问题很可能是因为——收回这条谬误日志的节点,对应的 key 刚好没有写进去。
搜寻代码后,咱们发现 etcd 在进行 apply 操作时,如果开启了鉴权,在鉴权时会判断 raft 申请 header 中的 AuthRevision,如果申请中的 AuthRevision 小于以后 node 的 AuthRevision,则会认为 AuthRevision 太老而导致 Apply 失败。
func (as *authStore) isOpPermitted(userName string, revision uint64, key, rangeEnd []byte, permTyp authpb.Permission_Type) error {// ... if revision < as.Revision() {return ErrAuthOldRevision} // ...}
这样看来,很可能是不同节点之间的 AuthRevision 不统一了,AuthRevision 是 etcd 启动时间接从 db 读取的,每次变更后也会及时的写入 db,于是咱们简略批改了下 etcd-dump-db 工具,将每个节点 db 内存储的 AuthRevision 解码进去比照了下,发现 3 个节点的 AuthRevision 的确不统一,node1 的 AuthRevision 最高,node3 的 AuthRevision 最低,这正好可能解释之前的景象,endpoint 指定为 node1 写入的数据,3 个节点都能查到,指定为 node3 写入的数据,只有 node3 可能查到,因为 AuthRevision 较低的节点发动的 Raft 申请,会被 AuthRevision 较高的节点在 Apply 的过程中抛弃掉(如下表)。
源码之前,了无机密?
目前为止咱们曾经能够明确,新写入的数据通过拜访某些 endpoint 查不进去的起因是因为 AuthRevision 不统一。然而,数据最开始产生不统一问题是否是由 AuthRevision 造成,还临时不能判定。为什么这么说呢?因为 AuthRevision 很可能也是受害者,比方 AuthRevision 和数据的不统一都是由同一个起因导致的,只不过是 AuthRevision 的不统一放大了数据不统一的问题。然而,为更进一步靠近假相,咱们先假如 AuthRevision 就是导致数据不统一的罪魁祸首,进而找出导致 AuthRevision 不统一的实在起因。
起因到底如何去找呢?正所谓,源码之前了无机密,咱们首先想到了剖析代码。于是,咱们走读了一遍 Auth 操作相干的代码(如下),发现只有在进行权限相干的写操作(如增删用户 / 角色,为角色受权等操作)时,AuthRevision 才会减少。AuthRevision 减少后,会和写权限操作一起,写入 backend 缓存,当写操作超过肯定阈值(默认 10000 条记录)或者每隔 100ms(默认值),会执行刷盘操作写入 db。因为 AuthRevision 的长久化和创立用户等操作的长久化放在一个事务内,因而根本不会存在创立用户胜利了,而 AuthRevision 没有失常减少的状况。
func (as *authStore) UserAdd(r *pb.AuthUserAddRequest) (*pb.AuthUserAddResponse, error) {// ... tx := as.be.BatchTx() tx.Lock() defer tx.Unlock() // Unlock 时满足条件会触发 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 个节点的 AuthRevision 不统一,会不会是因为某些节点写权限相干的操作失落了,从而没有写入 db?如果该猜想成立,3 个节点的 db 里 authUser 和 authRole 的 bucket 内容应该有所不同才对。于是为进一步验证,咱们持续批改了下 etcd-dump-db 这个工具,退出了比照不同 db 文件 bucket 内容的性能。遗憾的是,通过比照发现,3 个节点之间的 authUser 和 authRole bucket 的内容并没有什么不同。
既然节点写权限相干的操作没有丢,那会不会是命令反复执行了呢?查看异样时间段内日志时发现,其中蕴含了较多的 auth 操作;进一步别离比对 3 个节点的 auth 操作相干的日志又发现,局部节点日志较多,而局部节点日志较少,看起来像是存在命令反复执行景象。因为日志压缩,尽管临时还不能确定是反复执行还是操作失落,然而这些信息可能为咱们后续的排查带来很大启发。
咱们持续察看发现,不同节点之间的 AuthRevison 虽有差别,然而差别较小,而且差别值在咱们压测期间没有变过。既然不同节点之间的 AuthRevision 差别值没有进一步放大,那么通过新增的日志基本上也看不出什么问题,因为不统一景象的呈现很可能是在过来的某个工夫点刹时造成的。这就造成咱们如果想要发现问题根因,还是要可能复现 AuthRevison 不统一或者数据不统一问题才行,并且要可能抓到复现霎时的现场。
问题仿佛又回到了原点,但好在咱们目前曾经排除了很多烦扰信息,将指标聚焦在了 auth 操作上。
混沌工程,胜利复现
鉴于之前屡次手动模仿各种场景都没能胜利复现,咱们打算搞一套自动化的压测计划来复现这个问题,计划制订时次要思考的点有以下几个:
- 如何增大复现的概率?
依据之前的排查后果,很有可能是 auth 操作导致的数据不统一,因而咱们实现了一个 monkey 脚本,每隔一段时间,会向集群写入随机的用户、角色,并向角色受权,同时进行写数据操作,以及随机的重启集群中的节点,具体记录每次一操作的工夫点和执行日志。
- 怎么保障在复现的状况下,可能尽可能的定位到问题的根因?
依据之前的剖析得出,问题根因大概率是 apply 过程中出了问题,于是咱们在 apply 的流程里退出了具体的日志,并打印了每次 apply 操作 committedIndex、appliedIndex、consistentIndex 等信息。
- 如果复现胜利,如何可能在第一工夫发现?
因为日志量太大,只有第一工夫发现问题,才可能更准确的放大问题范畴,能力更利于咱们定位问题。于是咱们实现了一个简略的 metric-server,每隔一分钟拉取各个节点的 key 数量,并进行比照,将差别值裸露为 metric,通过 prometheus 进行拉取,并用 grafana 进行展现,一旦差别值超过肯定阈值(写入数据量大的状况下,就算并发统计各个节点的 key 数量,也可能会有大量的差别,所以这里有一个容忍误差),则立即通过对立告警平台向咱们推送告警,以便于及时发现。
计划搞好后,咱们新建了一套 etcd 集群,部署了咱们的压测计划,打算进行长期察看。后果第二天中午,咱们就收到了微信告警——集群中存在数据不统一景象。
于是,咱们立即登录压测机器进行剖析,首先停掉了压测脚本,而后查看了集群中各个节点的 AuthRevision,发现 3 个节点的 AuthRevision 果然不一样!依据 grafana 监控面板上的监控数据,咱们将数据不统一呈现的工夫范畴放大到了 10 分钟内,而后重点剖析了下这 10 分钟的日志,发现在某个节点重启后,consistentIndex 的值比重启前要小。然而 etcd 的所有 apply 操作,幂等性都依赖 consistentIndex 来保障,当进行 apply 操作时,会判断以后要 apply 的 Entry 的 Index 是否大于 consistentIndex,如果 Index 大于 consistentIndex,则会将 consistentIndex 设为 Index,并容许该条记录被 apply。否则,则认为该申请被反复执行了,不会进行理论的 apply 操作。
// applyEntryNormal apples an EntryNormal type raftpb request to the EtcdServerfunc (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} // ...}
也就是说,因为 consistentIndex 的减小,etcd 自身依赖它的幂等操作将变得不再幂等,导致权限相干的操作在 etcd 重启后被反复 apply 了,即一共 apply 了两次!
问题原理剖析
为何 consistentIndex 会减小?走读了 consistentIndex 相干代码后,咱们终于发现了问题的根因:consistentIndex 自身的长久化,依赖于 mvcc 的写数据操作;通过 mvcc 写入数据时,会调用 saveIndex 来长久化 consistentIndex 到 backend,而 auth 相干的操作,是间接读写的 backend,并没有通过 mvcc。这就导致,如果做了权限相干的写操作,并且之后没有通过 mvcc 写入数据,那么这期间 consistentIndex 将不会被长久化,如果这时候重启了 etcd,就会造成权限相干的写操作被 apply 两次,带来的副作用可能会导致 AuthRevision 反复减少,从而间接造成不同节点的 AuthRevision 不统一,而 AuthRevision 不统一又会造成数据不统一。
func putUser(lg *zap.Logger, tx backend.BatchTx, user *authpb.User) {b, err := user.Marshal() tx.UnsafePut(authUsersBucketName, user.Name, b) // 间接写入 Backend,未通过 MVCC,此时不会长久化 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) // 当通过 MVCC 写数据时,会触发 consistentIndex 长久化 tw.s.revMu.Lock() tw.s.currentRev++} tw.tx.Unlock() if len(tw.changes) != 0 {tw.s.revMu.Unlock() } tw.s.mu.RUnlock()}
再回过头来,为什么数据不统一了还能够读出来,而且读出来的数据还可能不一样?etcd 不是应用了 raft 算法吗,难道不可能保障强一致性吗?其实这和 etcd 自身的读操作实现无关。
而影响 ReadIndex 操作的,一个是 leader 节点的 CommittedIndex,一个是以后节点的 AppliedIndex,etcd 在 apply 过程中,无论 apply 是否胜利,都会更新 AppliedIndex,这就造成,尽管以后节点 apply 失败了,但读操作在判断的时候,并不会感知到这个失败,从而导致某些节点可能读不进去数据;而且 etcd 反对多版本并发管制,同一个 key 能够存在多个版本的数据,apply 失败可能只是更新某个版本的数据失败,这就造成不同节点之间最新的数据版本不统一,导致读出不一样的数据。
影响范畴
该问题从 2016 年引入,所有开启鉴权的 etcd3 集群都会受到影响,在特定场景下,会导致 etcd 集群多个节点之间的数据不统一,并且 etcd 对外体现还能够失常读写,日志无显著报错。
触发条件
- 应用的为 etcd3 集群,并且开启了鉴权。
- etcd 集群中节点产生重启。
- 节点重启之前,有 grant-permission 操作(或短时间内对同一个权限操作间断屡次增删),且操作之后重启之前无其余数据写入。
- 通过非重启节点向集群发动写数据申请。
修复计划
理解了问题的根因,修复计划就比拟明确了,咱们只须要在 auth 操作调用 commitRevision 后,触发 consistentIndex 的长久化操作,就可能保障 etcd 在重启的时候 consistentIndex 的自身的正确性,从而保障 auth 操作的幂等性。具体的修复形式咱们曾经向 etcd 社区提交了 PR #11652,目前这个个性曾经 backport 到 3.4,3.3 等版本,将会在最近一个 release 更新。
那么如果数据曾经不统一了怎么办,有方法复原吗?在 etcd 过程没有频繁重启的状况下,能够先找到 authRevision 最小的节点,它的数据应该是最全的,而后利用 etcd 的 move-leader 命令,将 leader 转移到这个节点,再顺次将其余节点移出集群,备份并删除数据目录,而后将节点从新加进来,此时它会从 leader 同步一份最新的数据,这样就能够使集群其余节点的数据都和 leader 保持一致,即最大可能地不丢数据。
降级倡议
须要留神的是,降级有危险,新版本尽管解决了这个问题,但因为降级过程中须要重启 etcd,这个重启过程仍可能触发这个 bug。因而降级修复版本前倡议进行写权限相干操作,并且手动触发一次写数据操作之后再重启节点,防止因为降级造成问题。
另外,不倡议间接跨大版本升级,例如从 etcd3.2 → etcd3.3。大版本升级有肯定的危险,需谨慎测试评估,咱们之前发现过由 lease 和 auth 引起的另一个不统一问题,具体可见 issue #11689,以及相干 PR #11691。
问题总结
导致该问题的间接起因,是因为 consistentIndex 在进行权限相干操作时未长久化,从而导致 auth 相干的操作不幂等,造成了数据的不统一。
而造成 auth 模块未长久化 consistentIndex 的一个因素,是因为 consistentIndex 目前是在 mvcc 模块实现的,并未对外裸露长久化接口,只能通过间接的形式来调用,很容易漏掉。为了优化这个问题,咱们重构了 consistentIndex 相干操作,将它独立为一个独自的模块,其余依赖它的模块能够间接调用,肯定水平上能够防止未来再呈现相似问题,具体见 PR #11699。
另一方面,etcd 的 apply 操作自身是个异步流程,而且失败之后没有打印任何谬误日志,很大水平上减少了排障的难度,因而咱们后边也向社区提交了相干 PR #11670,来优化 apply 失败时的日志打印,便于定位问题。
造成问题定位艰难的另一个起因,是 auth revision 目前没有对外裸露 metric 或者 api,每次查问只能通过 [etcd-dump-db 工具来间接从 db 获取,为不便 debug,咱们也减少了相干的
metric](https://github.com/etcd-io/et… 和 status api,加强了 auth revision 的可观测性和可测试性。
参考资料
- etcd 源码:https://github.com/etcd-io/et…
- 存储实现:https://www.codedump.info/pos…
- etcd 的实现原理:https://draveness.me/etcd-int…
- raft 设计与实现:https://zhuanlan.zhihu.com/p/…://zhuanlan.zhihu.com/p/51065416
致谢
感激在 PR 提交过程中,etcd 社区 jingyih,mitake 的热心帮忙和倡议!
【腾讯云原生】云说新品、云研新术、云游新活、云赏资讯,扫码关注同名公众号,及时获取更多干货!!