Bug #86447 mysqlbinlog with rewrite-db flag does not handle CREATE/DROP database correctly
Submitted: 24 May 2017 20:51 Modified: 9 Jun 2017 10:02
Reporter: Tom Kubit Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.7.13+, 5.7.18 OS:Any
Assigned to: CPU Architecture:Any
Tags: mysqlbinlog, rewrite-db

[24 May 2017 20:51] Tom Kubit
Description:
The CREATE DATABASE and DROP DATABASE statements in the binlogs are not translated properly to use the target DB of the rewrite-db parameter and are therefore not processed correctly.  

How to repeat:

mysql> flush logs;
Query OK, 0 rows affected (0.14 sec)

mysql> create database drop_db_tst;
Query OK, 1 row affected (0.05 sec)

mysql> drop database drop_db_tst;
Query OK, 0 rows affected (0.01 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.04 sec)

$ ./mysqlbinlog  --read-from-remote-server --host=testdb --user=adm --password=xxxx --rewrite-db='drop_db_tst->foo' replicatelogs.000018
mysqlbinlog: [Warning] Using a password on the command line interface can be insecure.
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
DEBUG: ev_type <15># at 4
#170522 14:45:28 server id 12740  end_log_pos 123 	Start: binlog v 4, server v 5.7.18-0031-log created 170522 14:45:28
BINLOG '
2D8jWQ/EMQAAdwAAAHsAAAAAAAQANS43LjE4LTAwMzEtbG9nAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
AMP/tzw=
'/*!*/;
DEBUG: ev_type <35># at 123
#170522 14:45:28 server id 12740  end_log_pos 150 	Previous-GTIDs
# [empty]
DEBUG: ev_type <34># at 150
#170522 14:45:50 server id 12740  end_log_pos 211 	Anonymous_GTID	last_committed=0	sequence_number=1
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
DEBUG: ev_type <2># at 211
#170522 14:45:50 server id 12740  end_log_pos 322 	Query	thread_id=25394exec_time=0	error_code=0
SET TIMESTAMP=1495482350/*!*/;
SET @@session.pseudo_thread_id=25394/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1344274464/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create database drop_db_tst
/*!*/;
DEBUG: ev_type <34># at 322
#170522 14:46:02 server id 12740  end_log_pos 383 	Anonymous_GTID	last_committed=1	sequence_number=2
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
DEBUG: ev_type <2># at 383
#170522 14:46:02 server id 12740  end_log_pos 478 	Query	thread_id=25394exec_time=0	error_code=0
SET TIMESTAMP=1495482362/*!*/;
drop database drop_db_tst
/*!*/;
DEBUG: ev_type <4># at 478
#170522 14:46:07 server id 12740  end_log_pos 525 	Rotate to replicatelogs.000019  pos: 4
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

The way a rewrite happens for the query_event is the DB is only changed in the header of the event not the body where the actual statement that is executed is stored for statement based events.
[9 Jun 2017 10:02] Umesh Shastry
Hello Tom,

Thank you for the report.

Thanks,
Umesh
[19 Jun 2017 12:16] Matthew Lord
This has always been the designed and documented behavior:
https://dev.mysql.com/doc/refman/5.5/en/replication-options-slave.html#option_mysqld_repli...
https://dev.mysql.com/doc/refman/5.7/en/replication-options-slave.html#option_mysqld_repli...

"Only statements involving tables are affected (not statements
such as CREATE DATABASE, DROP DATABASE, and ALTER DATABASE)"

Moving this to a feature request.
[6 Jul 2017 21:33] Matthew Lord
Sorry, I misunderstood. The issue at question is not this server option:
https://dev.mysql.com/doc/refman/5.7/en/replication-options-slave.html#option_mysqld_repli...

But rather this mysqlbinlog client option:
https://dev.mysql.com/doc/refman/5.7/en/mysqlbinlog.html#option_mysqlbinlog_rewrite-db

In light of this, the current behavior is NOT documented. And from a user perspective, the current behavior is not expected and a bug--it can result in serious data loss. Changing the Severity back to mark it as a Bug rather than a Feature Request.