以下描述中用zk
代指ZooKeeper
背景
04.11
对内部系统使用的zk
集群执行变更导致集群4分钟
不可用。
详情如下:
Pigeon
使用的zk
集群原本有5个节点
(myid
为0~5
,以下描述中使用zk0
指代id
为0
的节点,依此类推)zk0
、zk1
、zk2
提供对外提供服务(其中,zk2
为leader
),zk3
、zk4
从未对外提供服务(服务域名中未包含)4月初
机柜迁移,未服务的zk3
、zk4
在需要迁移的机柜上,将zk3
、zk4
先下线了- 从提供服务的
zk0
、zk1
、zk2
里的配置中删除已经下线的zk3
、zk4
,择机重启 - 计划
04.11
进行重启节点的变更 - 此时之前下线的
zk3
、zk4
已经关机,无法ping
通 2017-04-11 11:19:13
重启完zk1
之后,集群选举持续无法成功,导致4分钟
不可用- 直到
2017-04-11 11:23:01
把其余两个节点(zk0
、zk2
)也重启了,集群才恢复可用
变更之前在线下模拟了操作流程,一切正常,对客户端影响都在数秒以内。
这个问题,经过数天的排查,终于找到原因并且重现了。05.09
对Kafka
依赖的zk
集群下线节点变更,利用前面的经验制定了下线的步骤,表现与预期相符,至此,验证了结论。
转眼,已经过了一个月了,小心翼翼地分享下彼时的排查过程,当然,写得异常混乱。
懵逼
对于故障排查,可以按照是否有现场
、是否能重现
、是否有详细上下文信息
等几个因素分为划分,因素里面否
越多,排查难度越大。04.11
的问题等到排查的时候,属于无现场
/不能重现
/有详细上下文信息
,毕竟有完整的ZooKeeper
的日志。
zk1
日志内容摘取部分如下:
|
|
看到这样的信息我是很崩溃的,完全不知道是什么意思。彼时的ZooKeeeper
对于我来说,就是一个黑盒,探索原因的手段非常有限,眼看成疑案了。谷律师说过,“疑案从无”,换到排查问题也一样,有疑案,说明排查的人修为不够。彼时,唯有硬啃代码了。
硬啃
zk1
的日志里面有:
|
|
按理说,这个时候,LEADER ELECTION TOOK
的字样已经出现了,选举应该已经结束了。
但是从当时四字命令cons
的结果来看,集群里面3台机器确实都处于This ZooKeeper instance is not currently serving requests
的状态。
再看下zk2
的日志:
|
|
一直到恢复的时候才打印了LEADER ELECTION TOOK
,zk0
也是差不多的时间打印这个日志的。
难道zk1
一直都在自嗨么?再看下zk1
的日志:
|
|
契而不舍地自嗨了10
多次,这个其实是可以理解的,zk1
认为集群里面只有3个节点,拿到两票一致,就认为选举结束了,而zk0
、zk2
还是认为集群里面有5
个节点,所以需要3
个节点的投票完全统一,才能结束选举。
这时候有一个问题:为什么zk1
进入了FOLLOWING
状态之后,会再一次进行Looking
状态,重新参与选举呢?
问题A
为什么
zk1
进入了FOLLOWING
状态之后,会再一次进行Looking
状态,重新参与选举呢?
zk
节点进行FOLLOWING
状态之后会调用Follower.followLeader
(代码位于src/java/main/org/apache/zookeeper/server/quorum/Follower.java
),如果处于正常状态,会一直处于followLeader
方法的一个loop
中。
摘取部分代码如下:
|
|
如上面代码中的中文注释所示,zk1
会去调用connectToLeader
,那么连接leader
的哪个端口呢?
我们回头看一下配置文件conf/zoo.cfg
的内容:
|
|
一共存在2181
、2888
、3888
这3个端口。
2181
最常见,是客户端使用的、提供服务的端口2888
是Leader
的专属端口,只有Leader
会启动这个端口,就像Leader
的权杖一样3888
是zk
节点在选举期间进行通信的
所以,connectToLeader
会去连接leader
(这时候从投票结果中,zk1
认为zk0
是leader
)的2888
端口,而这时,zk0
并没有认为自己是leader
,并没有启动2888
端口,所以zk1
的日志中会有如下的报错:
|
|
connectToLeader
中会重试5
次,每次重试之前间隔1s
,全部重试失败之后,会抛出异常到上层,从而导致followLeader
方法退出。
再看看QuorumPeer.run
(代码位于src/java/main/org/apache/zookeeper/server/quorum/QuorumPeer.java
)方法里面,节点进入FOLLOWING
状态后的处理:
|
|
所以这个问题的路径是:=>
zk1
进入FOLLOWING
状态=>
zk1
调用followLeader
去连接leader
=>
zk1
认为的leader
-zk0
并不认为是leader
,没有启动2888
端口=>
zk1
连接leader
失败=>
zk1
退出FOLLOWING
状态,进入LOOKING
状态
这时候有一个问题:为什么zk0
没有进入leader
状态;如果是因为zk2
没有投票给zk0
,为什么zk2
没有投票给zk0
?
问题B
为什么
zk0
没有进入leader
状态;如果是因为zk2
没有投票给zk0
,为什么zk2
没有投票给zk0
?
zk0
没有进入leader
状态说明没有获取足够的票数,从zk1
的日志里面可以看到,zk1
已经投票给了zk0
:
|
|
这里解释一下,zk
选举过程中最关键的日志的格式。这个日志是在FastLeaderElection.printNotification
(代码位于src/java/main/org/apache/zookeeper/server/quorum/FastLeaderElection.java
)中打印的。逐段来看下含义:
1 (message format version)
消息协议的版本号,从代码里面看,这个字段比较好的版本里面是0
,ZooKeeper 3.4.6
里面,这个版本号是1
。0 (n.leader)
收到的投票里面的leader
对应的id
。例子里面这张投票是投给zk0
的。0x724cd3601 (n.zxid)
收到的投票里面的leader
对应的zxid
,zxid
的高32
位代表epoch
(选出leader
后会对epoch
进行更新),低32
位代表日志偏移。例子里面的数据说明,收到的这张投票里面。0x8 (n.round)
投票发送方的logicalclock
,这个值和节点进入FastLeaderElection.lookForLeader
方法的次数是相关的,譬如我们的case
中,zk1
频繁地进行LOOKING
->FOLLOWING
->LOOKING
状态的转换,所以logicalclock
会不断地增加。如果节点收到一张投票,n.round
是比自己的logicalclock
大时,就会更新自己的logicalclock
,更新自己的票为收到的投票信息或者初始票(初始票即为投票信息填写的是节点自己的信息)。zk1
每次重新进行LOOKING
状态时,logicalclock
都比别的节点要大,但是zk1
的zxid
比其它两个节点要小,所以zk0
和zk1
会各自重新投票给自己。LOOKING (n.state)
投票发送方的状态。例子里面发送方zk1
的状态为LOOKING
。1 (n.sid)
投票发送方的id
。例子里面这张投票是zk1
发送出来的。0x7 (n.peerEpoch)
收到的投票里面的leader
对应的epoch
,当然,这个值已经被n.zxid
所涵盖了LOOKING (my state)
寄几的状态,即投票接收方当前的状态。
解释完了日志的信息,再从zk0
的日志里面去看下为什么zk0
没有获得足够的票:
|
|
所以问题B
的答案:
- 为什么
zk0
没有进入leader
状态?
在zk1
从LOOKING
进入FOLLOWING
的期间(11:19:18 - 11:19:19
),zk0
早已将自己的选票投给了zk2
,zk0
是不可能成为leader
的。只是由于zk3
/zk4
的缘故,zk0
的第二张选票(认为zk2
是leader
的投票),一直到11:19:23
以后才发送给zk1
,为时已晚。 - 如果是因为
zk2
没有投票给zk0
,为什么zk2
没有投票给zk0
在zk1
从LOOKING
进入FOLLOWING
的期间(11:19:18 - 11:19:19
),zk2
还卡在连接zk3
/zk4
上,选票无法发送出去;即使选票能发送出去,这个状态下也只可能zk2
能变成leader
,因为它同时拥有最大的epoch
、zxid
、id
。
所以,问题的根本原因在于,zk0
/zk2
变成了半哑巴,它们在集群里面说一句话,需要间隔10s
,导致zk1
频繁地进行状态地切换,即使它找到了正确的leader
-zk2
,zk2
也会因为收不到zk0
的选票而无法变成leader
。
基于这个判断,使用Byteman
模拟连接超时来重现故障场景。
重现
版本信息
重现过程中使用的版本如下:
ZooKeeper
:3.4.6
Byteman
:3.0.6
Saltstack
:salt 2015.8.8 (Beryllium)
重现步骤
1. 创建5节点
的ZooKeeper集群
使用Saltstack
在本地创建5节点
的zk集群
|
|
集群对应目录如下:
|
|
zoo.cfg
中节点相关的配置如下:
|
|
5节点
对应的clientPort
为7000~7004
。
以下描述中用zk0
代指clientPort
为7000
的zk节点
,依此类推
查看各个节点中集群创建完毕之后的角色
|
|
2. 下线节点并修改配置
下线节点zk3
/zk4
:
|
|
在zk0
/zk1
/zk2
的配置中注释掉zk3
/zk4
的配置:
|
|
注释之后的配置如下:
|
|
这时候,各节点的角色如下:
|
|
3. 模拟连接zk3
/zk4
超时
对zk0
/zk2
加载Byteman
脚本,模拟连接zk3
/zk4
超时的问题。
打开监控端口
|
|
加载Byteman
脚本
|
|
脚本Issue170411.btm
内容如下:
|
|
4. 重启zk1
重启zk1
,此时zk1
的配置中只有zk0
/zk1
/zk2
这3个节点。
|
|
这时候,就可以看到选举一直无法成功,no matter how long it takes ... :(
|
|
小结
无疑,这次问题出现是因为下线操作不合理。zk0
/zk1
/zk2
/zk3
/zk4
这样5节点
的zk
集群,需要下线zk3
/zk4
两个节点的时候,如果zk3
/zk4
不是原集群的leader
,合理规范的操作应该是:
- 修改
zk0
/zk1
/zk2
的配置为3节点
- 逐台重启
zk0
/zk1
/zk2
,最后重启leader
这样,只有在重启leader
时才会影响集群的可用性。
|
|