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

本文涉及的产品
RDS MySQL Serverless 基础系列,0.5-2RCU 50GB
云数据库 RDS MySQL,集群系列 2核4GB
推荐场景:
搭建个人博客
容器服务 Serverless 版 ACK Serverless,317元额度 多规格
简介: MGR作为MySQL原生的高可用方案,它的基于共识协议的同步和决策机制,看起来也更为先进。吸引了一票用户积极尝试,希望通过MGR架构解决RPO=0的高可用切换。在实际使用中经常会遇到因为网络抖动的问题造成集群故障,本文以真实案例分析MGR相同GTID产生不同transaction的原因。

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 Query
thread_id=19132957 exec_time=0 error_code=0
SET 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 398
flags: STMT_END_F
BINLOG '
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 Query
thread_id=19162514 exec_time=318 error_code=0
SET 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 id
113 flags: STMT_END_F
BINLOG '
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: 1032
2019-01-28T11:59:30.919926Z 6 [Warning] Slave: Can't find record in 'IC_WB_RELEASE' Error_code: 1032
2019-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.'

问题分析

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

对于该故障的分析,我们要从主从实例GTID相同,但是事务不同的原因入手,该问题猜测与bug(https://bugs.mysql.com/bug.php?id=92690)相关,我们针对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:以下分析过程请结合时序图操作步骤观看
建议点开放大,效果更清晰 ^ ^**

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

▽过程总结:

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

结论

针对此问题我们也向官方提交SR,官方已经反馈社区版MySQL 5.7.26和MySQL 8.0.16 中会修复,如果是企业版客户可以申请最新的hotfix版本。

在未升级 MySQL 版本前,若再发生此类故障,在修复时需要人工检查,检查切换时binlog中 GTID 信息与新主节点对应 GTID 的信息是否一致。如果不一致需要人工修复至一致状态,如果一致才可以将被踢出的原主节点加回集群。

所以正在使用了MGR 5.7.26之前社区版的DBA同学请注意避坑。

相关实践学习
通过Ingress进行灰度发布
本场景您将运行一个简单的应用,部署一个新的应用用于新的发布,并通过Ingress能力实现灰度发布。
容器应用与集群管理
欢迎来到《容器应用与集群管理》课程,本课程是“云原生容器Clouder认证“系列中的第二阶段。课程将向您介绍与容器集群相关的概念和技术,这些概念和技术可以帮助您了解阿里云容器服务ACK/ACK Serverless的使用。同时,本课程也会向您介绍可以采取的工具、方法和可操作步骤,以帮助您了解如何基于容器服务ACK Serverless构建和管理企业级应用。 学习完本课程后,您将能够: 掌握容器集群、容器编排的基本概念 掌握Kubernetes的基础概念及核心思想 掌握阿里云容器服务ACK/ACK Serverless概念及使用方法 基于容器服务ACK Serverless搭建和管理企业级网站应用
相关文章
|
存储 SQL 缓存
MySQL日志系统redo log(两阶段提交)和binlog
MySQL日志系统redo log(两阶段提交)和binlog
231 0
MySQL日志系统redo log(两阶段提交)和binlog
|
机器学习/深度学习 关系型数据库
|
SQL 关系型数据库 MySQL
MySQL:slave_skip_errors参数对MGR可用性的影响
整个问题提出和测试由 @gc @甘露寺的姑子@乙酉 完成,文档记录由@gc @乙酉完成。 我只是进行了问题分析和文档整理 欢迎关注我的《深入理解MySQL主从原理 32讲 》,如下: 一、案例描述 MGR在遇到表不存在的情况下,节点没有退出节点而是爆出一个警告,并且节点状态也正常,警告如下: 2019-10-17T21:16:11.
1246 0
|
算法 MySQL 关系型数据库
|
关系型数据库 MySQL
深入理解MySQL 5.7 GTID系列(七)binlog_gtid_simple_recovery参数的影响总结
想了想还是专门开了一节来总结这个问题: 5.7.6以下中默认 simplified_binlog_gtid_recovery=flase 5.7.6以上中默认 binlog_gtid_simple_recovery=true 默认值就是最合理的设置。
3967 0
|
SQL 存储 关系型数据库
MySQL 5.7 LOGICAL_CLOCK 并行复制原理及实现分析
MySQL 5.7 LOGICAL_CLOCK 并行复制原理及实现分析 在MySQL5.7 引入基于Logical clock的并行复制方案前,MySQL使用基于Schema的并行复制,使不同db下的DML操作可以在备库并发回放(在优化后,可以做到不同table下并发)。
2806 0