老叶茶馆 关注
手机版

深入理解MySQL 5.7 GTID系列(九):实际案例一

  1. 云栖社区>
  2. 老叶茶馆>
  3. 博客>
  4. 正文

深入理解MySQL 5.7 GTID系列(九):实际案例一

技术小能手 2018-04-13 14:02:35 浏览5095 评论0

摘要: 原文地址: https://www.jianshu.com/p/2c25842d58d3 深入理解MySQL 5.7 GTID系列文章共十篇,本文为第四篇,点击查看: 第一篇:深入理解MySQL 5.

原文地址:

https://www.jianshu.com/p/2c25842d58d3

深入理解MySQL 5.7 GTID系列文章共十篇,本文为第四篇,点击查看:

第一篇:深入理解MySQL 5.7 GTID系列(一)

第二篇:深入理解MySQL 5.7 GTID系列(二):GTID相关内部数据结构

第三篇:深入理解MySQL 5.7 GTID系列(三):GTID的生成时机

第四篇:

深入理解MySQL 5.7 GTID系列(四):mysql.gtid_executed&PREVIOUS GTID EVENT

第五篇:深入理解MySQL 5.7 GTID系列(五) gtid_executed&gtid_purged什么时候更新

第六篇:深入理解MySQL 5.7 GTID系列(六):MySQL启动初始化GTID模块

第七篇:深入理解MySQL 5.7 GTID系列(七)binlog_gtid_simple_recovery参数的影响总结

第八篇:深入理解MySQL 5.7 GTID系列(八):GTID带来的运维改变

该系列文章将陆续不定期更新~

一、触发条件

d47e62d2b349aca45e42305ed6714efbe5ed61d9binlog_gtid_simple_recovery=false。
d47e62d2b349aca45e42305ed6714efbe5ed61d95.7.6以上版本。

d47e62d2b349aca45e42305ed6714efbe5ed61d9GTID 关闭或者GTID中途开启有大量的未开启GTID的BINLOG。

二、本案例回顾

d47e62d2b349aca45e42305ed6714efbe5ed61d9版本:MySQL版本 5.7.19。
d47e62d2b349aca45e42305ed6714efbe5ed61d9故障为:大概每半小时发生一次故障,整个MySQL压力巨大,很多简单的操作都相应缓慢。使用iotop,top等工具都发现MySQL某个线程有大量的I/O。
d47e62d2b349aca45e42305ed6714efbe5ed61d9分析方法:使用strace发现有大量的BINLOG文件读取。
d47e62d2b349aca45e42305ed6714efbe5ed61d9binlog_gtid_simple_recovery=false。
d47e62d2b349aca45e42305ed6714efbe5ed61d9GTID关闭,中途开启,但是留下了很多未开启GTID的BINLOG。

d47e62d2b349aca45e42305ed6714efbe5ed61d9数据库没有重启,但是由于expire_logs_days触发了BINLOG删除。

三、故障分析

其实本案例就是前文第七部分总结中的:

Gtid关闭,simple_recovery=flase
5.7.6以上:这种方式一定得到正确的Gtid集合
重启Mysql不扫秒全部的binlog,如果是中途打开GTID重启任然需要扫描多个binlog因为需要找到Gtid event。
purge binlog或者超过参数expire_logs_days参数设置不触发全binlog扫描,如果是中途打开GTID重启

仍然需要扫描多个binlog因为需要找到Gtid event。

从案例中我们得知是中途开启的GTID,但是留下了很多未开启GTID的BINLOG,从第六部分源码bool MYSQL_BIN_LOG::init_gtid_sets()函数的分析,我们知道删除BINLOG后也会触发正向查找来获取gtid_purged(Gtid_state.lost_gtids)。当读取到第一个BINLOG的时候虽然获取到了PREVIOUS GTID EVENT但是没有GTID EVENT,而simple_recovery=flase所以需要继续查找下一个文件,直到找到同时包含PREVIOUS GTID EVENT和GTID EVENT的 那个BINLOG才会停止,那么显然这种情况下那些GTID关闭的时候生成的BINLOG将会全部扫描一遍,如果量大那么代价将是巨大的。
而案例中每半个小时会触发一次BINLOG切换,因为触发超过expire_logs_days参数设置导致BINLOG进行删除,触发了大量的BINLOG扫描。
显然有了前面的基础这个案例很容易分析。

四、案例模拟

这个案例非常好模拟。我打算直接使用strace查看。因为不是每位朋友都能方便使用GDB调试。
使用测试版本社区版本5.7.17:

+---------------+-----------+
| Log_name | File_size |
+---------------+-----------+
| binlog.000027 | 198 |
| binlog.000028 | 198 |
| binlog.000029 | 198 |
| binlog.000030 | 198 |
| binlog.000031 | 198 |
| binlog.000032 | 198 |
| binlog.000033 | 198 |
| binlog.000034 | 198 |
| binlog.000035 | 198 |
| binlog.000036 | 198 |
| binlog.000037 | 198 |
| binlog.000038 | 198 |
| binlog.000039 | 198 |
| binlog.000040 | 198 |
| binlog.000041 | 198 |
| binlog.000042 | 198 |
| binlog.000043 | 154 |
+---------------+-----------+

mysql> show variables like '%gtid%';
+----------------------------------+-----------+
| Variable_name | Value |
+----------------------------------+-----------+
| binlog_gtid_simple_recovery | OFF |
| enforce_gtid_consistency | ON |
| gtid_executed_compression_period | 1000 |
| gtid_mode | OFF |
| gtid_next | AUTOMATIC |
| gtid_owned | |
| gtid_purged | |
| session_track_gtids | OFF |
+----------------------------------+-----------+
8 rows in set (0.02 sec)
mysql> show variables like '%expir%';
+--------------------------------+-------+
| Variable_name | Value |
+--------------------------------+-------+
| disconnect_on_expired_password | ON |
| expire_logs_days | 1 |
+--------------------------------+-------+
2 rows in set (0.06 sec)

然后我修改了系统时间同时MySQL开启GTID:

[root@test1 ~]# date -s '2017-12-13 10:10:10'
Wed Dec 13 10:10:10 CST 2017
mysql> set global gtid_mode=1;
Query OK, 0 rows affected (0.02 sec)

mysql> set global gtid_mode=2;
Query OK, 0 rows affected (0.01 sec)

mysql> set global gtid_mode=3;
Query OK, 0 rows affected (0.02 sec)

mysql> show variables like '%gtid_mode%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| gtid_mode | ON |
+---------------+-------+
1 row in set (0.02 sec)

到一步我们已经达到了触发的标准,只要手动触发一次flush binary logs,让BINLOG刷新就会看到。当然线上是BINLOG满了做的切换。
这个时候开始做strace,并且做flush binary logs ,我们观察到:

0e52545ab1b769996cc0ddc1b4a10cbe6e699a11

受限篇幅我这里删除了一些。我们看到很多read/lseek系统调用正是读取BINLOG的证据。
至此整个案例模拟完成。
五、总结

前文已经描述过在5.7.6以上binlog_gtid_simple_recovery应该设置为true,这样可以避免可能的大量的BINLOG的扫描。具体分析可以参考第七节和从第六部分源码bool MYSQL_BIN_LOG::init_gtid_sets()函数的分析。


原文发布时间为:2018-04-13
本文作者:高鹏(重庆八怪)
本文来自云栖社区合作伙伴“老叶茶馆”,了解相关信息可以关注“老叶茶馆”。

用云栖社区APP,舒服~

【云栖快讯】诚邀你用自己的技术能力来用心回答每一个问题,通过回答传承技术知识、经验、心得,问答专家期待你加入!  详情请点击

网友评论

技术小能手
文章6417篇 | 关注1451
关注
MySQL 是全球最受欢迎的开源数据库,阿里云MySQL版 通过深度的内核优化和独享实例提供... 查看详情
是基于语音识别、语音合成、自然语言理解等技术,为企业在多种实际应用场景下,赋予产品“能听、会... 查看详情
支持 PB 级数据存储的海量分布式关系型数据库。它支持 MySQL 数据库接口,采用可扩展的... 查看详情
为您提供简单高效、处理能力可弹性伸缩的计算服务,帮助您快速构建更稳定、安全的应用,提升运维效... 查看详情
阿里云总监课正式启航

阿里云总监课正式启航