三年之久的 etcd3 数据不一致 bug 分析

问题背景

诡异的 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 集群的节点之间确实存在数据不一致现象。

问题分析和排查过程

遇事不决问搜素引擎

强一致性的存储忽然数据不一致了，这么严重的问题，想必日志里确定会有所体现。然而，多是 etcd 开发者担忧日志太多会影响性能的缘故，etcd 的日志打印的比较少，以致于咱们排查了 etcd 各个节点的日志，也没有发现有用的报错日志。甚至是在咱们调高日志级别以后，仍没有发现异常信息。

做为一个21世纪的程序员，遇到这种诡异且暂时没头绪的问题，第一反应固然是先搜索一下啦，毕竟不会 StackOverFlow 的程序员不是好运维！搜索框输入“etcd data inconsistent” 搜索发现，并非只有咱们遇到过该问题，以前也有其余人向 etcd 社区反馈过相似问题，只是苦于没有提供稳定的复现方式，最后都不了了之。如 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

因为这个问题比较严重，会影响到数据的一致性，而咱们生产环境中当前使用了数百套 etcd 集群，为了不出现相似问题，咱们决定深刻定位一番。

etcd 工做原理和术语简介

在开始以前，为方便读者理解，这里先简单介绍下 etcd 的经常使用术语和基本读写原理。

术语表：

etcd 是一个强一致性的分布式 KV 存储，所谓强一致性，简单来讲就是一个写操做成功后，从任何一个节点读出来的数据都是最新值，而不会出现写数据成功后读不出来或者读到旧数据的状况。etcd 经过 raft 协议来实现 leader 选举、配置变动以及保证数据读写的一致性。下面简单介绍下 etcd 的读写流程：

写数据流程（以 leader 节点为例，见上图）：

1. etcd 任一节点的 etcd server 模块收到 Client 写请求（若是是 follower 节点，会先经过 Raft 模块将请求转发至 leader 节点处理）。
2. etcd server 将请求封装为 Raft 请求，而后提交给 Raft 模块处理。
3. leader 经过 Raft 协议与集群中 follower 节点进行交互，将消息复制到follower 节点，于此同时，并行将日志持久化到 WAL。
4. follower 节点对该请求进行响应，回复本身是否赞成该请求。
5. 当集群中超过半数节点（(n/2)+1 members ）赞成接收这条日志数据时，表示该请求能够被Commit，Raft 模块通知 etcd server 该日志数据已经 Commit，能够进行 Apply。
6. 各个节点的 etcd server 的 applierV3 模块异步进行 Apply 操做，并经过 MVCC 模块写入后端存储 BoltDB。
7. 当 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 空间。

经过上述场景，咱们能够初步判断出如下几个可疑的触发条件：

1. dbsize 满
2. dbsize 和 compaction 配置更新
3. compaction 操做和 defrag 操做
4. 重启 etcd

出了问题确定要可以复现才更有利于解决问题，正所谓可以复现的 bug 就不叫 bug。复现问题以前，咱们经过分析 etcd 社区以前的相关 issue 发现，触发该 bug 的共同条件都包含执行过 compaction 和 defrag 操做，同时重启过 etcd 节点。所以，咱们计划首先尝试同时模拟这几个操做，观察是否可以在新的环境中复现。为此咱们新建了一个集群，而后经过编写脚本向集群中不停的写入和删除数据，直到 dbsize 达到必定程度后，对节点依次进行配置更新和重启，并触发 compaction 和 defrag 操做。然而通过屡次尝试，咱们并无复现出相似于上述数据不一致的场景。

抽丝剥茧，初现端倪

紧接着，在以后的测试中无心发现，client 指定不一样的 endpoint 写数据，可以查到数据的节点也不一样。好比，endpoint 指定为 node1 进行写数据，3个节点均可以查到数据；endpoint 指定为 node2 进行写数据，node2 和 node3 能够查到；endpoint 指定为 node3 写数据，只有 node3 本身可以查到。具体状况以下表：

因而咱们作出了初步的猜想，有如下几种可能：

1. 集群可能分裂了，leader 未将消息发送给 follower 节点。
2. leader 给 follower 节点发送了消息，可是 log 异常，没有对应的 command 。
3. leader 给 follower 节点发送了消息，有对应的 command，可是 apply 异常，操做还未到 KV Index 和 boltdb 就异常了。
4. leader 给 follower 节点发送了消息, 有对应的 command，可是 apply 异常，KV Index 出现了问题。
5. 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 对外表现还能够正常读写，日志无明显报错。

触发条件

1. 使用的为 etcd3 集群，而且开启了鉴权。

2. etcd 集群中节点发生重启。

3. 节点重启以前，有 grant-permission 操做(或短期内对同一个权限操做连续屡次增删)，且操做以后重启以前无其余数据写入。

4. 经过非重启节点向集群发起写数据请求。

修复方案

了解了问题的根因，修复方案就比较明确了，咱们只须要在 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/etcd/pull/11652/commits/f14d2a087f7b0fd6f7980b95b5e0b945109c95f3) 和 status api，加强了 auth revision 的可观测性和可测试性。

参考资料

1. etcd 源码：https://github.com/etcd-io/etcdetcd
2. 存储实现：https://www.codedump.info/post/20181125-etcd-server/高可用分布存储
3. etcd 的实现原理：https://draveness.me/etcd-introduction/etcd
4. raft 设计与实现：https://zhuanlan.zhihu.com/p/51063866,https://zhuanlan.zhihu.com/p/51065416

致谢

感谢在 PR 提交过程当中，etcd 社区 jingyih，mitake 的热心帮助和建议！