mysqldump 5.7.36版本GTID不一致bug

原创王运亮 2023-02-19

892

有一个简单需求：用mysqldump在线备份主库，使用基于GTID方式重建从库。当在从库初始化数据后，数据同步出现不一致现象，随即排查，思路如下：

备份、还原数据时是否存在错误？
从库初始化@@GLOBAL.GTID_PURGED时，是否正确？

检查后发现，是由于mysqldump存在bug导致。下面重现下这个问题：

主库创建测试表

mysql> create table test(id int);
Query OK, 0 rows affected (0.13 sec)
mysql> insert into test(id) values(1);
Query OK, 1 row affected (0.02 sec)
mysql> select * from test;
+------+
| id   |
+------+
|    1 |
+------+
1 row in set (0.00 sec)

#记录当前Exceuted_Gtid_Set
mysql> show master status;
+------------------+----------+--------------+------------------+-------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                         |
+------------------+----------+--------------+------------------+-------------------------------------------+
| mysql-bin.000016 | 10503869 |              |                  | d58fd9cd-4cbe-11ed-a864-000c291479a8:1-80 |
+------------------+----------+--------------+------------------+-------------------------------------------+
1 row in set (0.00 sec)

主库开启general_log

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

mysql> show variables like 'general_log%';
+------------------+----------------------------------------+
| Variable_name    | Value                                  |
+------------------+----------------------------------------+
| general_log      | ON                                     |
| general_log_file | /data/mysql/mysql_3306/vm-mysql-01.log |
+------------------+----------------------------------------+
2 rows in set (0.02 sec)

#清空general log
mysql> system echo "" > /data/mysql/mysql_3306/vm-mysql-01.log

主库mysqldump5.7.36备份

#使用mysqldump5.7.36版本进行全库备份
/usr/local/mysql-5.7.36-linux-glibc2.12-x86_64/bin/mysqldump \
--protocol=TCP \
--host=127.0.0.1 \
--port=3306 \
--user=root \
--password="xxxxxx" \
--hex-blob \
--single-transaction \
--master-data=2 \
--set-gtid-purged=ON \
--all-databases  \
--triggers --routines --events \
 > /tmp/full_3306-5.7.36.sql

#查看备份文件: /tmp/full_3306-5.7.36.sql

-- MySQL dump 10.13  Distrib 5.7.36, for linux-glibc2.12 (x86_64)
--
-- Host: 127.0.0.1    Database:
-- ------------------------------------------------------
-- Server version       5.7.39-log

/*!40101 SET @OLD_CHARACTER_SET_CLIENT=@@CHARACTER_SET_CLIENT */;
/*!40101 SET @OLD_CHARACTER_SET_RESULTS=@@CHARACTER_SET_RESULTS */;
/*!40101 SET @OLD_COLLATION_CONNECTION=@@COLLATION_CONNECTION */;
/*!40101 SET NAMES utf8 */;
/*!40103 SET @OLD_TIME_ZONE=@@TIME_ZONE */;
/*!40103 SET TIME_ZONE='+00:00' */;
/*!40014 SET @OLD_UNIQUE_CHECKS=@@UNIQUE_CHECKS, UNIQUE_CHECKS=0 */;
/*!40014 SET @OLD_FOREIGN_KEY_CHECKS=@@FOREIGN_KEY_CHECKS, FOREIGN_KEY_CHECKS=0 */;
/*!40101 SET @OLD_SQL_MODE=@@SQL_MODE, SQL_MODE='NO_AUTO_VALUE_ON_ZERO' */;
/*!40111 SET @OLD_SQL_NOTES=@@SQL_NOTES, SQL_NOTES=0 */;
SET @MYSQLDUMP_TEMP_LOG_BIN = @@SESSION.SQL_LOG_BIN;
SET @@SESSION.SQL_LOG_BIN= 0;

--
-- Position to start replication or point-in-time recovery from
--

-- CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000016', MASTER_LOG_POS=10503869;

...省略库、表部分

--
-- GTID state at the end of the backup
--

SET @@GLOBAL.GTID_PURGED='d58fd9cd-4cbe-11ed-a864-000c291479a8:1-81';
/*!40103 SET TIME_ZONE=@OLD_TIME_ZONE */;

/*!40101 SET SQL_MODE=@OLD_SQL_MODE */;
/*!40014 SET FOREIGN_KEY_CHECKS=@OLD_FOREIGN_KEY_CHECKS */;
/*!40014 SET UNIQUE_CHECKS=@OLD_UNIQUE_CHECKS */;
/*!40101 SET CHARACTER_SET_CLIENT=@OLD_CHARACTER_SET_CLIENT */;
/*!40101 SET CHARACTER_SET_RESULTS=@OLD_CHARACTER_SET_RESULTS */;
/*!40101 SET COLLATION_CONNECTION=@OLD_COLLATION_CONNECTION */;
/*!40111 SET SQL_NOTES=@OLD_SQL_NOTES */;

-- Dump completed on 2023-02-12 23:10:49

#查看general log: /data/mysql/mysql_3306/vm-mysql-01.log

2023-02-12T23:10:47.185865+08:00           31 Connect   root@127.0.0.1 on  using SSL/TLS
2023-02-12T23:10:47.189021+08:00           31 Query     /*!40100 SET @@SQL_MODE='' */
2023-02-12T23:10:47.191633+08:00           31 Query     /*!40103 SET TIME_ZONE='+00:00' */
2023-02-12T23:10:47.193818+08:00           31 Query     FLUSH /*!40101 LOCAL */ TABLES
2023-02-12T23:10:47.196899+08:00           31 Query     FLUSH TABLES WITH READ LOCK
2023-02-12T23:10:47.198546+08:00           31 Query     SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
2023-02-12T23:10:47.199749+08:00           31 Query     START TRANSACTION /*!40100 WITH CONSISTENT SNAPSHOT */
2023-02-12T23:10:47.201860+08:00           31 Query     SHOW VARIABLES LIKE 'gtid\_mode'
2023-02-12T23:10:47.257565+08:00           31 Query     SHOW MASTER STATUS
2023-02-12T23:10:47.258572+08:00           31 Query     UNLOCK TABLES
2023-02-12T23:10:47.259875+08:00           31 Query     SELECT LOGFILE_GROUP_NAME, FILE_NAME, TOTAL_EXTENTS, INITIAL_SIZE, ENGINE, EXTRA FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'UNDO LOG' AND FILE_NAME IS NOT NULL AND LOGFILE_GROUP_NAME IS NOT NULL GROUP BY LOGFILE_GROUP_NAME, FILE_NAME, ENGINE, TOTAL_EXTENTS, INITIAL_SIZE ORDER BY LOGFILE_GROUP_NAME
2023-02-12T23:10:47.269998+08:00           31 Query     SELECT DISTINCT TABLESPACE_NAME, FILE_NAME, LOGFILE_GROUP_NAME, EXTENT_SIZE, INITIAL_SIZE, ENGINE FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'DATAFILE' ORDER BY TABLESPACE_NAME, LOGFILE_GROUP_NAME
2023-02-12T23:10:47.271829+08:00           31 Query     SHOW DATABASES
2023-02-12T23:10:47.277688+08:00           31 Query     SHOW VARIABLES LIKE 'ndbinfo\_version'

... 省略库、表部分

2023-02-12T23:10:49.026754+08:00           31 Query     SET SESSION character_set_results = 'utf8'
2023-02-12T23:10:49.027665+08:00           31 Query     SELECT @@GLOBAL.GTID_EXECUTED
2023-02-12T23:10:49.079618+08:00           31 Quit

备份期间，往主库插入一条记录(整个库数据量大一些，以延长备份时间)

mysql> insert into test(id) values(2);
Query OK, 1 row affected (0.01 sec)
mysql> select * from test;
+------+
| id   |
+------+
|    1 |
|    2 |
+------+
2 rows in set (0.01 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+-------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                         |
+------------------+----------+--------------+------------------+-------------------------------------------+
| mysql-bin.000016 | 10504178 |              |                  | d58fd9cd-4cbe-11ed-a864-000c291479a8:1-81 |
+------------------+----------+--------------+------------------+-------------------------------------------+
1 row in set (0.00 sec)

分析Executed_Gtid_Set的值

#备份前
binlog file：mysql-bin.000016
binlog position: 10503869
gtid: d58fd9cd-4cbe-11ed-a864-000c291479a8:1-80

#备份中(插入一条记录)
binlog file：mysql-bin.000016
binlog position: 10504178
gtid: d58fd9cd-4cbe-11ed-a864-000c291479a8:1-81

#备份后(主库未做其它操作，故不变)
binlog file：mysql-bin.000016
binlog position: 10504178
gtid: d58fd9cd-4cbe-11ed-a864-000c291479a8:1-81

分析备份文件中的@@GLOBAL.GTID_PURGED值

#这一行在备份文件的开头部分
-- CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000016', MASTER_LOG_POS=10503869;
#这一行在备份文件的末尾部分
SET @@GLOBAL.GTID_PURGED='d58fd9cd-4cbe-11ed-a864-000c291479a8:1-81';

从备份中CHANGE MASTER TO MASTER_LOG_FILE和@@GLOBAL.GTID_PURGED可以看出：

取binlog的 file 和 position是正确的
取@@GLOBAL.GTID_PURGED的值是错误的

为啥会发生这种情况呢？继续查看general log文件：

2023-02-12T23:10:47.185865+08:00           31 Connect   root@127.0.0.1 on  using SSL/TLS
2023-02-12T23:10:47.189021+08:00           31 Query     /*!40100 SET @@SQL_MODE='' */
2023-02-12T23:10:47.191633+08:00           31 Query     /*!40103 SET TIME_ZONE='+00:00' */
2023-02-12T23:10:47.193818+08:00           31 Query     FLUSH /*!40101 LOCAL */ TABLES	#关闭所有打开的表
2023-02-12T23:10:47.196899+08:00           31 Query     FLUSH TABLES WITH READ LOCK		#设置全库只读
2023-02-12T23:10:47.198546+08:00           31 Query     SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ		#设置RR隔离级别
2023-02-12T23:10:47.199749+08:00           31 Query     START TRANSACTION /*!40100 WITH CONSISTENT SNAPSHOT */		#在RR隔离级别下，开启事务，目的是获取一致性数据
2023-02-12T23:10:47.201860+08:00           31 Query     SHOW VARIABLES LIKE 'gtid\_mode'
2023-02-12T23:10:47.257565+08:00           31 Query     SHOW MASTER STATUS	#在全库只读的状态下，获取一致性读的binlog, position
2023-02-12T23:10:47.258572+08:00           31 Query     UNLOCK TABLES	#解锁全库只读
2023-02-12T23:10:47.259875+08:00           31 Query     SELECT LOGFILE_GROUP_NAME, FILE_NAME, TOTAL_EXTENTS, INITIAL_SIZE, ENGINE, EXTRA FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'UNDO LOG' AND FILE_NAME IS NOT NULL AND LOGFILE_GROUP_NAME IS NOT NULL GROUP BY LOGFILE_GROUP_NAME, FILE_NAME, ENGINE, TOTAL_EXTENTS, INITIAL_SIZE ORDER BY LOGFILE_GROUP_NAME
2023-02-12T23:10:47.269998+08:00           31 Query     SELECT DISTINCT TABLESPACE_NAME, FILE_NAME, LOGFILE_GROUP_NAME, EXTENT_SIZE, INITIAL_SIZE, ENGINE FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'DATAFILE' ORDER BY TABLESPACE_NAME, LOGFILE_GROUP_NAME
2023-02-12T23:10:47.271829+08:00           31 Query     SHOW DATABASES
2023-02-12T23:10:47.277688+08:00           31 Query     SHOW VARIABLES LIKE 'ndbinfo\_version'

... 省略库、表部分

2023-02-12T23:10:49.026754+08:00           31 Query     SET SESSION character_set_results = 'utf8'
2023-02-12T23:10:49.027665+08:00           31 Query     SELECT @@GLOBAL.GTID_EXECUTED	#读完全库数据后，获取当前的GTID
2023-02-12T23:10:49.079618+08:00           31 Quit

从general log中可以看出：

@@GLOBAL.GTID_EXECUTED的值，是在备份完数据后获取的。
@@GLOBAL.GTID_EXECUTED的值，和数据并不一致。也就是说，会记录下备份期间产生的GTID信息，而实际上，备份中并不包含这些数据。

总结：
经过测试可知：

mysqldump5.7.36之后存在此问题，当前最新的5.7.40版本未修复。
mysqldump5.7.36之前的版本不存在此问题。
mysqldump8.0.31版本已修复此问题。
应该把获取@@GLOBAL.GTID_EXECUTED的代码，放在START TRANSACTION之后UNLOCK TABLES之前。
解决此问题的方法，可以使用之前版本的mysqldump进行备份。

参考：
https://cloud.tencent.com/developer/article/1915277?shareByChannel=link

mysql

最后修改时间：2023-02-20 10:12:29

「喜欢这篇文章，您的关注和赞赏是给作者最好的鼓励」

关注作者

mysqldump 5.7.36版本GTID不一致bug

评论