您当前的位置:首页 > 电脑百科 > 数据库 > MYSQL

一次MySQL主从同步异常,扒个底朝天都没排查出来……

时间:2023-06-08 13:36:06  来源:微信公众号  作者:悟空聊架构

一、现象

最近项目的测试环境遇到一个主备同步的问题:

备库的同步线程停止了,无法同步主库的数据更改。

备库报错如下:

从库同步报错信息

完整的错误信息:

Relay log read fAIlure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'MySQLbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a.NETwork problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.

上面的报错信息是什么意思呢?

翻译一下就是主库的 binlog 或者从库的 relay log 损坏了,造成这个问题的原因:

  • 可能是网络问题。
  • 也可能是主库或备库的代码 bug。

首先我们还是得复习下主从同步的原理才能更好地分析原因。

二、主从同步的原理

主从同步的原理

  • 从库会生成两个线程,一个 I/O 线程,名字叫做 Slave_IO_Running,另外一个是 SQL 线程,名字叫做 Slave_SQL_Running;
  • 从库的 I/O 线程会去请求主库的 binlog 日志文件,并将得到的 binlog 日志文件写到本地的 relay log (中继日志)文件中;
  • 主库会生成一个 dump 线程,用来给从库 I/O 线程传 binlog;
  • 从库 SQL 线程,会读取 relay log 文件中的日志,并解析成 SQL 语句逐一执行。

三、排查思路

1、分析从库的同步状态

我们可以打印下从库的同步状态,看到如下几个关键信息:

分析从库的同步状态

  • Master_Log_File:mysql-bin.000956,代表从库读到的主库的 binlog file
  • Read_Master_Log_Pos:528071913,代表从库读到的主库的 binlog file 的日志偏移量
  • Relay_Log_File:relay-bin.000094,代表从库执行到了哪一个 relay log
  • Relay_Log_Pos:123408769,代表从库执行的 relay log file 的日志偏移量
  • Relay_Master_Log_File:mysql-bin.000955,代表从库已经重放到了主库的哪个 binlog file。
  • Exec_Master_Log_Pos:123408556,代表从库已经重放到了主库 binlog file 的偏移量。
  • Slave_IO_Running:Yes,说明 I/O 线程正在运行,可以正常获取 binlog 并生成 relay log。
  • Slave_SQL_Running:No,说明 SQL 线程已经停止运行,不能正常解析 relay log,也就不能执行主库上已经执行的命令。
  • Master_Log_File 和 Read_Master_Log_Pos 这两个参数合起来表示的是读到的主库的最新位点。
  • Relay_Master_Log_File 和 Exec_Master_Log_Pos,这两个参数合起来表示的是从库执行的最新位点。

如果红色框起来的两个参数 Master_Log_File 和 Relay_Master_Log_File 相等,则说明从库读到的最新文件和主库上生成的文件相同,这里前者是 mysql-bin.000956,后者是 mysql-bin.000955,说明两者不相同,存在主从不同步。

如果蓝色框起来的两个参数 Read_Master_Log_Pos 和 Exec_Master_Log_Pos 相等,则说明从库读到的日志文件的位置和从库上执行日志文件的位置相同,这里不相等,说明主从不同步。

当上面两组参数都相等时,则说明主从同步正常,且没有延迟。只要有任意一组不相等,则说明主从不同步,可能是从库停止同步了,或者从库存在同步延迟。由于上面的 SQL 线程已经停止了,说明是从库同步出现问题了。

从库同步出现的问题在最开始的报错信息里面已经提到了,可能是网络问题导致,还有可能是 binlog 或 relay log 损坏。

2、重启万能大法

先通过重启来恢复从库的 SQL 线程试试看?重启方式就是两种:

  • 方式一:从库重新开启同步。就是执行 stop slave; 和 start slave; 命令。
  • 方式二:重启从库实例。就是重启 mysql 实例或 mysql 容器。

这两种方式试了后,都不能恢复从库的 SQL 线程。

3、查看 binlog

再来看下 binlog 是否有损坏,在主库上通过这个命令打开 mysql-bin.000955 文件。

mysqlbinlog /var/lib/mysql/log/mysql-bin.000955

没有报错信息,如下图所示:

binlog 日志

4、查看 relay log

看到从库同步的 Relay_Log_File 到 relay-bin.00094 就停止同步了,如下图所示,可能是这个文件损坏了。

relay log 日志

在从库上通过 mysqlbinlog 命令打开这个文件:

mysqlbinlog /var/lib/mysql/log/relay-bin.000094

可以看到有个报错信息:

ERROR: Error in Log_event::read_log_event(): 'read error', data_len: 7644, event_type: 31

ERROR: Could not read entry at offset 243899899: Error in log format or read error.

这段文字翻译过来就是读取错误,数据长度 7644,在读取偏移量为 243899899 的日志时发生了错误,可能是日志文件格式错误或是读取文件错误。

relay log 报错信息

5、找原因

1)猜测事务日志太大

根据这个报错信息可以知道这个事务日志数据太长了,data_len: 7644,而导致读取错误。

而且上面还有很多 Update_rows 的操作。

猜测:会不会是主库执行了一个大事务,造成该事务生成的一条 binlog 日志太大了,从库生成的对应的一条 relay log 日志也很大, SQL 线程去解析这条 relay log 日志解析报错。

2)验证

到主库上查看下 binlog 日志里面有没有在那个时间点做特殊操作。

感觉快找到原因了。执行以下命令来查看:

mysqlbinlog File --stop-datetime=T --start-datetime=T

stop-datetime 指定为读取 relay log 报错的时刻 2023-04-04 16:47:16;

start-datetime 指定为读取 relay log 报错的时刻 2023-04-04 16:47:30。

发现并没有找到 Update_rows 的操作。继续把时间往后加一点,经过多次尝试,把时间锁定在了 2023-04-04 17:00:30~17:00:31。这 1s 内能找到 2023-04-04 16:47:16 的操作日志。

日志如下,这个命令会打印 N 多日志,直接把屏幕打满了!

难道真的 binlog 对应的这条事务日志太大了吗?

存疑:2023-04-04 16:47:16 时刻对数据库中的表做了某个大事务的操作,造成该事务对应的这条 binlog 日志很大很大。生成的 relay log 也很大,SQL 线程解析 relay log 报错。

6、这是真相吗?

问了下熟悉这张表的同事,有没有在这个时刻做什么大事务操作。

同事看了下代码,发现有个批量插入的操作,一次执行 400 条,难道是 400 条太多了?这不应该是真正的原因,400 条也不多。

不经意间问了下这张表的数据量有多大,该同事在 4月4号 16:45:25 做了一个手动备份 xx_dance 表的操作,这张表有 25 万条数据。

备份表 xx_dance_0404 的信息

这个备份操作是在一个事务里面执行的,生成的一条 binlog 日志很大。

这里只是一个猜测,还未得到验证,文末会说明真正的原因。

如果真的是这样,那我可以先恢复从库的同步,备份表的操作在从库上其实不需要。

7、GTID

不知道细心的你是否有发现上面的 binlog 里面有一个GTID

'c5d74746-d7ec-11ec-bf8f-0242ac110002:8634832

binlog 中 GTID

记住 GTID 中的数字 8634832,后面恢复从库同步时要用到。

我们再来看下从库的状态,发现也有一个 GTID,如下图所示,值为 8634831正好相差 1,感觉这两个 GTID 值之间有不可告人的秘密。

从库的状态,GTID 集合

那么从库 SQL 线程停止运行的原因就是卡在 8634832 这里了,我们可否跳过这个 GTID 呢?这里就需要了解 GTID 的原理了。

四、GTID 同步方式的原理

这里还是把主从同步采用 GTID 方式的流程拿出来看下,帮助大家快速回顾下,熟悉的同学可以跳过本节内容。

  • GTID 方案:主库计算主库 GTID 集合和从库 GTID 的集合的差集,然后主库推送差集 binlog 给从库。

当从库设置完同步参数后,假定主库 A 的GTID 集合记为集合 x,从库 B 的 GTID 集合记为 y。

从库同步的逻辑如下:

GTID 同步方式的原理

  • 从库 B 指定主库 A,基于主备协议建立连接。
  • 从库 B 把集合 y 发给主库 A。
  • 主库 A 计算出集合 x 和集合 y 的差集,也就是集合 x 中存在,集合 y 中不存在的 GTID 集合。比如集合 x 是 1~100,集合 y 是 1~90,那么这个差集就是 91~100。这里会判断集合 x 是不是包含有集合 y 的所有 GTID,如果不是则说明主库 A 删除了从库 B 需要的 binlog,主库 A 直接返回错误。
  • 主库 A 从自己的 binlog 文件里面,找到第一个不在集合 y 中的事务 GTID,也就是找到了 91。
  • 主库 A 从 GTID = 91 的事务开始,往后读 binlog 文件,按顺序取 binlog,然后发给 B。
  • 从库 B 的 I/O 线程读取 binlog 文件生成 relay log,SQL 线程解析 relay log,然后执行 SQL 语句。

GTID 同步方案和位点同步的方案区别是:

  • 位点同步方案是通过人工在从库上指定哪个位点,主库就发哪个位点,不做日志的完整性判断。
  • 而 GTID 方案是通过主库来自动计算位点的,不需要人工去设置位点,对运维人员友好。

五、恢复从库的同步

1、查看从库执行 GTID 的进度

在从库上执行 show slave status G 来查看 GTID 集合。

Retrieved_Gtid_Set 表示从库收到的所有日志的 GTID 集合。

Executed_Gtid_Set 表示从库已经执行完成的 GTID 集合。

如果 Executed_Gtid_Set 集合是包含Retrieved_Gtid_Set,则表示从库接收到的日志已经同步完成。

这里 Executed_Gtid_Set 的集合为 1-8634831,而 Retrieved_Gtid_Set 为 1-9101426,说明从库有些 GTID 是没有执行的。从库已经执行到了 8634831,下一个要执行的 GTID 为 8634832。

因为我们采用的同步方式是 GTID 方式,所以只要让从库跳过这个 GTID ,从下一个 GTID 开始同步就行。

带来的问题就是这个 GTID 对应的事务没有执行。因为报错的操作是从库备份一张大表,所以从库跳过这个备份操作也是可以接受的。

2、手动设置 GTID

1)重置从库进度

首先重置下从库同步的进度 reset slave,这条命令会把所有的 relog 给清理掉,重新启用一个新的 relay log文件。

stop slave;

reset slave;

重新开启同步后,主库会计算主库 GTID 集合和从库 GTID 的集合的差集,然后主库推送差集 binlog 给从库。

2)设置 GTID 为一个值

执行以下命令设置 GTID 为下一个值。

set gtid_next='c5d74746-d7ec-11ec-bf8f-0242ac110002:8634832';

begin;

commit;

set gtid_next=automatic;

start slave;

gtid_next 表示设置下一个 GTID = 8634832,这个值是在原来的 8634831 加 1。后面的 begin 和 commit 是提交了一个空事务,把这个 GTID 加到从库的 GTID 集合中。那么从库的 GTID 集合就变成了:

'c5d74746-d7ec-11ec-bf8f-0242ac110002:1-8634832';

3)查看当前 GTID 集合

我们可以通过 show master statusG 命令来查看从库的 GTID 集合。下方截图是执行上述命令之前的。GTID集合为 1-8634831。另外 GTID 集合 为 1 和 GTID 集合为 1-4 的可以忽略,因为它们前面的 Master_UUID 不是当前主库的 uuid。

show master statusG 的结果

也可以通过 show slave statusG 命令来查看 GTID 集合,结果也是一样的。

3、开启从库同步

再次启动从库的同步(start slave 命令),I/O 线程和 SQL 线程的状态都为 YES,说明启动成功了。

而且查看从库的同步状态时,观察到从库的同步是存在延迟的。通过观察这个字段 Seconds_Behind_Master 在不断减小,说明主从同步的延迟越来越小了。

两个线程都是正常运行,主从同步延迟越来越小

过一段时间后,执行的 GTID 等于收到的 GTID 集合,Seconds_Behind_Master = 0,说明主从完全同步了。

六、原因

上面的推测:备份大表造成 binlog 的一条日志太大,relay log 也跟着变大,SQL 线程无法正常解析。

但这是真相吗?

虽然从库重新开启了同步,且跳过了这条日志,但带来的是从库上就不会出现这个备用表 xx_dance_0404 。

但出现了两个奇怪的问题:

问题 1:从库开启同步后,居然出现了这个备份表 xx_dance_0404。不是跳过这个备份操作了吗?目前没想到原因。

问题 2:为了重现这个问题,我到主库上做了一个备份表的操作,表名为 xx_dance_0412,从库也同步了这个新的备份表 xx_dance_0412。而且 binlog 出现的日志现象也是一样的,对应的这条 binlog 日志也很大,但是从库同步正常。我又备份了一张 300 万的大表,依然没重现。

通过问题 2 可以说明上面的推测是错误的,备份大表并不会影响主从同步。

那么 relay log 报错的原因是什么?

只有一个原因了,即:relay log 文件真的是损坏的,从库的状态上也说明了原因,relay log is corrupted(损坏)。SQL 线程去解析 relay log 时报错了,导致 SQL 线程停止,从库不能正常执行同步。

小结:relay log 损坏了,导致从库的 SQL 线程解析 relay log 时出现异常。从库恢复方式是通过手动设置当时出错的 GTID 的下一个值,让从库不从主库同步这个 GTID,最后从库就能正常同步这个 GTID 之后的 binlog 了,后续 SQL 线程也能正常解析 relay log 了。

作者丨悟空聊架构

来源丨公众号:悟空聊架构(ID:PassJAVA666)



Tags:MySQL   点击:()  评论:()
声明:本站部分内容及图片来自互联网,转载是出于传递更多信息之目的,内容观点仅代表作者本人,不构成投资建议。投资者据此操作,风险自担。如有任何标注错误或版权侵犯请与我们联系,我们将及时更正、删除。
▌相关推荐
MySQL 核心模块揭秘
server 层会创建一个 SAVEPOINT 对象,用于存放 savepoint 信息。binlog 会把 binlog offset 写入 server 层为它分配的一块 8 字节的内存里。 InnoDB 会维护自己的 savepoint...【详细内容】
2024-04-03  Search: MySQL  点击:(6)  评论:(0)  加入收藏
MySQL 核心模块揭秘,你看明白了吗?
为了提升分配 undo 段的效率,事务提交过程中,InnoDB 会缓存一些 undo 段。只要同时满足两个条件,insert undo 段或 update undo 段就能被缓存。1. 关于缓存 undo 段为了提升分...【详细内容】
2024-03-27  Search: MySQL  点击:(11)  评论:(0)  加入收藏
MySQL:BUG导致DDL语句无谓的索引重建
对于5.7.23之前的版本在评估类似DDL操作的时候需要谨慎,可能评估为瞬间操作,但是实际上线的时候跑了很久,这个就容易导致超过维护窗口,甚至更大的故障。一、问题模拟使用5.7.22...【详细内容】
2024-03-26  Search: MySQL  点击:(10)  评论:(0)  加入收藏
从 MySQL 到 ByteHouse,抖音精准推荐存储架构重构解读
ByteHouse是一款OLAP引擎,具备查询效率高的特点,在硬件需求上相对较低,且具有良好的水平扩展性,如果数据量进一步增长,可以通过增加服务器数量来提升处理能力。本文将从兴趣圈层...【详细内容】
2024-03-22  Search: MySQL  点击:(24)  评论:(0)  加入收藏
MySQL自增主键一定是连续的吗?
测试环境:MySQL版本:8.0数据库表:T (主键id,唯一索引c,普通字段d)如果你的业务设计依赖于自增主键的连续性,这个设计假设自增主键是连续的。但实际上,这样的假设是错的,因为自增主键不...【详细内容】
2024-03-10  Search: MySQL  点击:(6)  评论:(0)  加入收藏
准线上事故之MySQL优化器索引选错
1 背景最近组里来了许多新的小伙伴,大家在一起聊聊技术,有小兄弟提到了MySQL的优化器的内部策略,想起了之前在公司出现的一个线上问题,今天借着这个机会,在这里分享下过程和结论...【详细内容】
2024-03-07  Search: MySQL  点击:(28)  评论:(0)  加入收藏
MySQL数据恢复,你会吗?
今天分享一下binlog2sql,它是一款比较常用的数据恢复工具,可以通过它从MySQL binlog解析出你要的SQL,并根据不同选项,可以得到原始SQL、回滚SQL、去除主键的INSERT SQL等。主要...【详细内容】
2024-02-22  Search: MySQL  点击:(45)  评论:(0)  加入收藏
如何在MySQL中实现数据的版本管理和回滚操作?
实现数据的版本管理和回滚操作在MySQL中可以通过以下几种方式实现,包括使用事务、备份恢复、日志和版本控制工具等。下面将详细介绍这些方法。1.使用事务:MySQL支持事务操作,可...【详细内容】
2024-02-20  Search: MySQL  点击:(53)  评论:(0)  加入收藏
为什么高性能场景选用Postgres SQL 而不是 MySQL
一、 数据库简介 TLDR;1.1 MySQL MySQL声称自己是最流行的开源数据库,它属于最流行的RDBMS (Relational Database Management System,关系数据库管理系统)应用软件之一。LAMP...【详细内容】
2024-02-19  Search: MySQL  点击:(38)  评论:(0)  加入收藏
MySQL数据库如何生成分组排序的序号
经常进行数据分析的小伙伴经常会需要生成序号或进行数据分组排序并生成序号。在MySQL8.0中可以使用窗口函数来实现,可以参考历史文章有了这些函数,统计分析事半功倍进行了解。...【详细内容】
2024-01-30  Search: MySQL  点击:(54)  评论:(0)  加入收藏
▌简易百科推荐
MySQL 核心模块揭秘
server 层会创建一个 SAVEPOINT 对象,用于存放 savepoint 信息。binlog 会把 binlog offset 写入 server 层为它分配的一块 8 字节的内存里。 InnoDB 会维护自己的 savepoint...【详细内容】
2024-04-03  爱可生开源社区    Tags:MySQL   点击:(6)  评论:(0)  加入收藏
MySQL 核心模块揭秘,你看明白了吗?
为了提升分配 undo 段的效率,事务提交过程中,InnoDB 会缓存一些 undo 段。只要同时满足两个条件,insert undo 段或 update undo 段就能被缓存。1. 关于缓存 undo 段为了提升分...【详细内容】
2024-03-27  爱可生开源社区  微信公众号  Tags:MySQL   点击:(11)  评论:(0)  加入收藏
MySQL:BUG导致DDL语句无谓的索引重建
对于5.7.23之前的版本在评估类似DDL操作的时候需要谨慎,可能评估为瞬间操作,但是实际上线的时候跑了很久,这个就容易导致超过维护窗口,甚至更大的故障。一、问题模拟使用5.7.22...【详细内容】
2024-03-26  MySQL学习  微信公众号  Tags:MySQL   点击:(10)  评论:(0)  加入收藏
从 MySQL 到 ByteHouse,抖音精准推荐存储架构重构解读
ByteHouse是一款OLAP引擎,具备查询效率高的特点,在硬件需求上相对较低,且具有良好的水平扩展性,如果数据量进一步增长,可以通过增加服务器数量来提升处理能力。本文将从兴趣圈层...【详细内容】
2024-03-22  字节跳动技术团队    Tags:ByteHouse   点击:(24)  评论:(0)  加入收藏
MySQL自增主键一定是连续的吗?
测试环境:MySQL版本:8.0数据库表:T (主键id,唯一索引c,普通字段d)如果你的业务设计依赖于自增主键的连续性,这个设计假设自增主键是连续的。但实际上,这样的假设是错的,因为自增主键不...【详细内容】
2024-03-10    dbaplus社群  Tags:MySQL   点击:(6)  评论:(0)  加入收藏
准线上事故之MySQL优化器索引选错
1 背景最近组里来了许多新的小伙伴,大家在一起聊聊技术,有小兄弟提到了MySQL的优化器的内部策略,想起了之前在公司出现的一个线上问题,今天借着这个机会,在这里分享下过程和结论...【详细内容】
2024-03-07  转转技术  微信公众号  Tags:MySQL   点击:(28)  评论:(0)  加入收藏
MySQL数据恢复,你会吗?
今天分享一下binlog2sql,它是一款比较常用的数据恢复工具,可以通过它从MySQL binlog解析出你要的SQL,并根据不同选项,可以得到原始SQL、回滚SQL、去除主键的INSERT SQL等。主要...【详细内容】
2024-02-22  数据库干货铺  微信公众号  Tags:MySQL   点击:(45)  评论:(0)  加入收藏
如何在MySQL中实现数据的版本管理和回滚操作?
实现数据的版本管理和回滚操作在MySQL中可以通过以下几种方式实现,包括使用事务、备份恢复、日志和版本控制工具等。下面将详细介绍这些方法。1.使用事务:MySQL支持事务操作,可...【详细内容】
2024-02-20  编程技术汇    Tags:MySQL   点击:(53)  评论:(0)  加入收藏
MySQL数据库如何生成分组排序的序号
经常进行数据分析的小伙伴经常会需要生成序号或进行数据分组排序并生成序号。在MySQL8.0中可以使用窗口函数来实现,可以参考历史文章有了这些函数,统计分析事半功倍进行了解。...【详细内容】
2024-01-30  数据库干货铺  微信公众号  Tags:MySQL   点击:(54)  评论:(0)  加入收藏
mysql索引失效的场景
MySQL中索引失效是指数据库查询时无法有效利用索引,这可能导致查询性能显著下降。以下是一些常见的MySQL索引失效的场景:1.使用非前导列进行查询: 假设有一个复合索引 (A, B)。...【详细内容】
2024-01-15  小王爱编程  今日头条  Tags:mysql索引   点击:(85)  评论:(0)  加入收藏
站内最新
站内热门
站内头条