MySQL alter table时执行innobackupex全备再谈Seconds_Behind_Master

作者: 东山絮柳仔

1.场景描述

早上7:25 接到Report中心同学告警,昨天业务报表数据没有完整跑出来,缺少500位业务员的数据,并且很快定位到,缺少的是huabei_order库上的数据。Report中心的数据是BI每天5:15从huabei_order库的从库上抽取。查看监控告警,从库实例确实在4:50 –6:00 有延迟,但已恢复。报表数据不完整,直接原因就是主从延迟。 7:50 确认主从延迟已恢复,请求BI重新抽取数据,重新生成报表。 8:20 报表数据验证无误。 问题还没结束:

忽略监控告警的不及时、不完整。 还需要回答的问题是为什么在业务低峰期会出现延迟?是什么操作造成的?【问题1】 监控界面主从延迟指标

看到这样的走势图,又一个需要思考的问题:为什么延迟会瞬间飙升到24440s以上(实际可能已达25K以上),延迟不应该是逐渐累积的吗?【问题2】

确实是业务低峰期,和研发、产品、业务确认,23:30 之后没有大的操作、大的流量,也没有特别的活动、促销。从数据库Server业务压力上考虑,确实没有特殊的操作。

忽然想到,备份,完整备份。们的灾备,数据库的完整备份实在从库上做的,cron 设置在每天的00:05 , 一般执行2个小时, 并且是周二、周五执行,当天正好是周二。

虽然自己也不太相信这个就是真正的原因,但毕竟是一个可考虑的因素。查看完整备份的log。

2.全量备份

失败 报错信息如下:

210831 04:49:46 >> log scanned up to (1168680308582)
210831 04:49:47 >> log scanned up to (1168680308668)
210831 04:49:48 >> log scanned up to (1168680308770)
210831 04:49:49 >> log scanned up to (1168680308856)
210831 04:49:50 >> log scanned up to (1168680308942)
210831 04:49:51 >> log scanned up to (1168680309028)
210831 04:49:52 >> log scanned up to (1168680309114)
InnoDB: Last flushed lsn: 1168515708469 load_index lsn 1168680309114InnoDB: An optimized (without redo logging) DDLoperation has been performed. All modified pages may not have been flushed to the disk yet.
PXB will not be able take a consistent backup. Retry the backup operation
mysql: [Warning] Using a password on the command line interface can be insecure.

失败了,并且时间都很吻合,04:49 完整备份失败,04:49 主从延迟瞬间飙升。

查看完整备份历史,过去备份耗时在2个小时左右,而本次备份执行了4个小时50分钟,还失败了。

(说明:从完整备份打印的log来看,打印FLUSH TABLES WITH READ LOCK时,完整备份就快结束了,所以,在此图上,通过FLUSH TABLES WITH READ LOCK的时间代表完整备份结束的时间) 到此时,相信很多同学,已经准备把锅甩给完整备份了。 需要思考的问题 :DDL操作和xtrabackup是怎么相互影响的?为什么全量备份失败后,延迟问题才会马上被监控到(Seconds_Behind_Master才显示异常)?【问题3】

3.继续分析原因,寻找DDL

每个问题都不简单。

们先看问题3.DDL操作和xtrabackup是怎么相互影响的?为什么全量备份失败后,延迟问题才会马上被监控到(Seconds_Behind_Master才显示异常)?【问题3】

回答这个问题,需要先找到具体的DDL操作。

但是备份期间没有执行过DDL操作。上次一DDL操作 要追溯到前一天19:50。迷雾重重、元凶隐隐。

想到MySQL DDL操作,一般执行时间相对较长,slow log 中或许有蛛丝马迹。 ELK–MySQL日志系统走起。

还是找到了一条大鱼,alter table ,添加字段。时间点吻合(04:49),执行时间超长25438秒(并且和Seconds_Behind_Master飙升后的值很接近 )。 从库DDL执行log

25438秒 ≈ 7 小时

从库所有的操作都来自主库,接下来,们看下主库啥时候执行DDL的。 主库DDL执行情况

主库执行了 5089 秒,结束于 前一天的21:18。向前推 5089 秒,也就是 19:50前后。

为什么执行时间会这么长呢?这张表确实是大表、宽表–1.6 亿 数据量、130G大小,其信息如下:

所以,到现在,才算把主从延迟的问题定位到—–DDL 和 innobackupex。两者相互影响、相互拖累,才导致这个时间段内的延迟产生。这也算问题1的答案吧。

4.Seconds_Behind_Master问题解答

此处们尝试问答第二个问题:为什么延迟,会瞬间飙升到24440S以上,延迟不应该是逐渐累积的吗?【问题2】 么先看下主从复制指标:Seconds_Behind_Master 的官方描述 Seconds_Behind_Master: The number of seconds that the replication SQL thread is behind processing the source's binary log. A high number (or an increasing one) can indicate that the replica is unable to handle events from the source in a timely fashion. A value of 0 for Seconds_Behind_Master can usually be interpreted as meaning that the replica has caught up with the source, but there are some cases where this is not strictly true. For example, this can occur if the network connection between source and replica is broken but the replication I/O thread has not yet noticed this—that is, slave_net_timeout has not yet elapsed. It is also possible that transient values for Seconds_Behind_Master may not reflect the situation accurately. When the replication SQL thread has caught up on I/O, Seconds_Behind_Master displays 0; but when the replication I/O thread is still queuing up a new event, Seconds_Behind_Master may show a large value until the SQL thread finishes executing the new event. This is especially likely when the events have old timestamps; in such cases, if you execute SHOW SLAVE STATUS several times in a relatively short period, you may see this value change back and forth repeatedly between 0 and a relatively large value. Check the Seconds_Behind_Master column in the output from SHOW REPLICA | SLAVE STATUS. When the replication SQL thread executes an event read from the source, it modifies its own time to the event timestamp. (This is why TIMESTAMP is well replicated.) In the Time column in the output of SHOW PROCESSLIST, the number of seconds displayed for the replication SQL thread is the number of seconds between the timestamp of the last replicated event and the real time of the replica machine. You can use this to determine the date of the last replicated event. Note that if your replica has been disconnected from the source for one hour, and then reconnects, you may immediately see large Time values such as 3600 for the replication SQL thread in SHOW PROCESSLIST. This is because the replica is executing statements that are one hour old.

通过以上的描述 和 本 Case 中 Seconds_Behind_Master 的数字变化: Seconds_Behind_Master 似乎应该为:SQL thread 重做主节点同步过来的binlog even, 执行提交后,比较从节点执行even的时间和主节点binlog event 中的时间所得到时间差。

再回答这个问题, Seconds_Behind_Master瞬间飙升到24440S 以上【因为们的telegraf 抓取是20S一次,并且从监控库图上可看到,有一个快速下降趋势,所以,真正的最大值应该为25K以上,很可能会比慢查询的25438 还稍微大些】,这个值是怎么来的?应该就是从库DDL提交的时刻【04:49】减去主库DDL提交的时刻【前一天的21:18】的差值。 – 这也算问题2的答案吧。

所以,Seconds_Behind_Master = 0 时,主从延迟可能已经很厉害了,除了官网提到的网络问题,还有就是从库正则执行同步过来的大DDL(尚未提交)。例如在本例的00:00—04:00 其实已经存在延迟了。

5.innobackupex知识补充

关于问题 3中 为什么全量备份失败后,延迟问题才会马上被监控到(Seconds_Behind_Master才显示异常)? 目前来看,尚未分析到直接因果关系,应该是概率事件。 innobackupex备份流程图如下:

经过验证测试,innobackupex备份开始时,并不是先看当前数据库是否有DDL操作,而是其中的某个线程在备份这张表时(或 scan lsn)才判断是否有DDL,有则推出报错。验证方法,在一张大表上执行DDL(保证DDL时间足够长),在DDL运行期间,开始备份,们看到这个很多表在执行copy备份,是运行了一段时间后,才报错的。

此外, innobackupex备份过程中,执行DDL,都会导致备份失败,与表大小无关,即使这张表只有一笔数据。 补充说明: MySQL版本为5.7.22 innobackupex的版本为 innobackupex version 2.4.9 Linux (x86_64) (revision id: a467167cdd4)

6.参考文献

1.mysqldump与innobackupex备份过程知多少(完结篇) https://blog.csdn.net/joy0921/article/details/80130860 2.MySQL中的seconds_behind_master的理解 https://www.cnblogs.com/drizzle-xu/p/9713350.html?ivk_sa=1024320u 3.How do I know how late a replica is compared to the source? https://dev.mysql.com/doc/refman/8.0/en/faqs-replication.html

原文创作:东山絮柳仔

原文链接:https://www.cnblogs.com/xuliuzai/p/15216768.html

文章列表

更多推荐

更多
  • MySQL实战宝典-27分布式事务:我们到底要不要使用2PC? 27 分布式事务:我们到底要不要使用 2PC?计。但是我们一直在回避分布式数据库中最令人头疼的问题,那就是分布式事务。 今天,我们就来学习分布式事务的概念,以及如何在海量互联网业务中实现它。 分布式事务概念 事务的概念相信你已经非
  • MySQL实战宝典-11索引出错:请理解CBO的工作原理 11 索引出错:请理解 CBO 的工作原理的使用已经有了一定的了解。 而在实际工作中,我也经常会遇到一些同学提出这样的问题:MySQL 并没有按照自己的预想来选择索引,比如创建了索引但是选择了全表扫描,这肯定是 MySQL 数据库的
  • MySQL实战宝典-21数据库备份:备份文件也要检查! 21 数据库备份:备份文件也要检查!据库可以进行切换(比如 20 讲基于复制或者 InnoDB Cluster 技术的高可用解决方案)。 除了高可用设计外,对架构师来说,还要做好备份架构的设计。因为我们要防范意外情况的发生,比如黑客删
  • MySQL实战宝典-15MySQL复制:最简单也最容易配置出错 15 MySQL 复制:最简单也最容易配置出错结构设计、索引设计。对业务开发的同学来说,掌握这些内容已经能很好地面向业务逻辑进行编码工作了。 但是业务需要上线,所以除了表和索引的结构设计之外,你还要做好高可用的设计。因为在真实的生产环
  • MySQL实战宝典-07表的访问设计:你该选择SQL还是NoSQL? 07 表的访问设计:你该选择 SQL 还是 NoSQL?的访问选型。这样一来,字段类型选择 + 物理存储设计 + 表的访问设计,就完成了表结构设计的所有内容。 前面 6 讲,我演示的都是通过 SQL 的方式对表进行访问,但从 MySQ
  • MySQL实战宝典-17高可用设计:你怎么活用三大架构方案? 17 高可用设计:你怎么活用三大架构方案?是为了铺垫 MySQL 数据库的高可用架构设计。因为复制是高可用的基础,但只用复制同步数据又远远不够,你还要结合自己的业务进行高可用设计。 同时,高可用也不仅仅是数据库的事情,你要从业务的全流
  • MySQL实战宝典-06表压缩:不仅仅是空间压缩 06 表压缩:不仅仅是空间压缩用户表、订单表。既然我们已经掌握了表的逻辑设计,那这一讲就继续学习不同业务表的物理存储设计。 据我观察,很多同学不会在表结构设计之初就考虑存储的设计,只有当业务发展到一定规模才会意识到问题的严重性。而物理
  • MySQL实战宝典-19高可用套件:选择这么多,你该如何选? 19 高可用套件:选择这么多,你该如何选?求,通过无损半同步复制的方式进行三园区的同城容灾设计,以及三地务中心的跨城容灾设计。 但是当数据库发生宕机时,MySQL 的主从复制并不会自动地切换,这需要高可用套件对数据库主从进行管理。
  • MySQL实战宝典-09索引组织表:万物皆索引 09 索引组织表:万物皆索引步深入了解 MySQL 的 B+ 树索引的具体使用,这一讲我想和你聊一聊 MySQL InnoDB 存储引擎的索引结构。 InnoDB 存储引擎是 MySQL 数据库中使用最为广泛的引擎,在海量大并发的 OL
  • MySQL实战宝典-12JOIN连接:到底能不能写JOIN? 12 JOIN 连接:到底能不能写 JOIN?优工作。但除了单表的 SQL 语句,还有两大类相对复杂的 SQL,多表 JOIN 和子查询语句,这就要在多张表上创建索引,难度相对提升不少。 而很多开发人员下意识地认为 JOIN 会降低
  • 近期文章

    更多
    文章目录

      推荐作者

      更多