MySQL Bugs: #48542: Implicit drops on temporary tables aren't always replicated to slaves

Bug #48542	Implicit drops on temporary tables aren't always replicated to slaves
Submitted:	4 Nov 2009 18:43	Modified:	12 Mar 2010 9:01
Reporter:	Dmitriy Pinchukov	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.1.39, 5.1.40, 5.1.41	OS:	Any
Assigned to:	Assigned Account	CPU Architecture:	Any
Tags:	replication, temporary tables

Description:
MySQL slave servers don't replicate (or don't receive from the master) the implicit DROP TABLE statements on temporary tables under certain conditions. This results in a virtual memory leak like a memory being malloc()'ed but neither used not free()'d.

Example (on a slave server):

mysql> show status like "%temp%";
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Slave_open_temp_tables | 26407 |
+------------------------+-------+
1 row in set (0.00 sec)

While it should be near to zero.

Also, the processor usage seems to grow continuously when the 'leaked' tables count gets high enough.

How to repeat:
On the master:

mysql> delimiter //
mysql> CREATE PROCEDURE test.test ()
BEGIN
  DROP TABLE IF EXISTS test.temp;
  CREATE TEMPORARY TABLE test.temp (id INT PRIMARY KEY) ENGINE=MEMORY;
END//
mysql> delimiter ;

On the slave:

mysql> show status like "%temp%";
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Slave_open_temp_tables | 0     |
+------------------------+-------+
1 row in set (0.00 sec)

Now, execute the procedure at least two times on the master and exit:

mysql> call test.test();
Query OK, 0 rows affected, 1 warning (0.02 sec)
mysql> call test.test();
Query OK, 0 rows affected (0.00 sec)
mysql> Aborted

Now, on the slave:

mysql> show status like "%temp%";
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| Slave_open_temp_tables | 1     |
+------------------------+-------+
1 row in set (0.00 sec)

It keeps growing when you call the procedure and disconnect.

Workaround: adding an explicit DROP TABLE on the previously created temporary table in the end of the procedure seems to help.

Verified just as described with the following test case for our test suite:

77-52-7-73:mysql-test openxs$ tail suite/rpl/t/rpl_bug48542.test 
call test.test();
call test.test();
call test.test();
#save_master_pos;
disconnect master;

connection slave;
#sync_with_master;
select 1;
show status like '%temp%';

Test fails only in statement based replication mode:

rpl.rpl_bug48542 'stmt'                  [ fail ]
        Test ended at 2009-11-05 16:11:41

CURRENT_TEST: rpl.rpl_bug48542
--- /Users/openxs/dbs/5.1/mysql-test/suite/rpl/r/rpl_bug48542.result	2009-11-05 17:11:24.000000000 +0300
+++ /Users/openxs/dbs/5.1/mysql-test/suite/rpl/r/rpl_bug48542.reject	2009-11-05 17:11:41.000000000 +0300
@@ -22,4 +22,4 @@
 1
 show status like '%temp%';
 Variable_name	Value
-Slave_open_temp_tables	0
+Slave_open_temp_tables	1

mysqltest: Result content mismatch

But(!) only if sync_with_master is commented out...

Sorry, this is complete test case:

source include/master-slave.inc;
source include/have_innodb.inc;

connection master;
delimiter |;
CREATE PROCEDURE test()
BEGIN
  DROP TABLE IF EXISTS temp;
  CREATE TEMPORARY TABLE temp (id INT PRIMARY KEY) ENGINE=MEMORY;
  DROP TEMPORARY TABLE temp;
END|
delimiter ;|
call test.test();
call test.test();
call test.test();
#save_master_pos;
disconnect master;

connection slave;
#sync_with_master;
select 1;
show status like '%temp%';

Dmitriy,

please, send the results of:

show variables like 'binlog_f%';

from the environment where you got this bug.

On both the master the slave:

+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | MIXED |
+---------------+-------+

I meant "AND the slave", sorry.

Only reproduced on 5.1.40, 5.1.41. Can not be reproduced after 5.1.41.
It is a replica of bug#48216.

'DROP /*!40005 TEMPORARY */ TABLE IF EXISTS' was binlogged with a wrong db name
and db name length.