Mysql 5.7 Gtid内部实际案例分析

61次阅读
没有评论

共计 7634 个字符,预计需要花费 20 分钟才能阅读完成。

本篇内容介绍了“Mysql 5.7 Gtid 内部实际案例分析”的有关知识,在实际案例的操作过程中,不少人都会遇到这样的困境,接下来就让丸趣 TV 小编带领大家学习一下如何处理这些情况吧!希望大家仔细阅读,能够学有所成!

一、触发条件

本案列我测试过 4 个版本
percona Mysql 5.7.14
官方社区 Mysql 5.7.17
percona Mysql 5.7.19
percona Mysql 5.7.15
其中 percona Mysql 5.7.14 和官方社区 Mysql 5.7.17 有这个问题。其他版本未知

已知 percona Mysql 5.7.14 或者官方社区 Mysql 5.7.17。

mysqldump 备份没有使用 -F, –flush-logs 选项

Gtid 打开。

二、故障描述

本故障主要是新搭建的 Gtid 主从库,运行一段时间后重启主从必然报错如下:

Last_IO_Error: Got fatal error 1236 from master when reading data from binary log:  The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.

三、故障分析

为什么重启后会报错找到不事物呢,然后发现这个 Gtid 事物在主库的 binlog 中已经没有了,应该是很久以前的。其实这个问题我们要回到 mysqldump 出来的文件如何进行 Gtid 的初始化以及 mysql.gtid_executed 表中。
在 mysqldump 不使用 –set-gtid-purged 的时候必然会在 dump 出来的脚本中包含

-- GTID state at the beginning of the backup 
 SET @@GLOBAL.GTID_PURGED= e859a28b-b66d-11e7-8371-000c291f347d:1-41

这样一个设置 GTID_PURGED 的语句,它包含了主库上已经执行的全部 Gtid 事物。从第五节的源码和总结部分我们知道这个语句至少做了三个更改(DBA 可见的只有三个):

mysql.gtid_executed 表的写入

gtid_executed 变量的修改

gtid_purged 变量的修改

而完成了这一步实际上 mysql.gtid_executed 表是包含了全部的执行过的 Gtid 事物的,但是随后我们看到 dump 脚本包含了如下语句

 210 -- Table structure for table `gtid_executed`
 211 --
 212
 213 DROP TABLE IF EXISTS `gtid_executed`;
 214 /*!40101 SET @saved_cs_client = @@character_set_client */;
 215 /*!40101 SET character_set_client = utf8 */;
 216 CREATE TABLE `gtid_executed` ( 217 `source_uuid` char(36) NOT NULL COMMENT  uuid of the source where the transaction was originally executed. ,
 218 `interval_start` bigint(20) NOT NULL COMMENT  First number of interval. ,
 219 `interval_end` bigint(20) NOT NULL COMMENT  Last number of interval. ,
 220 PRIMARY KEY (`source_uuid`,`interval_start`)
 221 ) ENGINE=InnoDB DEFAULT CHARSET=utf8;
 222 /*!40101 SET character_set_client = @saved_cs_client */;
 223
 224 --
 225 -- Dumping data for table `gtid_executed`
 226 --
 227
 228 LOCK TABLES `gtid_executed` WRITE;
 229 /*!40000 ALTER TABLE `gtid_executed` DISABLE KEYS */;
 230 INSERT INTO `gtid_executed` VALUES (e859a28b-b66d-11e7-8371-000c291f347d ,1,32);
 231 /*!40000 ALTER TABLE `gtid_executed` ENABLE KEYS */;
 232 UNLOCK TABLES;

显然这里我们在 source 的时候从库的 mysql.gtid_executed 将被重新初始化为:

e859a28b-b66d-11e7-8371-000c291f347d ,1,32

而实际的已经执行过的 Gtid 是:

e859a28b-b66d-11e7-8371-000c291f347d:1-41

如前文第五节我们通过源码分析后总结如下:

mysql.gtid_executed 表修改时机
在 binlog 发生切换 (rotate) 的时候保存直到上一个 binlog 文件执行过的全部 Gtid,它不是实时更新的。

因此此时表中并没有完全包含全部执行过的 Gtid 事物,而在前文第六节的源码分析中我们知道在 Gtid 模块启动的时候必须要读取两个 Gtid 持久化的介质:

mysql.gtid_executed

binlog

来判断 Gtid 的集合,显然从库不可能在 binlog 包含这个 Gtid 事物,所以这样的操作步骤就导致了数据库从库后的报错,而这里的正确的步骤是压根不进行 mysql.gtid_executed 的重建和导入,我发现在 percona Mysql 5.7.15 和 percona Mysql 5.7.19 正是这样的。但是为了防范这个问题,我在搭建的 Gtid 从库导完数据后加入了两个个步骤如下:

reset master;set global gtid_purged=e859a28b-b66d-11e7-8371-000c291f347d:1-41

这两步也就是为了从新初始化 mysql.gtid_executed 表,让其正确。
此问题还可以在 mysqldump 的时候加入 -F, –flush-logs 选项规避,但是 - F 会加入如下的 MDL LOCK:

2017-12-18T08:16:39.580985Z 6 Query FLUSH /*!40101 LOCAL */ TABLES
2017-12-18T08:16:39.612598Z 6 Query FLUSH TABLES WITH READ LOCK
2017-12-18T08:16:39.613406Z 6 Refresh
/root/mysql5.7.14/percona-server-5.7.14-7/sql/mysqld, Version: 5.7.14-7-debug-log (Source distribution). started with:
Tcp port: 13001 Unix socket: /root/mysql5.7.14/percona-server-5.7.14-7/mysql-test/var/tmp/mysqld.1.sock
Time Id Command Argument
2017-12-18T08:16:39.965847Z 6 Query SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
2017-12-18T08:16:39.966298Z 6 Query START TRANSACTION /*!40100 WITH CONSISTENT SNAPSHOT */
2017-12-18T08:16:39.966792Z 6 Query SHOW VARIABLES LIKE  gtid\_mode 
2017-12-18T08:16:39.969587Z 6 Query SELECT @@GLOBAL.GTID_EXECUTED
2017-12-18T08:16:39.970216Z 6 Query SHOW STATUS LIKE  binlog_snapshot_% 
2017-12-18T08:16:39.975242Z 6 Query UNLOCK TABLES

这把锁是 GLOBAL 级别的 MDL_SHARED(S)锁,它会等到你说有的 SELECT/DML/DDL 语句结束后才能获得,同时会堵塞全部的 SELECT/DML/DDL 虽然持有时间很短如下:

mysql  flush tables with read lock;
Query OK, 0 rows affected (0.01 sec)
2017-08-03T18:19:11.603911Z 3 [Note] (acquire_lock)THIS MDL LOCK acquire ok!
2017-08-03T18:19:11.603947Z 3 [Note] (MDL PRINT) Thread id is 3: 
2017-08-03T18:19:11.603971Z 3 [Note] (--- MDL PRINT) Namespace is:GLOBAL 
2017-08-03T18:19:11.603994Z 3 [Note] (----- MDL PRINT) Mdl type is:MDL_SHARED(S) 
2017-08-03T18:19:11.604045Z 3 [Note] (------ MDL PRINT) Mdl duration is:MDL_EXPLICIT 
2017-08-03T18:19:11.604073Z 3 [Note] (------- MDL PRINT) Mdl status is:EMPTY 
2017-08-03T18:19:11.604133Z 3 [Note] (acquire_lock)THIS MDL LOCK acquire ok!

当然要了解 MDL LOCK 的朋友可以参考我的文章
http://blog.itpub.net/7728585/viewspace-2143093/
MYSQL METADATA LOCK(MDL LOCK) 学习(1) 理论知识和加锁类型测试

四、故障模拟

知道了原因后也是很好模拟我使用的版本是社区版 5.7.17,搭建过程就是前面说的步骤。只是导完数据后不使用 reset master 和 set gtid_purged 表进行重新初始化 mysql.gtid_executed 表。搭建完成后做几个事物状态正常如下:

mysql  show slave status \G
*************************** 1. row ***************************
 Master_Log_File: binlog.000002
 Read_Master_Log_Pos: 5077
 Relay_Log_File: test1-relay-bin.000002
 Relay_Log_Pos: 2498
 Relay_Master_Log_File: binlog.000002
 Slave_IO_Running: Yes
 Slave_SQL_Running: Yes
 Exec_Master_Log_Pos: 5077
 Relay_Log_Space: 2705
 Last_IO_Errno: 0
 Last_IO_Error: 
 Seconds_Behind_Master: 0
 Retrieved_Gtid_Set: e859a28b-b66d-11e7-8371-000c291f347d:42-49
 Executed_Gtid_Set: e859a28b-b66d-11e7-8371-000c291f347d:1-49
 Auto_Position: 1

但是这个时候我们发现 mysql.gtid_executed 表已经出现了问题如下:

mysql  select * from gtid_executed;
+--------------------------------------+----------------+--------------+
| source_uuid | interval_start | interval_end |
+--------------------------------------+----------------+--------------+
| e859a28b-b66d-11e7-8371-000c291f347d | 1 | 32 |
| e859a28b-b66d-11e7-8371-000c291f347d | 42 | 42 |
| e859a28b-b66d-11e7-8371-000c291f347d | 43 | 43 |
| e859a28b-b66d-11e7-8371-000c291f347d | 44 | 44 |
| e859a28b-b66d-11e7-8371-000c291f347d | 45 | 45 |
| e859a28b-b66d-11e7-8371-000c291f347d | 46 | 46 |
| e859a28b-b66d-11e7-8371-000c291f347d | 47 | 47 |
| e859a28b-b66d-11e7-8371-000c291f347d | 48 | 48 |
| e859a28b-b66d-11e7-8371-000c291f347d | 49 | 49 |
+--------------------------------------+----------------+--------------+

很容易发现 33-41 之间是没有持久化的。如果这个时候如果我们使用 purge binary logs to 来清理掉主库的日志那么必将出现问题,如果不清理也会出现 Gtid 事物重新执行的情况。我们做清理模拟线上错误。主库执行:

mysql  show binary logs;
+---------------+-----------+
| Log_name | File_size |
+---------------+-----------+
| binlog.000001 | 9974 |
| binlog.000002 | 5121 |
| binlog.000003 | 194 |
+---------------+-----------+
3 rows in set (0.01 sec)
mysql  purge binary logs to  binlog.000003 
Query OK, 0 rows affected (0.04 sec)
mysql  show binary logs;
+---------------+-----------+
| Log_name | File_size |
+---------------+-----------+
| binlog.000003 | 194 |
+---------------+-----------+
1 row in set (0.00 sec)

备库重启后错误重现:

mysql  show slave status \G
*************************** 1. row ***************************
 Slave_IO_State: 
 Master_Host: 192.168.190.62
 Master_User: repl
 Master_Port: 3308
 Connect_Retry: 60
 Master_Log_File: binlog.000003
 Read_Master_Log_Pos: 194
 Relay_Log_File: test1-relay-bin.000005
 Relay_Log_Pos: 4
 Relay_Master_Log_File: binlog.000003
 Slave_IO_Running: No
 Slave_SQL_Running: Yes
 Exec_Master_Log_Pos: 194
 Relay_Log_Space: 194
 Last_IO_Errno: 1236
 Last_IO_Error: Got fatal error 1236 from master when reading data from binary log:  The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.
 Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates
 Retrieved_Gtid_Set: e859a28b-b66d-11e7-8371-000c291f347d:42-49
 Executed_Gtid_Set: e859a28b-b66d-11e7-8371-000c291f347d:1-32:42-49
 Auto_Position: 1

我们发现 I /O thread 试图获取主库的 33-41 的 Gtid 事物的事物,已经不能获取,实际上即使能获取也会造成事物的重新执行,我们看到 Executed_Gtid_Set 已经出现了两个连续的区间:

Executed_Gtid_Set: e859a28b-b66d-11e7-8371-000c291f347d:1-32:42-49

“Mysql 5.7 Gtid 内部实际案例分析”的内容就介绍到这里了,感谢大家的阅读。如果想了解更多行业相关的知识可以关注丸趣 TV 网站,丸趣 TV 小编将为大家输出更多高质量的实用文章!

正文完
 
丸趣
版权声明:本站原创文章,由 丸趣 2023-07-20发表,共计7634字。
转载说明:除特殊说明外本站除技术相关以外文章皆由网络搜集发布,转载请注明出处。
评论(没有评论)