1. 问题现象
某天mon leader在服务器node0001和node0002节点间一直切换,导致数据库损坏界面告警
2. 详细分析
2.1 查看mon.b日志
通过上图日志信息分析可以得出,mon.b发生的选举都是由于续租超时(lease_timeout)触发的。为什么会出现续租超时呢?
2.2 分析续租在mon中是怎么实现
2.2.1 续租是谁发出的?
续租的操作是由主mon发起的,周期是每隔3s(lease_renew_event = 3),租约时长为10s(mon_lease_ack_timeout=10)
2.2.2 租约的作用?
mon要想提供读写服务必须取得租约,否则无法读写
2.2.3 续租触发时机?
-
mon probe同步完元数据之后,如果mon的之间的元数据一致,即mon都是active的,此时需要由主mon发起续租
-
当主mon持久化本地元数据commit_finish之后会发起续租
-
active状态下由主mon每隔3s会触发一次续租
2.2.4 续租取消
- 当非主mon节点处理元数据更新时候会讲lease_expire时间设置为空表示cancel lease用来判断mon是否能够提供读写服务,因为此时mon还在更新元数据还不能提供读写服务。注意:此时非主mon节点的lease超时定时器并未取消
- 主mon发起元数据更新会把关闭续租定时器。注意:如果元数据更新时间长会导致其他mon续租超时
2.3 详细分析过程
分析mon.a的日志结合mon.b的日志以及2.2.3小结的分析,mon.b的续租应该是由主mon更新完本地元数据之后触发,即commit_finish。那为什么10s都没有触发呢?
通过上图分析
- mon.a日志
- mon.b日志
通过比较mon.b发生选举的时间和mon.a处理选举的消息的时间,发现是一致的
那为什么mon.b的选举消息不能触发mon.a的发起新的选举呢(mon.a’rank < mon.b’s rank),通过代码分析handle_propose接口,如果当前mon.a处于更新元数据的状态,start_election则需要等待元数据更新完之后触发,那什么时候mon.a本地更新完呢?通过查看本地mon.a的日志没有commit_finish的打印是因为日志级别太低导致,但是可以通过其他mon的日志反推,因为mon之间同步数据的过程是这样的,如下图:
- 查看mon.c的日志:
mon.c在07:00:30.739841收到了mon.a的commit finish消息,所以推测mon.a在该时刻处理完了元数据更新操作。那mon.a处理完元数据更新什么时候发起选举呢? - 查看mon.a日志:
07:00:35.9367347fc4083a4700 0 common/LogClient.cc 175 log_channel(cluster) log [INF] : mon.acalling new monitor election
这个时间点和mon.c处理mon.a的选举消息时间不一致,如下图
通过mon.c接受选举消息推算mon.a发起选举的请求时间即07:00:32时候发起的
总结:mon.a从处理元数据开始到结束共消耗了差不多10s,begin–>commit_finish,所以怀疑是系统处理慢导致mon元数据更新时间长
-
分析mon.a系统盘信息,发现该系统盘是由两块盘做了软raid构成的,通过iostat工具查看这两块盘的统计信息发现其中sdf盘压力经常是100%并且带宽很低(mon.b节点系统盘也比较慢),如下图
-
通过工具查看sdf上io主要的来源,如下图
-
分析下其他时间点的leader 发生切换的日志看是不是一样的原因导致的
mon.a:
mon.b:
mon.a的发起元数据更新过程:
从上图以及结合代码看出06:31:44至06:31:56之间的时间主要消耗在同步更新db系统太慢导致mon.b续租超时发生双leader问题,与上面分析结论也是一致的
由于系统盘是个做了软raid,那么系统盘上I/O请求会同步更新到组成raid的磁盘上,只有所有磁盘的I/O处理完成了才会对上层应用返回,因此只要有块盘慢就会影响系统盘的I/O性能
3 结论
mon.a与mon.b之间的leader切换是由于系统盘慢导致mon元数据更新慢导致的,需要更换系统盘;经过更换系统盘之后,再也没有出现双leader的现象了