Bug #96414 CREATE TABLE events in wrong order in a binary log.
Submitted: 2 Aug 13:17 Modified: 7 Aug 13:24
Reporter: Iwo P Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.7, 5.7.27 OS:Any
Assigned to: CPU Architecture:Any

[2 Aug 13:17] Iwo P
Description:
When an application is concurrently creating tables, the tables can be logged into a binary log in a wrong order. This causes replication to break if foreign keys are used.

How to repeat:
1. 
Add extra DBUG_EXECUTE_IF condition into function:
bool mysql_create_table(THD *thd, TABLE_LIST *create_table,
                        HA_CREATE_INFO *create_info,
                        Alter_info *alter_info)

    ...
    if (create_info->options & HA_LEX_CREATE_TMP_TABLE)
      thd->get_transaction()->mark_created_temp_table(Transaction_ctx::STMT);

    if (!thd->is_current_stmt_binlog_format_row() ||
        (thd->is_current_stmt_binlog_format_row() &&
         !(create_info->options & HA_LEX_CREATE_TMP_TABLE)))
    {
      thd->add_to_binlog_accessed_dbs(create_table->db);

         **
         DBUG_EXECUTE_IF("inject_create_table_sleep_before_binlog", {
         my_sleep(5000000);
 });
         **
      result= write_bin_log(thd, true,
                            thd->query().str, thd->query().length, is_trans);
    }
  }
  ...

2. Start two sessions.

first> SET SESSION debug='d,inject_create_table_sleep_before_binlog';
first> CREATE TABLE testa(
    ->    cat_id int not null auto_increment primary key,
    ->    cat_name varchar(255) not null,
    ->    cat_description text
    -> ) ENGINE=InnoDB;
second> CREATE TABLE testb (prd_id int not null auto_increment primary key, prd_name varchar(355) not null, prd_price decimal, cat_id int not null, FOREIGN KEY fk_cat(cat_id) REFERENCES testa(cat_id) ON UPDATE CASCADE ON DELETE RESTRICT);

3. MySQL will write events in the following order to the binary log:

# at 1439
#190802 15:05:28 server id 1  end_log_pos 1741 CRC32 0x796b725f 	Query	thread_id=6	exec_time=0	error_code=0
SET TIMESTAMP=1564751128/*!*/;
CREATE TABLE testb (prd_id int not null auto_increment primary key, prd_name varchar(355) not null, prd_price decimal, cat_id int not null, FOREIGN KEY fk_cat(cat_id) REFERENCES testa(cat_id) ON UPDATE CASCADE ON DELETE RESTRICT)
/*!*/;
# at 1741
# at 1806
#190802 15:05:27 server id 1  end_log_pos 2025 CRC32 0xb1415a89 	Query	thread_id=7	exec_time=5	error_code=0
SET TIMESTAMP=1564751127/*!*/;
CREATE TABLE testa(
   cat_id int not null auto_increment primary key,
   cat_name varchar(255) not null,
   cat_description text
) ENGINE=InnoDB
/*!*/;
DELIMITER ;
# End of log file

Suggested fix:
Child table DDL statement should be written to a binary log after parent table.
[7 Aug 13:24] Umesh Shastry
Hello Iwo P,

Thank you for the report and test case.
Verified as described with patched 5.7.27 source build.

regards,
Umesh
[7 Aug 13:26] Umesh Shastry
Test results - 5.7.27

Attachment: 96414_5.7.27.results (application/octet-stream, text), 248.94 KiB.

[7 Aug 13:27] Umesh Shastry
- Haven't checked other GAs, shall do it tomorrow or later on
[12 Aug 12:24] Dmitry Lenev
Posted by developer:
 
Note that the problem is not repeatable in modern 8.0 versions (I've used 8.0.18-git) to verify.
This is thanks to WL#6049 "Meta-data locking for FOREIGN KEY tables" which was introduced in
release 8.0.3. The second CREATE TABLE statement now acquires metadata lock on parent table
in FK so has to wait until the first CREATE TABLE completes (since the latter holds conflicting
MDL on it).