近期我们在测试环境升级ETCD集群(3.2升级到3.3)的时候,遇到了一些奇怪现象。当集群升级完后,收到了测试同学反馈集群出现各种BUG了:
我们最开始怀疑K8S的controller-manager/scheduler/apiserver出bug了,一番调查后发现又是etcd出现严重问题了(恰好测试环境我们屏蔽了这个集群的告警,导致我们事后才知道),我们通过监控视图和日志观察到有如下异常:
我们尝试看日志是否为什么部分Key在有些节点有,有些节点无, 但是因为etcd的日志实在少的可怜,缺少关键的错误日志,我们一无所获,陷入迷茫和困惑中. 同时在社区上也未能搜索到有效信息,同时我们通过比对db的鉴权版本号也排除了不是我们上一次发现的严重的BUG(https://github.com/etcd-io/etcd/issues/11651,https://github.com/etcd-io/etcd/pull/11652),于是只能修改etcd代码并尝试复现了。
首先我们采用尝试人工简单升级ETCD集群试试是否能复现,然并卵,未能复现,其实正如我们所预期一样,如果那么能复现社区早发现早解决了,不可能我们现在才遇到。
如何才能成功复现一个严重的BUG? 首先我们有如下推测:
我们采取以下方法及技术手段对推测进行了分析和落地:
当我们把chaos monkey程序按照以上分析结论优化完后,在两套集群上同时部署,令人振奋的是,没过多久,我们就收到了一致性差异告警,我们又成功复现了。
收到告警后,我们立刻采取了以下措施:
node A(3.2+,Leader)
```
637802:Mar 11 21:52:23 localhost etcd[28065]: LeaseRevoke:{LeaseRevoke 24 0 ID:2229124347589447546 } {entry-index 17 25 <nil>} {entry-term 17 2 <nil>} {rev 11 2014102077 <nil>}
637803:Mar 11 21:52:23 localhost etcd[28065]: revoke lessor,lessor id:2229124347589447546
637804:Mar 11 21:52:23 localhost etcd[28065]: revoke lessor,lessor id:2229124347589447546,key:/masterleases/A
637805:Mar 11 21:52:23 localhost etcd[28065]: apply request:header:<ID:16363671783383239993 > lease_revoke:<ID:2229124347589447546 > ,response:&{0xc000d545e0 <nil> <nil>}
```
node B(3.2+,Follower)
```
637802:Mar 11 21:52:23 localhost etcd[28065]: LeaseRevoke:{LeaseRevoke 24 0 ID:2229124347589447546 } {entry-index 17 25 <nil>} {entry-term 17 2 <nil>} {rev 11 2014102077 <nil>}
637803:Mar 11 21:52:23 localhost etcd[28065]: revoke lessor,lessor id:2229124347589447546
637804:Mar 11 21:52:23 localhost etcd[28065]: revoke lessor,lessor id:2229124347589447546,key:/masterleases/A
637805:Mar 11 21:52:23 localhost etcd[28065]: apply request:header:<ID:16363671783383239993 > lease_revoke:<ID:2229124347589447546 > ,response:&{0xc000d545e0 <nil> <nil>}
```
node C(3.3+,Follower)
```
1392010:Mar 11 21:56:42 localhost etcd[26312]: applyEntryNormal:check index, entry-index: 25, consistent-index: 24
1392011:Mar 11 21:56:42 localhost etcd[26312]: shouldApplyV3, entry-index: 25, consistent-index: 25
1392012:Mar 11 21:56:42 localhost etcd[26312]: LeaseRevoke: ID:2229124347589447546 , entry-index: 25, entry-term: 2, rev: 2014102070
1392014:Mar 11 21:56:42 localhost etcd[26312]: request "header:<ID:16363671783383239993 > lease_revoke:<id:1eef70c8a23e4f7a>" with result "error:auth: user name is empty" took too long (1.464µs) to execute
```
从日志中我们可以看到节点C(3.3+)执行lease_revoke命令时失败了,错误是用户名为空。 此错误将继续放大,从而导致mvcc版本差异很大,进而可能无法执行txn命令,并且数据损坏。
为什么3.3节点执行会报user name is empty呢? 我突然想起之前比对3.2和3.3差异的时候,偶然看到了一处与其相关改动点,当时没意识到有什么问题,我立刻再去对比差异,发现正是这个PR(https://github.com/etcd-io/etcd/pull/8031)在3.3的变动,导致3.3节点执行失败,在3.3以前lease revoke不需要鉴权,但是3.3这个PR增加了鉴权,导致lease过期的时候,3.3节点无法删除lease对应的key,进而出现数据不一致,版本差异,数据毁坏等一系列BUG。
详情参考issue: https://github.com/etcd-io/etcd/issues/11689
我们讨论的修复方案有两种:
在成功发现和修复两个严重数据不一致BUG后,我们推荐以下ETCD最佳实践方案:
最后关于ETCD数据不一致定位老大难的问题,我们也提交了PR,https://github.com/etcd-io/etcd/pull/11670,相信以后定位不一致问题会方便很多,目前已经合入master。
原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。
如有侵权,请联系 cloudcommunity@tencent.com 删除。
原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。
如有侵权,请联系 cloudcommunity@tencent.com 删除。