深度分析 | MGR相同GTID产生不同transaction故障分析

5次阅读

共计 6004 个字符,预计需要花费 16 分钟才能阅读完成。

本文是由爱可生运维团队出品的「MySQL 专栏」系列文章,内容来自于运维团队一线实战经验,涵盖 MySQL 各种特性的实践,优化案例,数据库架构,HA,监控等,有扫雷功效。
爱可生开源社区持续运营维护的小目标:

每周至少推送一篇高质量技术文章

每月研发团队发布开源组件新版

每年 1024 开源一款企业级组件
2019 年至少 25 场社区活动

欢迎大家持续关注~

MGR 作为 MySQL 原生的高可用方案,它的基于共识协议的同步和决策机制,看起来也更为先进。吸引了一票用户积极尝试,希望通过 MGR 架构解决 RPO= 0 的高可用切换。在实际使用中经常会遇到因为网络抖动的问题造成集群故障,最近我们某客户就遇到了这类问题,导致数据不一致。
问题现象
这是在生产环境中一组 MGR 集群,单主架构,我们可以看到在相同的 GTID86afb16f-1b8c-11e8-812f-0050568912a4:57305280 下,本应执行相同的事务,但 binlog 日志显示不同事务信息。

Primary 节点 binlog:
SET @@SESSION.GTID_NEXT= ’86afb16f-1b8c-11e8-812f-0050568912a4:57305280’/*!*/;# at 637087357#190125 15:02:55 server id 3136842491 end_log_pos 637087441 Querythread_id=19132957 exec_time=0 error_code=0SET TIMESTAMP=1548399775/*!*/;BEGIN/*!*/;# at 637087441#190125 15:02:55 server id 3136842491 end_log_pos 637087514 Table_map:`world`.`IC_WB_RELEASE` mapped to number 398# at 637087514#190125 15:02:55 server id 3136842491 end_log_pos 637087597 Write_rows: table id 398flags: STMT_END_FBINLOG ‘n7RKXBP7avi6SQAAABov+SUAAI4BAAAAAAEAB2ljZW50ZXIAFUlDX1FVRVJZX1VTRVJDQVJEX0xP’/*!*/;### INSERT INTO `world`.`IC_WB_RELEASE`### SET

Secondary 节点 binlog:
SET @@SESSION.GTID_NEXT= ’86afb16f-1b8c-11e8-812f-0050568912a4:57305280’/*!*/;# at 543772830#190125 15:02:52 server id 3136842491 end_log_pos 543772894 Querythread_id=19162514 exec_time=318 error_code=0SET TIMESTAMP=1548399772/*!*/;BEGIN/*!*/;# at 543772894#190125 15:02:52 server id 3136842491 end_log_pos 543772979 Table_map:`world`.`IC_QUERY_USERCARD_LOG` mapped to number 113# at 543772979#190125 15:02:52 server id 3136842491 end_log_pos 543773612 Delete_rows: table id113 flags: STMT_END_FBINLOG ‘nLRKXBP7avi6VQAAADNRaSAAAHEAAAAAAAEAB2ljZW50ZXIADUlDX1dCX1JFTEVBU0UACw8PEg8’/*!*/;### DELETE FROM `world`.`IC_QUERY_USERCARD_LOG`### WHERE
从以上信息可以推测,primary 节点在这个 GTID 下对 world.IC_WB_RELEASE 表执行了 insert 操作事件没有同步到 secondary 节点,secondary 节点收到主节点的其他事件,造成了数据是不一致的。当在表 IC_WB_RELEASE 发生 delete 操作时,引发了下面的故障,导致从节点脱离集群。
2019-01-28T11:59:30.919880Z 6 [ERROR] Slave SQL for channel ‘group_replication_applier’: Could not execute Delete_rows event on table `world`.`IC_WB_RELEASE`; Can’t find record in ‘IC_WB_RELEASE’, Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND, Error_code: 10322019-01-28T11:59:30.919926Z 6 [Warning] Slave: Can’t find record in ‘IC_WB_RELEASE’ Error_code: 10322019-01-28T11:59:30.920095Z 6 [ERROR] Plugin group_replication reported: ‘The applier thread execution was aborted. Unable to process more transactions, this member will now leave the group.’2019-01-28T11:59:30.920165Z 6 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with “SLAVE START”. We stopped at log ‘FIRST’ position 271.2019-01-28T11:59:30.920220Z 3 [ERROR] Plugin group_replication reported: ‘Fatal error during execution on the Applier process of Group Replication. The server will now leave the group.’2019-01-28T11:59:30.920298Z 3 [ERROR] Plugin group_replication reported: ‘The server was automatically set into read only mode after an error was detected.’
问题分析

主节点在向从节点同步事务时,至少有一个 GTID 为 86afb16f-1b8c-11e8-812f-0050568912a4:57305280(执行的是 insert 操作)的事务没有同步到从节点,此时从实例还不存在这个 GTID;于是主实例 GTID 高于从实例。数据就已经不一致了。
集群业务正常进行,GTID 持续上涨,新上涨的 GTID 同步到了从实例,占用了 86afb16f-1b8c-11e8-812f-0050568912a4:57305280 这个 GTID,所以从实例没有执行 insert 操作,少了一部分数据。
主节点对 GTID 为 86afb16f-1b8c-11e8-812f-0050568912a4:57305280 执行的 insert 数据进行 delete,而从节点由于没有同步到原本的 insert 操作;没有这部分数据就不能 delete,于是脱离了集群。

对于该故障的分析,我们要从主从实例 GTID 相同,但是事务不同的原因入手,该问题猜测与 bug(https://bugs.mysql.com/bug.ph…)相关,我们针对 MGR 同步事务的时序做如下分析。
相关知识背景
MGR 全组同步数据的 Xcom 组件是基于 paxos 算法的实现;每当提交新生事务时,主实例会将新生事务发送到从实例进行协商,组内协商通过后全组成员一起提交该事务;每一个节点都以同样的顺序,接收到了同样的事务日志,所以每一个节点以同样的顺序回放了这些事务,最终组内保持了一致的状态。
paxos 包括两个角色:
提议者(Proposer):主动发起投票选主,允许发起提议。接受者(Acceptor):被动接收提议者(Proposer)的提议,并记录和反馈,或学习达成共识的提议。
paxos 达成共识的过程包括两个阶段:
第一阶段(prepare)
a:提议者(Proposer)发送 prepare 请求,附带自己的提案标识(ballot,由数值编号加节点编号组成)以及 value 值。组成员接收 prepare 请求;b:如果自身已经有了确认的值,则将该值以 ack_prepare 形式反馈;在这个阶段中,Proposer 收到 ack 回复后会对比 ballot 值,数值大的 ballot 会取代数值小的 ballot。如果收到大多数应答之后进入下一个阶段。
第二阶段(accept)
a:提议者(Proposer)发送 accept 请求 b:接收者(Acceptor)收到请求后对比自身之前的 bollat 是否相同以及是否接收过 value 值。如果未接受过 value 值 以及 ballot 相同,则返回 ack_accept,如果接收过 value 值,则选取最大的 ballot 返回 ack_accept。c:之后接受相同 value 值的 Proposer 节点发送 learn_op,收到 learn_op 节点的实例表示确认了数据修改,传递给上层应用。
针对本文案例我们需要强调几个关键点:

1. 该案例最根本的异常对比发生在第二次提案的 prepare 阶段。
2.prepare 阶段的提案标识由数值编号和节点编号两部分组成;其中数值编号类似自增长数值,而节点编号不变。

分析过程
结合 paxos 时序,我们对案例过程进行推测:

Tips:以下分析过程请结合时序图操作步骤观看
建议点开放大,效果更清晰 ^ ^

【step1】primary 节点要执行对表 world.IC_WB_RELEASE 的 insert 操作,向组内发送假设将 ballot 设置为(0.0)以及将 value 值 world.IC_WB_RELEASE 的 prepare 请求,并收到大多数成员的 ack_prepare 返回,于是开始发送 accept 请求。primary 节点将 ballot(0.0)的提案信息发送至组内,仍收到了大多数成员 ack_accept(ballot=0.0value=world.IC_WB_RELEASE)返回。然后发送 learn_op 信息【step3】。
同时其他从节点由于网络原因没有收到主实例的的 learn_op 信息【step3】,而其中一台从实例开始新的 prepare 请求【step2】,请求 value 值为 no_op(空操作)ballot=1.1(此编号中节点编号是关键,该 secondary 节点编号大于 primary 节点编号,导致了后续的问题,数值编号无论谁大谁小都要被初始化)。

其他的从实例由于收到过主节点的 value 值;所以将主节点的(ballot=0.0,value=world.IC_WB_RELEASE)返回;而收到的 ack_prepare 的 ballot 值的数值符号全组内被初始化为 0,整个 ballot 的大小完全由节点编号决定,于是从节点选取了 ballot 较大的该实例 value 值作为新的提案,覆盖了主实例的 value 值并收到大多数成员的 ack_accept【step2】。并在组成员之间发送了 learn_op 信息【step3】,跳过了主实例提议的事务。
从源码中可以看到关于 handle_ack_prepare 的逻辑。
handle_ack_prepare has the following code: if (gt_ballot(m->proposal,p->proposer.msg->proposal)) {replace_pax_msg(&p->proposer.msg, m); … }

此时,主节点在 accept 阶段收到了组内大多数成员的 ack_accept 并收到了 自己所发送的 learn_op 信息,于是把自己的提案(也就是 binlog 中对表的 insert 操作)提交【step3】,该事务 GTID 为 86afb16f-1b8c-11e8-812f-0050568912a4:57305280。而其他节点的提案为 no_op【step3】,所以不会提交任何事务。此时主实例 GTID 大于其他从实例的。
主节点新生 GTID 继续上涨;同步到从实例,占用了从实例的 86afb16f-1b8c-11e8-812f-0050568912a4:57305280 这个 GTID,于是产生了主节点与从节点 binlog 中 GTID 相同但是事务不同的现象。
当业务执行到对表 world.IC_WB_RELEASE 的 delete 操作时,主实例能进行操作,而其他实例由于没有 insert 过数据,不能操作,就脱离了集群。

▽过程总结:

旧主发送 prepare 请求,收到大多数 ack,进入 accept 阶段,收到大多数 ack。
从实例由于网络原因没有收到 learn_op 信息。
其中一台从实例发送新的 prepare 请求,value 为 no_op。
新一轮的 prepare 请求中,提案标识的数值编号被初始化,新的提案者大于主实例,从实例选取新提案,执行空操作,不写入 relay-log。代替了主实例的事务,使主实例 GTID 大于从实例。
集群网络状态恢复,新生事物正常同步到从实例,占用了本该正常同步的 GTID,使集群中主节点与从节点相同 GTID 对应的事务时不同的。

结论
针对此问题我们也向官方提交 SR,官方已经反馈社区版 MySQL 5.7.26 和 MySQL 8.0.16 中会修复,如果是企业版客户可以申请最新的 hotfix 版本。
在未升级 MySQL 版本前,若再发生此类故障,在修复时需要人工检查,检查切换时 binlog 中 GTID 信息与新主节点对应 GTID 的信息是否一致。如果不一致需要人工修复至一致状态,如果一致才可以将被踢出的原主节点加回集群。
所以正在使用了 MGR 5.7.26 之前社区版的 DBA 同学请注意避坑。
开源分布式中间件 DBLE 社区官网:https://opensource.actionsky….GitHub 主页:https://github.com/actiontech… 技术交流群:669663113
开源数据传输中间件 DTLE 社区官网:https://opensource.actionsky….GitHub 主页:https://github.com/actiontech… 技术交流群:852990221

正文完
 0