mysql binlog rotate_binlog rotate引发的MySQL阻塞事件
背景
在大型MySQL集群增加了新的库,运行正常(没有开启GTID)。几天后将新加入的库开启GTID。
MySQL版本:5.7.19
故障现象
变更后,当业务压力开始上升,发现其中一个节点以大概半小时的频率,业务会间断性地发生阻塞。
分析过程
1.观察故障现象
根据业务研发同事描述,大概每半小时发生一次故障。等到故障发生时,观测到以下现象:
a.show processlist发现有4000左右正在执行的insert,执行时间在10~300s
b. show global variables like 'thread_running' 无响应
c. top观察CPU只使用到1个核,内存正常,iowait值3%左右
d. iostat观察到700M/s read,随后使用iotop观察有一个MySQL线程700M/s read
2.定位700M/s read线程
显然700M/s的读IO极不正常,问题突破点就在这里,接下来我们要找到数据库在做什么导致了这么高的读IO。
iotop可查找到问题线程TID,通过performance_schema.threads查找到对应的MySQL内部真实线程:
(以下截图均为测试环境复现截图,虚拟机IO差很多只有97M/s)
查得MySQL中线程正在做一个insert,且只插入一行数据。
第一反应是insert为什么会造成700M/s的读IO,并且会持续3-5分钟之久?分析insert语句,只插入1行数据,更加不可理解。几次故障观察到同一现象。
3.分析binlog
猜测:这是一个大事务,事务包含了大量insert语句。
解析binlog,使用insert语句中的唯一ID过滤binlog,发现:
a. 这个insert所在事务只有1条insert;
b. 这个insert所在事务位于binlog最末尾。
得到结论:insert语句正常,并非大事务。那是什么原因?“insert所在事务位于binlog最末尾”好像有点意思。
继续解析binlog,发现几次故障时的insert所在事务也是位于binlog最末尾。
这不是巧合,应该与binlog rotate有关!好像发现了什么!
4.确认故障与binlog rotate相关联
前面提到每次故障发生,MySQL的thread_running会飙升至4000左右,并且无响应。
通过这个信息,我们打开监控图表,对照binlog的刷新时间点,基本吻合。
到这里,我们基本可以认为故障与binlog rotate是相关联的。接下来就是验证了。
5.复现与验证
情况紧急,接下来的操作需要在从库(因为从库也发生过故障导致了主从切换)验证,从库执行flush logs手工刷新binlog,并使用strace观测MySQL到底做了什么导致了700M/s的读IO。
a. 开启strace,strace -o /tmp/strace_output.txt -T -tt -f -e trace=read,open -p 'mysql_pid'
b. 从库flush logs;
c. iotop观察到有一个700M/s读的线程,问题复现!
d. 关闭strace
6.原因定位
(以下截图均为测试环境复现截图,虚拟机IO差很多只有97M/s)
上一步复现了故障,并且获取strace信息,接下来进行分析:
看到strace信息中大量重复的文件句柄号:
统计strace信息中 文件句柄72 的总行数,占strace信息总行数的90%以上,由此可大致判断:对文件句柄72存在大量读操作:
查看MySQL进程下的文件句柄,发现 文件句柄72 对应文件为binlog:
再分析strace信息中open函数,发现open的文件都是binlog,且在按顺序打开binlog文件!离真相越来越近了:)
这时我们脑海里会出现一个问题:为什么binlog刷新时会从头至尾扫描binlog?
扫描脑子里的知识库:binlog_gtid_simple_recovery
以下是MySQL官方手册解释:
结合源码归纳后可以理解为:
当MySQL重启,且当MySQL重启,且binlog_gtid_simple_recovery=false:
更新gtid_executed,从最新的binlog开始扫描,直到找到第一个有Previous_gtids_log_event的binlog为止;
更新gtid_purged,从最旧的binlog开始扫描,直到找到第一个有Previous_gtids_log_event的binlog为止;
当MySQL重启,且binlog_gtid_simple_recovery=true:
更新gtid_executed,只扫描最新的那个binlog,如果这个binlog不包含gtid,直接将GLOBAL.GTID_EXECUTED设置为空;
更新gtid_purged,只扫描最旧的那个binlog,如果这个binlog不包含gtid,直接将GLOBAL.GTID_PURGED设置为空;
当删除binlog,且binlog_gtid_simple_recovery=false:
更新gtid_purged,从最旧的binlog开始扫描,直到找到第一个有Previous_gtids_log_event的binlog为止;
当删除binlog,且binlog_gtid_simple_recovery=true:
更新gtid_purged,只扫描最旧的那个binlog,如果这个binlog不包含gtid,直接将GLOBAL.GTID_PURGED设置为空;
另外还有一种情况就是relay_log_recovery=0的情况,扫描relay_log以更新all_gtids (Retrieved_Gtid_Set)
故障MySQL设置是
故障MySQL设置是binlog_gtid_simple_recovery=false,并且变更前是没有开启GTID的,意味着有一百多个binlog没有记录GTID,所以大量的读IO发生在扫描这一百多个binlog,符合故障现象。
再等等,好像有什么不对?我们的故障现场是binlog rotate(包括手工flush logs),和手册上描述的“MySQL重启”、“binlog被删除”不是一回事啊!
排除法:故障时MySQL并没有重启,那就是“binlog被删除”导致的了。
解到这里只剩最后一个问题了:binlog rotate(和手工flush logs)会导致binlog被删除吗?
答案是:expire_logs_days
再看下官方手册:
翻译一下就是:当开启了expire_logs_days,MySQL会自动删除binlog,触发条件是“启动”和“binlog的刷新”。
再次验证,在数据库中执行purge binary logs to 'mysql-bin.xxx',观察strace,iotop能够稳定复现故障现象。
结论
MySQL由非GTID模式到开启GTID,之前的binlog(一百多个)都没有记录GTID。
开启GTID后,受参数expire_logs_days=5影响,每次binlog rotate时会触发binlog的自动删除,当binlog被删除时:
由于参数binlog_gtid_simple_recovery=false,MySQL会从头至尾扫描binlog直到找到第一个有Previous_gtids_log_event的binlog为止。最终造成了数据库阻塞。
解决方案
删除没有记录GTID的binlog,因为purge binary logs to 'xxx'命令会触发binlog扫描,所以这里只能使用rm方式进行删除,删除后将mysql-bin.index文件中对应的行删除,注意不留空行。
如何避免
最好是创建数据库时直接启用GTID,GTID的好处谁用谁知道;
当MySQL由非GTID模式升级为开启GTID时:
1. 设置参数binlog_gtid_simple_recovery=true;
2. 重启MySQL后,备份binlog,执行reset master;
3. 运行后不要切换GTID模式,以免造成GTID的紊乱。
mysql binlog rotate_binlog rotate引发的MySQL阻塞事件相关推荐
- mysql多实例复制,Mysql实例使用Rotate Master实现MySQL 多主复制的实现方法
搜索热词 <MysqL实例使用Rotate Master实现MysqL 多主复制的实现方法>要点: 本文介绍了MysqL实例使用Rotate Master实现MysqL 多主复制的实现方法 ...
- mysql binlog 大数据_后起之秀 | MySQL Binlog增量同步工具go-mysql-transfer实现详解
一. 概述 工作需要研究了下阿里开源的MySQL Binlog增量订阅消费组件canal,其功能强大.运行稳定,但是有些方面不是太符合需求,主要有如下三点: 需要自己编写客户端来消费canal解析到的 ...
- mysql binlog线程恢复_使用MySQL SQL线程回放Binlog实现恢复
[toc] 1. 需求部分 1.1 基于MySQL复制同步特性,尝试使用Replication的SQL线程来回放binlog,可基于以下逻辑模拟场景 做全量xtrabackup备份模拟日常备份 执行s ...
- mysql binlog 目录_怎么查看mysql 的binlog日志存放的位置(linux和win)
这个你可以看配置文件 启用了才有这样的记录默认是没有的 linux系统中的/etc/my.cnf my.cnf内容: log-bin = mysqlbin # 默认配置 比如上面的设置重启数据库会生成 ...
- 浅谈MySQL Binlog
1 什么是binlog? binlog是二进制日志文件,用于记录mysql的数据更新或者潜在更新状况,在mysql主从复制中就是依靠的binlog.可以通过语句"show binlog ev ...
- Mysql Binlog三种格式详细介绍
binlog 的不同模式有什么区别呢? 1.Statement:每一条会修改数据的sql都会记录在binlog中. 优点:不需要记录每一行的变化,减少了binlog日志量,节约了IO,提高性能.(相比 ...
- MySQL Binlog三种格式介绍及分析
一.Mysql Binlog格式介绍 Mysql binlog日志有三种格式,分别为Statement,MiXED,以及ROW! 1.Statement:每一条会修改数据的sql都会记录在binlog ...
- mysql binlog mixed_MySQL Binlog三种格式介绍及分析
MySQL binlog日志有三种格式,分别为Statement,MiXED,以及ROW! 1.Statement:每一条会修改数据的sql都会记录在binlog中. 优点:不需要记录每一行的变化, ...
- MySQL Binlog 介绍
Binlog 简介 MySQL中一般有以下几种日志: 日志类型 写入日志的信息 错误日志 记录在启动,运行或停止mysqld时遇到的问题 通用查询日志 记录建立的客户端连接和执行的语句 二进制日志 记 ...
最新文章
- STP HSRP和NAT结合实现网络出口的冗余和次优路径分析
- 微软重新设计 Edge for Android 的用户界面
- 数据窗口dw导出多种格式文件
- 10款最赞的ROS机器人操作系统课程+为何ROS不是必须的
- .rpt文件内容读取java_Java项目读取配置文件时,找不到指定的文件???
- TEXT到EPUB格式转换
- MySQL 有哪些锁?
- 纵观 ActiveX 平台的兴衰史,看开发控件的技术演变
- Prettier formatter for vscode 配置单引号问题
- 隐藏OEM分区的解决办法和推荐的清理磁盘的方法
- 51CTO专访人人网黄晶:WEB开发需要随需应变(2)
- SqlParameter应用实例 实验日记
- 函数的值域【基础辅导和中阶辅导】
- 1、去除图像中的alpha通道或透明度
- (马蹄集)直线切平面 线段 圆切平面
- 记字节社招Java一面
- 暑期实习vs日常实习,它们究竟有什么区别?
- 常用七种排序之冒泡排序(排序图解+分析Java
- 输出含有9和9的倍数
- DPDK技术系统学习一(接收,发送,arp,icmp功能测试)
热门文章
- 超级计算机和人比,和超级计算机相比,人类的大脑很弱吗
- 一个按键控制数码管的开和关_基于FPGA的数字电路实验3:点亮数码管
- php stortime,文件存储 | 综合话题 | Laravel 5.3 中文文档
- affine工程难点、亮点汇总
- 【C++】智能指针详解
- 开源项目推荐:CNC+CRC/SoftPLC/OpenCASCADE/CAD/CAM
- Android开发之通过反射获取全局的application
- 计算机科学与教育信息化国际会议,A Courses Ontology System for Computer Science Education...
- 深入理解session过期机制
- 再谈 retain,copy,mutableCopy(官方SDK,声明NSString都用copy非retain)