MySQL启用Gtid时如何确保Slave crash safe

背景

MySQL5.6 支持slave crash safe特性，根据之前对slave crash safe特性的认识，在配置了以下参数的情况下，可以保证slave crash后保证数据的一致性。

relay_log_info_repository      = TABLE
relay_log_recovery             = ON 

但是，用MySQL5.6(Percona Server 5.6.31) 配置基于GTID的主从复制(MASTER_AUTO_POSITION=1)后，进行slave宕机测试时，发现slave恢复后，复制正常但数据不一致(注意没有报错，主备的GTID也是一致的！！！)。

MySQL参数

log_bin                        = /data/mysql/binlog
sync_binlog                    = 1
innodb_flush_log_at_trx_commit = 2
log_slave_updates             = true
gtid_mode                     = on 
enforce_gtid_consistency      = true 
master_info_repository         = TABLE
relay_log_info_repository      = TABLE
relay_log_recovery             = ON 

测试方法

搭建主从复制

使用上面的参数搭建主从复制

创建测试表

mysql> show create table test.test1;
+-------+--------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table                                                                                                                               |
+-------+--------------------------------------------------------------------------------------------------------------------------------------------+
| test1 | CREATE TABLE `test1` (
  `id` int(11) NOT NULL,
  `num` int(11) DEFAULT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 |
+-------+--------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec) 

插入数据

执行一个脚本，不断执行下面的insert语句

insert into test1 values($i,$i) 

模拟Slave宕机

测试环境是虚机，通过杀Slave虚机进程模拟Slave宕机，然后再重启Slave虚机并启动mysql。

现象

重启Slave虚机并启动mysql后，MySQL复制正常，但查询数据时发现遗漏了一些数据。

mysql> select count(*),max(id) from test1;
+----------+---------+
| count(*) | max(id) |
+----------+---------+
|    21997 |   22009 |
+----------+---------+
1 row in set (0.00 sec) 

正常情况下，max(id)应该和count(*)值相等。

MySQL错误日志中有如下消息。

2016-10-24 01:30:31 2637 [ERROR] Error in Log_event::read_log_event(): 'read error', data_len: 44, event_type: 30
2016-10-24 01:30:31 2637 [Warning] Error reading GTIDs from binary log: -1
2016-10-24 01:30:32 2637 [Warning] Recovery from master pos 33445082 and file binlog.000001. Previous relay log pos and relay log file had been set to 1276427, ./mysql-relay-bin.000010 respectively.
2016-10-24 01:30:32 2637 [Note] Slave SQL thread initialized, starting replication in log 'binlog.000001' at position 33445082, relay log './mysql-relay-bin.000011' position: 4
2016-10-24 01:30:32 2637 [Note] Slave I/O thread: Start semi-sync replication to master 'sn_repl@192.168.236.103:3306' in log 'binlog.000001' at position 33445082
2016-10-24 01:30:32 2637 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.
2016-10-24 01:30:32 2637 [Note] Slave I/O thread: connected to master 'sn_repl@192.168.236.103:3306',replication started in log 'binlog.000001' at position 33445082
2016-10-24 01:30:32 2637 [Note] Event Scheduler: Loaded 0 events
2016-10-24 01:30:32 2637 [Note] mysqld: ready for connections.
Version: '5.6.31-77.0-log'  socket: '/data/mysql/mysql.sock'  port: 3306  Percona Server (GPL), Release 77.0, Revision 5c1061c 

原因

参考官方文档

http://dev.mysql.com/doc/refman/5.6/en/replication-solutions-unexpected-slave-halt.html

When using GTIDs and MASTER_AUTO_POSITION, set relay_log_recovery=0. With this 
configuration the setting of relay_log_info_repository and other variables does 
not impact on recovery. 

上面官方文档上写的 relay_log_recovery=0，是个笔误，应该是relay_log_recovery=1，我提个了个bug报告（），已经得到了确认。

测试使用的参数是满足官方文档的要求的，但没有起到crash safe的效果。

进一步调查，发现问题的根源是下面2个参数

sync_binlog                    = 1
innodb_flush_log_at_trx_commit = 2 

在使用GTIDs且MASTER_AUTO_POSITION=1的情况下，Slave继续执行binlog的位置是基于Executed_Gtid_Set的(不是保存在mysql.slave_relay_log_info中binlog文件位置)，Executed_Gtid_Set是在mysqld启动时通过扫描binlog获取的。由于sync_binlog=1，所以binlog里的位置是最新的，而innodb_flush_log_at_trx_commit = 2并不是每次刷盘，所以innodb的redo log里会丢失一些数据，即Slave的数据文件和Executed_Gtid_Set不一致。这就导致了重新启动复制后会丢失部分更新。

另外一个相似的现象是,把innodb的redo log设成同步刷，而binlog异步刷，这会导致Slave重复回放已经执行过的binglog事件，在这个测试里的结果就是出现主键冲突。

sync_binlog                    = 0
innodb_flush_log_at_trx_commit = 1 

解决办法

修改下面2个参数为双1，可以确保数据文件和binlog文件一致。修改后问题不再出现。

sync_binlog                    = 1
innodb_flush_log_at_trx_commit = 1 

即，MySQL5.6启用GTIDs且MASTER_AUTO_POSITION=1时，可确保slave crash safe的参数设置如下：

relay_log_recovery             = 1
sync_binlog                    = 1
innodb_flush_log_at_trx_commit = 1 

每次事务提交都刷binlog和redo log的设置是最安全的，但会对性能一定影响。
在MySQL 5.7里有另外的解决办法。MySQL 5.7增加了一个系统表mysql.gtid_executed用于持久化已执行的gtid信息。即在没有开启log_bin或者从服务器没有开启log_slave_updates时每次事务提交往mysql.gtid_executed里插入一个gtid记录，这和relay_log_info_repository的处理方式相似。因此不需要把sync_binlog和innodb_flush_log_at_trx_commit设置为1就可以确保gtid_executed和实际的数据文件一致。不过在MySQL 5.7开启log_bin或者从服务器开启log_slave_updates时，只在flush log，服务器停止等场景下才写mysql.gtid_executed，Slave crash时依然有gtid_executed和数据文件不一致的问题。

后来查阅bug记录，这是一个已知bug，并且2013年就被发现了。

引申问题

• 如果采用基于Position的复制是不是就不需要binlog和redo log都实时刷盘了？

  当relayloginfo_repository=TABLE时，Slave执行的位置信息是和apply event在同一事务里提交的，所以可以保证它们是一致的。但基于Position的复制在多线程复制下会有gap和Gap-free low-watermark position的问题，也不能保证数据一致，需要注意，详见。

  http://dev.mysql.com/doc/refman/5.7/en/replication-features-transaction-inconsistencies.html

参考

• http://dev.mysql.com/doc/refman/5.6/en/replication-solutions-unexpected-slave-halt.html
• http://dev.mysql.com/doc/refman/5.7/en/replication-features-transaction-inconsistencies.html
• 
  

相关代码

mysqld启动时从binglog文件读取已执行的gtid，从最后一个文件开始读。

mysqld_main()
  mysql_bin_log.init_gtid_sets()
    read_gtids_from_binlog() 

基于GTID的binlog dump

Rpl_slave.cc:request_dump()
Rpl_master.cc:com_binlog_dump_gtid()