MySQL Bugs: #91086: CREATE DATABASE cause a missing executed GTID on slave

Bug #91086	CREATE DATABASE cause a missing executed GTID on slave
Submitted:	31 May 2018 5:49	Modified:	31 May 2018 8:16
Reporter:	Jian Chen	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.6.39, 5.6.40	OS:	CentOS (CentOS Linux release 7.3.1611 (Core))
Assigned to:		CPU Architecture:	Any
Tags:	binlog, GTID, replication

Description:
MySQL Server: 5.6.40-log MySQL Community Server
OS: CentOS Linux release 7.3.1611 (Core) x64
Configuration: one master & one slave replication, slave was configured with replicate-wild-do-table = xxx.% option

When working with a two nodes GTID mode replication structure (one master => one slave), and the slave instance has configured with `replicate-wild-do-table = A.%` option.
If executed a `CREATE/DROP DATABASE` statement which the database name is not A on the master node, the slave would get this GTID replicated (in RETRIEVED_GTID_SET & redo log) and would not executed it due to the replicate-wild-do-table option, so far it's expected. But this GTID get missed from the EXECUTED_GTID_SET on the slave node that a discontinuous GTID set occurs.

I file this report because when running with the same replicate option, INSERT/UPDATE... changes on the table which not belongs to database A wouldn't get executed on slave as well, but MySQL would fill this GTID in EXECUTED_GTID_SET of slave (recorded as a empty transaction event in slave's binary log) instead of skipping it.

How to repeat:
master - my.cnf:
log-bin                                 = mysql-bin
gtid-mode                               = ON
log-slave-updates                       = ON
enforce-gtid-consistency                = ON
...

slave - my.cnf:
replicate-wild-do-table                 = mydb1.%
gtid-mode                               = ON
log-slave-updates                       = ON
enforce-gtid-consistency                = ON
...

master status information:
mysql> show master status ;
+------------------+----------+--------------+------------------+--------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                          |
+------------------+----------+--------------+------------------+--------------------------------------------+
| mysql-bin.000002 |      627 |              |                  | 356d0651-5e4c-11e8-846c-126bb17ce918:1-345 |
+------------------+----------+--------------+------------------+--------------------------------------------+
1 row in set (0.01 sec)

replication status of slave:
mysql> show slave status \G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 10.23.7.81
                  Master_User: slave
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000002
          Read_Master_Log_Pos: 627
               Relay_Log_File: freewheel-relay-bin.000002
                Relay_Log_Pos: 554
        Relay_Master_Log_File: mysql-bin.000002
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB:
          Replicate_Ignore_DB:
           Replicate_Do_Table:
       Replicate_Ignore_Table:
      Replicate_Wild_Do_Table: mydb1.%
  Replicate_Wild_Ignore_Table:
                   Last_Errno: 0
                   Last_Error:
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 627
              Relay_Log_Space: 762
              Until_Condition: None
               Until_Log_File:
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
           Master_SSL_CA_File:
           Master_SSL_CA_Path:
              Master_SSL_Cert:
            Master_SSL_Cipher:
               Master_SSL_Key:
        Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error:
               Last_SQL_Errno: 0
               Last_SQL_Error:
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 27087
                  Master_UUID: 356d0651-5e4c-11e8-846c-126bb17ce918
             Master_Info_File: /export/data/mysql/data/master.info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it
           Master_Retry_Count: 86400
                  Master_Bind:
      Last_IO_Error_Timestamp:
     Last_SQL_Error_Timestamp:
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:345
            Executed_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:1-345
                Auto_Position: 1
1 row in set (0.00 sec)

Here're steps to verify:
1. Send INSERT on mydb1.t on master
master - GTID+1:
mysql> insert into mydb1.t values (1);
Query OK, 1 row affected (0.00 sec)

mysql> show master status ;
+------------------+----------+--------------+------------------+--------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                          |
+------------------+----------+--------------+------------------+--------------------------------------------+
| mysql-bin.000002 |      859 |              |                  | 356d0651-5e4c-11e8-846c-126bb17ce918:1-346 |
+------------------+----------+--------------+------------------+--------------------------------------------+
1 row in set (0.00 sec)

slave - GTID+1:
mysql> show slave status \G
...
      Replicate_Wild_Do_Table: mydb1.%
           Retrieved_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:345-346
            Executed_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:1-346
...

2. Send INSERT on mydb2.t on master
master - GTID+1:
mysql> insert into mydb2.t values (1);
Query OK, 1 row affected (0.00 sec)

mysql> show master status ;
+------------------+----------+--------------+------------------+--------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                          |
+------------------+----------+--------------+------------------+--------------------------------------------+
| mysql-bin.000002 |     1091 |              |                  | 356d0651-5e4c-11e8-846c-126bb17ce918:1-347 |
+------------------+----------+--------------+------------------+--------------------------------------------+
1 row in set (0.00 sec)

mysql> select * from mydb2.t;
+------+
| x    |
+------+
|    1 |
+------+
1 row in set (0.00 sec)

slave - GTID+1:
mysql> select * from mydb2.t;
Empty set (0.00 sec)

mysql> show slave status \G
...
      Replicate_Wild_Do_Table: mydb1.%
           Retrieved_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:345-347
            Executed_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:1-347
...

3. Send CREATE DATABASE xxx on master
master - GTID+1:
mysql> create database mydb3;
Query OK, 1 row affected (0.00 sec)

mysql> show master status ;
+------------------+----------+--------------+------------------+--------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                          |
+------------------+----------+--------------+------------------+--------------------------------------------+
| mysql-bin.000002 |     1236 |              |                  | 356d0651-5e4c-11e8-846c-126bb17ce918:1-348 |
+------------------+----------+--------------+------------------+--------------------------------------------+
1 row in set (0.00 sec)

slave - GTID retrieved but not changed on Executed_Gtid_Set:
mysql> show slave status \G
...
      Replicate_Wild_Do_Table: mydb1.%
           Retrieved_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:345-348
            Executed_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:1-347
...

4. Send INSERT on mydb1.t on master
master - GTID+1:
mysql> insert into mydb1.t values (1);
Query OK, 1 row affected (0.00 sec)

mysql> show master status ;
+------------------+----------+--------------+------------------+--------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                          |
+------------------+----------+--------------+------------------+--------------------------------------------+
| mysql-bin.000002 |     1468 |              |                  | 356d0651-5e4c-11e8-846c-126bb17ce918:1-349 |
+------------------+----------+--------------+------------------+--------------------------------------------+
1 row in set (0.00 sec)

slave - broken GTID set on Executed_Gtid_Set:
...
      Replicate_Wild_Do_Table: mydb1.%
           Retrieved_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:345-349
            Executed_Gtid_Set: 356d0651-5e4c-11e8-846c-126bb17ce918:1-347:349
...

Suggested fix:
Reserve the GTID of filtered CREATE/DROP DATABASE changes in that situation, keep GTID continuous on slave

Hello jian chen,

Thank you for the report.
This is most likely duplicate of Bug #88891, please see Bug #88891 which is fixed and here is the change log:

Posted by developer:
 
Thanks for the report. Changelog entry added for MySQL 8.0.12, 5.7.23, and 5.6.41:
When GTIDs are in use for replication, replicated transactions that are filtered out on the slave are persisted. If binary logging is enabled on the slave, the filtered-out transaction is written to the binary log as a Gtid_log_event followed by an empty transaction containing only BEGIN and COMMIT statements. If binary logging is disabled, the GTID of the filtered-out transaction is written to the mysql.gtid_executed table. This process ensures that there are no gaps in the set of executed GTIDs, and that the filtered-out transactions are not retrieved again if the slave reconnects to the master. Previously, this process was not done for CREATE DATABASE, ALTER DATABASE, and DROP DATABASE statements, but it is now carried out for those statements as well as for others.  

- The GTIDs documentation for MySQL 8.0 was recently updated to cover this area better. Please see https://dev.mysql.com/doc/refman/8.0/en/replication-gtids.html and the first three subtopics.

Thanks,
Umesh

Thanks for your information, Umesh. It is the same issue.