Mysql 5.7 Gtid内部实际案例分析
本篇内容介绍了“Mysql 5.7 Gtid内部实际案例分析”的有关知识,在实际案例的操作过程中,不少人都会遇到这样的困境,接下来就让小编带领大家学习一下如何处理这些情况吧!希望大家仔细阅读,能够学有所成!
一、触发条件本案列我测试过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:Gotfatalerror1236frommasterwhenreadingdatafrombinarylog:'TheslaveisconnectingusingCHANGEMASTERTOMASTER_AUTO_POSITION=1,butthemasterhaspurgedbinarylogscontainingGTIDsthattheslaverequires.'三、故障分析
为什么重启后会报错找到不事物呢,然后发现这个Gtid事物在主库的binlog中已经没有了,应该是很久以前的。其实这个问题我们要回到mysqldump出来的文件如何进行Gtid的初始化以及mysql.gtid_executed表中。
在mysqldump不使用--set-gtid-purged的时候必然会在dump出来的脚本中包含
--GTIDstateatthebeginningofthebackupSET@@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--Tablestructurefortable`gtid_executed`211--212213DROPTABLEIFEXISTS`gtid_executed`;214/*!40101SET@saved_cs_client=@@character_set_client*/;215/*!40101SETcharacter_set_client=utf8*/;216CREATETABLE`gtid_executed`(217`source_uuid`char(36)NOTNULLCOMMENT'uuidofthesourcewherethetransactionwasoriginallyexecuted.',218`interval_start`bigint(20)NOTNULLCOMMENT'Firstnumberofinterval.',219`interval_end`bigint(20)NOTNULLCOMMENT'Lastnumberofinterval.',220PRIMARYKEY(`source_uuid`,`interval_start`)221)ENGINE=InnoDBDEFAULTCHARSET=utf8;222/*!40101SETcharacter_set_client=@saved_cs_client*/;223224--225--Dumpingdatafortable`gtid_executed`226--227228LOCKTABLES`gtid_executed`WRITE;229/*!40000ALTERTABLE`gtid_executed`DISABLEKEYS*/;230INSERTINTO`gtid_executed`VALUES('e859a28b-b66d-11e7-8371-000c291f347d',1,32);231/*!40000ALTERTABLE`gtid_executed`ENABLEKEYS*/;232UNLOCKTABLES;
显然这里我们在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从库导完数据后加入了两个个步骤如下:
resetmaster;setglobalgtid_purged='e859a28b-b66d-11e7-8371-000c291f347d:1-41';
这两步也就是为了从新初始化mysql.gtid_executed表,让其正确。
此问题还可以在mysqldump的时候加入-F, --flush-logs选项规避,但是-F会加入如下的MDL LOCK:
2017-12-18T08:16:39.580985Z6QueryFLUSH/*!40101LOCAL*/TABLES2017-12-18T08:16:39.612598Z6QueryFLUSHTABLESWITHREADLOCK2017-12-18T08:16:39.613406Z6Refresh/root/mysql5.7.14/percona-server-5.7.14-7/sql/mysqld,Version:5.7.14-7-debug-log(Sourcedistribution).startedwith:Tcpport:13001Unixsocket:/root/mysql5.7.14/percona-server-5.7.14-7/mysql-test/var/tmp/mysqld.1.sockTimeIdCommandArgument2017-12-18T08:16:39.965847Z6QuerySETSESSIONTRANSACTIONISOLATIONLEVELREPEATABLEREAD2017-12-18T08:16:39.966298Z6QuerySTARTTRANSACTION/*!40100WITHCONSISTENTSNAPSHOT*/2017-12-18T08:16:39.966792Z6QuerySHOWVARIABLESLIKE'gtid\_mode'2017-12-18T08:16:39.969587Z6QuerySELECT@@GLOBAL.GTID_EXECUTED2017-12-18T08:16:39.970216Z6QuerySHOWSTATUSLIKE'binlog_snapshot_%'2017-12-18T08:16:39.975242Z6QueryUNLOCKTABLES
这把锁是GLOBAL级别的MDL_SHARED(S)锁,它会等到你说有的SELECT/DML/DDL语句结束后才能获得,同时会堵塞全部的SELECT/DML/DDL虽然持有时间很短如下:
mysql>flushtableswithreadlock;QueryOK,0rowsaffected(0.01sec)2017-08-03T18:19:11.603911Z3[Note](acquire_lock)THISMDLLOCKacquireok!2017-08-03T18:19:11.603947Z3[Note](>MDLPRINT)Threadidis3:2017-08-03T18:19:11.603971Z3[Note](--->MDLPRINT)Namespaceis:GLOBAL2017-08-03T18:19:11.603994Z3[Note](----->MDLPRINT)Mdltypeis:MDL_SHARED(S)2017-08-03T18:19:11.604045Z3[Note](------>MDLPRINT)Mdldurationis:MDL_EXPLICIT2017-08-03T18:19:11.604073Z3[Note](------->MDLPRINT)Mdlstatusis:EMPTY2017-08-03T18:19:11.604133Z3[Note](acquire_lock)THISMDLLOCKacquireok!
当然要了解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>showslavestatus\G***************************1.row***************************Master_Log_File:binlog.000002Read_Master_Log_Pos:5077Relay_Log_File:test1-relay-bin.000002Relay_Log_Pos:2498Relay_Master_Log_File:binlog.000002Slave_IO_Running:YesSlave_SQL_Running:YesExec_Master_Log_Pos:5077Relay_Log_Space:2705Last_IO_Errno:0Last_IO_Error:Seconds_Behind_Master:0Retrieved_Gtid_Set:e859a28b-b66d-11e7-8371-000c291f347d:42-49Executed_Gtid_Set:e859a28b-b66d-11e7-8371-000c291f347d:1-49Auto_Position:1
但是这个时候我们发现mysql.gtid_executed表已经出现了问题如下:
mysql>select*fromgtid_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>showbinarylogs;+---------------+-----------+|Log_name|File_size|+---------------+-----------+|binlog.000001|9974||binlog.000002|5121||binlog.000003|194|+---------------+-----------+3rowsinset(0.01sec)mysql>purgebinarylogsto'binlog.000003';QueryOK,0rowsaffected(0.04sec)mysql>showbinarylogs;+---------------+-----------+|Log_name|File_size|+---------------+-----------+|binlog.000003|194|+---------------+-----------+1rowinset(0.00sec)
备库重启后错误重现:
mysql>showslavestatus\G***************************1.row***************************Slave_IO_State:Master_Host:192.168.190.62Master_User:replMaster_Port:3308Connect_Retry:60Master_Log_File:binlog.000003Read_Master_Log_Pos:194Relay_Log_File:test1-relay-bin.000005Relay_Log_Pos:4Relay_Master_Log_File:binlog.000003Slave_IO_Running:NoSlave_SQL_Running:YesExec_Master_Log_Pos:194Relay_Log_Space:194Last_IO_Errno:1236Last_IO_Error:Gotfatalerror1236frommasterwhenreadingdatafrombinarylog:'TheslaveisconnectingusingCHANGEMASTERTOMASTER_AUTO_POSITION=1,butthemasterhaspurgedbinarylogscontainingGTIDsthattheslaverequires.'Slave_SQL_Running_State:Slavehasreadallrelaylog;waitingformoreupdatesRetrieved_Gtid_Set:e859a28b-b66d-11e7-8371-000c291f347d:42-49Executed_Gtid_Set:e859a28b-b66d-11e7-8371-000c291f347d:1-32:42-49Auto_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内部实际案例分析”的内容就介绍到这里了,感谢大家的阅读。如果想了解更多行业相关的知识可以关注亿速云网站,小编将为大家输出更多高质量的实用文章!
声明:本站所有文章资源内容,如无特殊说明或标注,均为采集网络资源。如若本站内容侵犯了原著者的合法权益,可联系本站删除。