Bug #55709 5.5 mixed mode break slaves with different engines and temporary tables!
Submitted: 3 Aug 2010 10:06 Modified: 17 Jan 2011 17:21
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.5.5, 5.5.6 OS:Any
Assigned to: Assigned Account
Tags: regression
Triage: Triaged: D2 (Serious) / R3 (Medium) / E3 (Medium)

[3 Aug 2010 10:06] Shane Bester
Description:
slave tries to rollback statements against the wrong table, if temporary table with same name was dropped and statement was rolled back.

[ERROR] Slave SQL: Column 0 of table 'test.t3' cannot be converted from type 'tinyint' to type 'longblob', Error_code: 1677
[ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log

5.1.49 didn't break here.

How to repeat:
#setup a master/slave pair, with master --binlog-format=mixed
#on master run this:

drop table if exists t3;
create table t3(a tinyint)engine=myisam;
drop temporary table if exists t3;
create temporary table t3(a longblob)engine=innodb;
start transaction;
drop temporary table if exists t3;
replace into t3 set a=1;
rollback;

Suggested fix:
workaround: use --binlog-format=row
[3 Aug 2010 14:13] Shane Bester
still repeatable as described on:

sbester@box2:~/big/build/bzr/mysql-trunk-security> bzr log |head -n 10
------------------------------------------------------------
revno: 3086 [merge]
committer: Georgi Kodinov <Georgi.Kodinov@Oracle.com>
branch nick: merge-trunk-security
timestamp: Mon 2010-08-02 11:17:47 +0300
message:

Built like: ./BUILD/compile-pentium-debug-max-no-ndb
Run like:
Master: ./bin/mysqld --console --skip-gr --skip-na --server-id=1 --log-bin   --max-allowed-packet=1G --innodb_buffer_pool_size=100M --innodb-lock-wait-timeout=1 --binlog-format=mixed --basedir=. --datadir=./data --skip-slave-start

Slave: ./bin/mysqld_safe --skip-gr --skip-na --port=3307 --server-id=32 --tmpdir=. --basedir=. --datadir=./data --console
[3 Aug 2010 16:17] Alfranio Correia
Find below another test case:

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

drop table if exists t3;
create table t3(a tinyint)engine=myisam;
drop temporary table if exists t3;
create temporary table t3(a longblob)engine=innodb;
start transaction;
drop temporary table if exists t3;
replace into t3 set a=1;
rollback;

SHOW BINLOG EVENTS;

SELECT * FROM t3;

--sync_slave_with_master

SELECT * FROM t3;

exit;

In this bug, the slave goes out of sync because the "replace into t3 set a=1;" is written directly to the binary log as a regular non-transactional table is
updated. However, outside the transaction boundaries there is a temporary table
with the same name. Thus the regular t3 table is updated in the master and, in the temporary table t3 is updated in the slave.

The error happens either when the logging format is statement or mixed. In row, as changes to temporary tables are not written to the binary log, the error does not happen.
[3 Aug 2010 16:33] Valerii Kravchuk
Verified that slave goes out of sync with the last test case:

macbook-pro:mysql-test openxs$ ./mtr bug55709a
Logging: ./mtr  bug55709a
100803 19:30:01 [Warning] Setting lower_case_table_names=2 because file system for /var/folders/dX/dXCzvuSlHX4Op1g-o1jIWk+++TI/-Tmp-/AWFG05PBNk/ is case insensitive
100803 19:30:01 [Note] Plugin 'FEDERATED' is disabled.
100803 19:30:01 [Note] Plugin 'ndbcluster' is disabled.
MySQL Version 5.5.6
Checking supported features...
 - using ndbcluster when necessary, mysqld supports it
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
vardir: /Users/openxs/dbs/trunk/mysql-test/var
Checking leftover processes...
Removing old var directory...
Creating var directory '/Users/openxs/dbs/trunk/mysql-test/var'...
Installing system database...
Using server port 60158

==============================================================================

TEST                                      RESULT   TIME (ms)
------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
main.bug55709a                           [ fail ]
        Test ended at 2010-08-03 19:30:20

CURRENT_TEST: main.bug55709a
--- /Users/openxs/dbs/trunk/mysql-test/r/bug55709a.result	2010-08-03 19:29:46.000000000 +0300
+++ /Users/openxs/dbs/trunk/mysql-test/r/bug55709a.reject	2010-08-03 19:30:19.000000000 +0300
@@ -0,0 +1,38 @@
+stop slave;
+drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
+reset master;
+reset slave;
+drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
+start slave;
+drop table if exists t3;
+Warnings:
+Note	1051	Unknown table 't3'
+create table t3(a tinyint)engine=myisam;
+drop temporary table if exists t3;
+Warnings:
+Note	1051	Unknown table 't3'
+create temporary table t3(a longblob)engine=innodb;
+start transaction;
+drop temporary table if exists t3;
+replace into t3 set a=1;
+rollback;
+Warnings:
+Warning	1196	Some non-transactional changed tables couldn't be rolled back
+SHOW BINLOG EVENTS;
+Log_name	Pos	Event_type	Server_id	End_log_pos	Info
+master-bin.000001	4	Format_desc	1	107	Server ver: 5.5.6-m3-debug-log, Binlog ver: 4
+master-bin.000001	107	Query	1	193	use `test`; drop table if exists t3
+master-bin.000001	193	Query	1	295	use `test`; create table t3(a tinyint)engine=myisam
+master-bin.000001	295	Query	1	391	use `test`; drop temporary table if exists t3
+master-bin.000001	391	Query	1	504	use `test`; create temporary table t3(a longblob)engine=innodb
+master-bin.000001	504	Query	1	572	BEGIN
+master-bin.000001	572	Query	1	658	use `test`; replace into t3 set a=1
+master-bin.000001	658	Query	1	727	COMMIT
+master-bin.000001	727	Query	1	795	BEGIN
+master-bin.000001	795	Query	1	891	use `test`; drop temporary table if exists t3
+master-bin.000001	891	Query	1	962	ROLLBACK
+SELECT * FROM t3;
+a
+1
+SELECT * FROM t3;
+a
[4 Aug 2010 9:21] Alfranio Correia
Suggested fix:
--------------

If we consider this a replication bug rather than a server bug. I think we should append to binary log event the type of table that must be updated on the slave, i.e. either temporary or regular.

The same solution could be applied to BUG#55478.
[5 Aug 2010 4:03] Zhenxing He
Because updates to temporary table would never be binlogged in ROW format, so I think the solution could be always ignore temporary tables when applying ROW events on slave.
[18 Oct 2010 4:04] Libing Song
The patch for bug#55478 will fix this bug on RBR.
[19 Oct 2010 9:10] Lars Thalmann
The problem in the described situation is not that MIXED or some other
format is used, it is rather that the option
binlog-direct-non-transactional-updates is used.

This option causes data changes to be logged immediately.  If there is
a DROP TEMPORARY TABLE *inside* a transaction, changes to this
temporary table can be logged before the drop if the option is used.

In the general case, binlog-direct-non-transactional-updates is not
recommended.  For this particular setup, we need to investigate if it
can be differently configured.
[19 Oct 2010 11:55] Luis Soares
Hi, 

  Please, find some more details below.

Context
=======

 -  tree: mysql-5.5-bugteam
 - revid: magne.mahre@sun.com-20101019102921-u5t3r13fw5e3elfe

Test case (based on Alfranio's - see "[3 Aug 18:17] Alfranio Correia")
=========

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

call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT");

drop table if exists t3; 
create table t3(a tinyint)engine=myisam;
drop temporary table if exists t3; 
create temporary table t3(a longblob)engine=innodb;
start transaction;
drop temporary table if exists t3; 
replace into t3 set a=1;
rollback;

--source include/show_binlog_events.inc

--sync_slave_with_master

-- let $diff_table_1= master:test.t3
-- let $diff_table_2= slave:test.t3
-- source include/diff_tables.inc

exit;

 shell> perl mtr --mysqld=--binlog-format={statement|mixed|row} \
                 --mysqld=--binlog-direct-non-transactional-updates={0|1} \
                 rpl_bug55709

Results
=======

- Vanilla

 | Format\Direct | ON             | OFF                        |
 |---------------+----------------+----------------------------|
 | STMT          | slave DIVERGES | OK                         |
 | MIXED         | slave DIVERGES | slave updates WRONG TABLE* |
 | ROW           | OK             | OK                         |

 * This is BUG#55478

- Server patched with BUG#55478 fix

 | Format\Direct | ON             | OFF |
 |---------------+----------------+-----|
 | STMT          | slave DIVERGES | OK  |
 | MIXED         | slave DIVERGES | OK  |
 | ROW           | OK             | OK  |

Workarounds
===========

W1. Disable the binlog-direct-non-transactional-updates when issuing a
    transaction with such profile and logging in statement. For
    example:

    (...)    
    +SET SESSION binlog_direct_non_transactional_updates=0;
    start transaction;
    drop temporary table if exists t3; 
    replace into t3 set a=1;
    rollback;
    +SET SESSION binlog_direct_non_transactional_updates=1;
    (...)

W2. Move the DROP TEMPORARY TABLE outside of the transaction. For
    example:

    (...)
    +drop temporary table if exists t3;
    start transaction;
    -drop temporary table if exists t3;
    replace into t3 set a=1;
    rollback;
    (...)
W3. Use row format.
   
    - Temporary tables are not logged in row mode, thence do not
      interfere with replication at the slave.
    - Additionally, see the outcome of the test case in the results
      section above.
[19 Oct 2010 12:24] Luis Soares
In my previous comment, in the results section:

slave updates WRONG TABLE => slave BREAKS

"Column 0 of table 'test.t3' cannot be converted from type 'tinyint' to type 'longblob'"
[8 Nov 2010 14:05] Andrei Elkin
This one must be a dup of bug#55478 (which page comments suggests the same).
[17 Jan 2011 17:21] Alfranio Correia
We have decided to close this bug as duplicate of BUG#55478, as the scenario reported by "[3 Aug 2010 12:06] Shane Bester", i.e.

  . binlog_direct_non_transactional_updates = OFF
  . mixed mode;

is already fixed in BUG#55478. However, we have filed BUG#59561 to keep track of the following scenario:

  . binlog_direct_non_transactional_updates = ON
  . statement or mixed mode.

Cheers.