MySQL Bugs: #90980: Duplicate error on Slave when drop temporary tables

Bug #90980	Duplicate error on Slave when drop temporary tables
Submitted:	23 May 2018 2:16	Modified:	19 Jul 2018 13:12
Reporter:	Juan Arruti	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.6, 5.7, 5.7.22	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
In RBR duplicate errors can be found on slave instances if drop temporary table is executed, then roll back is executed within the same transaction and a concurrent insert occurrs for one of the rows that is being rolled back.

How to repeat:
# Session 1 
master [localhost] {msandbox} ((none)) > use test ;
Database changed
master [localhost] {msandbox} (test) > CREATE TABLE t1 (a INT, primary key (a)) ENGINE=INNODB;
Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} (test) > CREATE TEMPORARY TABLE t2 (a INT auto_increment, b int, primary key (a)) ENGINE=INNODB;
Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} (test) > CREATE TABLE t3           (a INT AUTO_INCREMENT, b INT, primary key (a)) ENGINE=INNODB;
Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} (test) > insert into t3 (b) values (1);
Query OK, 1 row affected (0.00 sec)

master [localhost] {msandbox} (test) > insert into t3 (b) select b from t3 ;
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0

...

master [localhost] {msandbox} (test) > insert into t3 (b) select b from t3 ;
Query OK, 2097152 rows affected (20.09 sec)
Records: 2097152  Duplicates: 0  Warnings: 0

master [localhost] {msandbox} (test) > BEGIN;
Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} (test) > INSERT INTO t1 SELECT A from t3;

Query OK, 4194304 rows affected (37.65 sec)
Records: 4194304  Duplicates: 0  Warnings: 0

master [localhost] {msandbox} (test) > DROP TEMPORARY TABLE t2;
Query OK, 0 rows affected (0.00 sec)

master [localhost] {msandbox} (test) > ROLLBACK;
Query OK, 0 rows affected, 1 warning (38.48 sec)

# Session 2 - While the rollback statement is running following command is executed
master [localhost] {msandbox} (test) > insert into t1 values (4587467);
Query OK, 1 row affected (0.00 sec)

# Slave Errors:

Last_SQL_Error: Could not execute Write_rows event on table test.t1; Duplicate entry '4587467' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000001, end_log_pos 58982461

Suggested fix:
This is related with binary logging when drop temporary table occurs. The transaction shouldn't be logged to the binary log since only InnoDB tables were modified.

Tested on 5.6 and 5.7.

Hello Juan,

Thank you for the report and test case.
Observed this with 5.7.22 build.

Thanks,
Umesh

5.7.22 - test results

Attachment: 90980_5.7.22.results (application/octet-stream, text), 13.25 KiB.

This issue is also present on statement based replication since the DML that affects InnoDB rows is logged into the binary logs alongside the drop temporary command before the rollback statement, regardless of the binary log format.

Posted by developer:
 
Note added in 5.7 and 5.6 docs:

 From MySQL 8.0, this behavior is changed because the MySQL server tracks the logging mode that was in effect when each temporary table was created. The DROP TEMPORARY TABLE IF EXISTS statement is therefore not necessarily logged for each temporary table. From that release, when a given client session ends, the server logs a DROP TEMPORARY TABLE IF EXISTS statement for each temporary table that still exists and was created when statement-based binary logging was in use. If row-based or mixed format binary logging was in use when the table was created, the DROP TEMPORARY TABLE IF EXISTS statement is not logged.