MySQL Bugs: #12559: Transaction Rollbacks not replicated in rbr. Data on slave not matching master.

Bug #12559	Transaction Rollbacks not replicated in rbr. Data on slave not matching master.
Submitted:	12 Aug 2005 20:33	Modified:	22 Sep 2005 12:52
Reporter:	Jonathan Miller	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	5.0-wl1012	OS:	Linux (Linux)
Assigned to:	Guilhem Bichot	CPU Architecture:	Any

Description:
Consider the following test case:

CREATE TABLE test.t3 (a INT AUTO_INCREMENT KEY, t CHAR(6))ENGINE=INNODB;

delimiter |;
CREATE PROCEDURE test.p3(IN n INT)
begin
CASE n
WHEN 2 THEN
 DELETE from test.t3;
ELSE
 INSERT INTO test.t3 VALUES (NULL,'NONE');
END CASE;
end|
delimiter ;|

SET AUTOCOMMIT=0;
START TRANSACTION;

-- disable_query_log
-- disable_result_log
let $n=50;
while ($n)
{
  eval call test.p3($n);
  dec $n;
}
-- enable_result_log
-- enable_query_log

ROLLBACK;
select * from test.t3;
sleep 3;
connection slave;
select * from test.t3;

connection master;
START TRANSACTION;

-- disable_query_log
-- disable_result_log
let $n=50;
while ($n>3)
{
  eval call test.p3($n);
  dec $n;
}
-- enable_result_log
-- enable_query_log

COMMIT;
select * from test.t3;
sleep 3;
connection slave;
select * from test.t3;

connection master;
show binlog events;

*********************** RESULTS ****************************************
MASTER:
+ select * from test.t3;
+ a     t

SLAVE:
+ select * from test.t3;
+ a     t
+ 49    NONE <- should not be there :-)

** Second one, Commit not passed, but it works out

MASTER:
+ select * from test.t3;
+ a     t
+ 98    NONE

SLAVE:
+ select * from test.t3;
+ a     t
+ 98    NONE

How to repeat:
See above;

Another example;
~/jmiller/mysql5.0/mysql-test> cat ./t/rpl_row_sp007.test #############################################################################
# Original Author: Jonathan Miller                                          #
# Original Date: Aug/15/2005                                                #
#############################################################################

# Includes
-- source include/have_binlog_format_row.inc
-- source include/master-slave.inc
-- source include/have_innodb.inc

# Begin clean up test section
connection master;
--disable_warnings
DROP PROCEDURE IF EXISTS test.p1;
DROP TABLE IF EXISTS test.t2;
--enable_warnings
# End of cleanup

# Begin test section 1
delimiter |;
CREATE PROCEDURE test.p1(IN i INT)
BEGIN
  DECLARE CONTINUE HANDLER FOR sqlexception BEGIN END;
  DROP TABLE IF EXISTS test.t1;
  CREATE TABLE test.t1 (num INT,PRIMARY KEY(num))ENGINE=INNODB;
  START TRANSACTION;
    INSERT INTO test.t1 VALUES(i);
    savepoint t1_save;
    INSERT INTO test.t1 VALUES (14);
    ROLLBACK to savepoint t1_save;
    COMMIT;
END|
delimiter ;|

let $message=< ---- Master selects-- >;
--source include/show_msg.inc
CALL test.p1(12);
SELECT * FROM test.t1;
sleep 6;

let $message=< ---- Slave selects-- >;
--source include/show_msg.inc
connection slave;
SELECT * FROM test.t1;

let $message=< ---- Master selects-- >;
--source include/show_msg.inc
connection master;
CALL test.p1(13);
sleep 6;
SELECT * FROM test.t1;

let $message=< ---- Slave selects-- >;
--source include/show_msg.inc
connection slave;
SELECT * FROM test.t1;

connection master;
show binlog events;

DROP PROCEDURE IF EXISTS test.p1;
DROP TABLE IF EXISTS test.t1;
*************************** RESULTS ********************
+ < ---- Master selects-- >
+ -------------------------
+ CALL test.p1(12);
+ Warnings:
+ Note  1051    Unknown table 't1'
+ SELECT * FROM test.t1;
+ num
+ 12
+
+ < ---- Slave selects-- >
+ ------------------------
+ SELECT * FROM test.t1;
+ num
+ 12
+ 14
+
+ < ---- Master selects-- >
+ -------------------------
+ CALL test.p1(13);
+ SELECT * FROM test.t1;
+ num
+ 13
+
+ < ---- Slave selects-- >
+ ------------------------
+ SELECT * FROM test.t1;
+ num
+ 13
+ 14

Another example fro rpl_row_relayrotate.test

Statement based test:

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;
+ stop slave;
+ create table test.t1 (a int) engine=innodb;
+ reset slave;
+ start slave;
+ stop slave;
+ SELECT count(*) FROM test.t1;
+ count(*)
+ 0 <--------------- Rolled back as expected ******************
+ start slave;
+ select master_pos_wait('master-bin.001',3000)>=0;
+ master_pos_wait('master-bin.001',3000)>=0
+ 1
+ select max(a) from test.t1;
+ max(a)
+ 8000
+ select count(*) from test.t1;
+ count(*)
+ 8000 <------------------- all rows accounted for *********************
+ drop table t1;

********* Row Based, same test *******************
+ 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;
+ stop slave;
+ create table test.t1 (a int) engine=innodb;
+ reset slave;
+ start slave;
+ stop slave;
+ SELECT count(*) FROM test.t1;
+ count(*)
+ 106       < ---------------------- should be ZERO (0) ****************** Did not rollback
+ start slave;
+ select master_pos_wait('master-bin.001',3000)>=0;
+ master_pos_wait('master-bin.001',3000)>=0
+ 1
+ select max(a) from test.t1;
+ max(a)
+ 8000
 select count(*) from test.t1;
+ count(*) 
+ 116 <---------- Missing about 7884 rows of data ***************************
+ drop table t1;
*****************************************************
-- source include/master-slave.inc

connection slave;
stop slave;
connection master;
--disable_warnings
create table test.t1 (a int) engine=innodb;
--enable_warnings
let $1=8000;
disable_query_log;
begin;
while ($1)
{
# eval means expand $ expressions
 eval insert into test.t1 values( $1 );
 dec $1;
}
commit;
# This will generate a 500kB master's binlog,
# which corresponds to 30 slave's relay logs.
enable_query_log;
save_master_pos;
connection slave;
reset slave;
start slave;
# We wait 1 sec for the SQL thread to be somewhere in
# the middle of the transaction, hopefully not in
# the first relay log, and hopefully before the COMMIT.
# Usually it stops when the SQL thread is around the 15th relay log.
# We cannot use MASTER_POS_WAIT() as master's position
# increases only when the slave executes the COMMIT.
# Note that except when using Valgrind, 1 second is enough for the I/O slave
# thread to fetch the whole master's binlog.
sleep 1;
stop slave;
# We suppose the SQL thread stopped before COMMIT.
# If so the transaction was rolled back
# and the table is now empty.
# Now restart
SELECT count(*) FROM test.t1;
start slave;
# And see if the table contains '8000'
# which proves that the transaction restarted at
# the right place.
# We must wait for the transaction to commit before
# reading, MASTER_POS_WAIT() will do it for sure
# (the only statement with position>=3000 is COMMIT).
select master_pos_wait('master-bin.001',3000)>=0;
select max(a) from test.t1;
select count(*) from test.t1;
--replace_column 1 # 8 # 9 # 16 # 23 # 33 #
--replace_result $MASTER_MYPORT MASTER_MYPORT
show slave status;
connection master;
# The following DROP is a very important cleaning task:
# imagine the next test is run with --skip-innodb: it will do
# DROP TABLE IF EXISTS t1; but this will delete the frm and leave
# some data in the InnoDB datafile (because at that time mysqld
# does not know about InnoDB : --skip-innodb). So if later in the
# test suite a test wants to create an InnoDB table called t1, it
# will fail with
# InnoDB: Error: table t1 already exists in InnoDB internal
# InnoDB: data dictionary. Have you deleted the .frm file etc
drop table t1;
# wait until this drop is executed on slave
save_master_pos;
connection slave;
sync_with_master;

Disregard this part of the last post, found that the binlog position was wrong
+ select master_pos_wait('master-bin.001', 552275)>=0;
+ master_pos_wait('master-bin.001', 552275)>=0
+ 1
+ select max(a) from test.t1;
+ max(a)
+ 8000
+ select count(*) from test.t1;
+ count(*)
+ 8000

But the :
SELECT count(*) FROM test.t1;
+ count(*)
+ 116
should still be Zero (0)

Seems that if you have replication, you would want the master and slave to be the same (i.e. have same data). Not repicating the commits and rollback will be okay, if only rows that are inserted, updated and or deleted are put in the bin log only after the commit has been completed on master side.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/29907

rpl_row_sp007 now works fine (must have been fixed with some other bug).
the first Jeb's testcase, I don't know: Jeb could you test it, please?
The last one, rpl_row_relayrotate is probably a different, more complex thing, not the same (issues with slave stopping and restarting maybe).
So I'm closing this bug and creating a new one dedicated to rpl_row_relayrotate

Once more:
this bug report does not need to be documented as it is specific to row-based replication which is not in the main 5.0 tree yet.
Some have found a similarity between this bug and BUG#12334; I can't tell if this is true.
A changelog entry should be made, but about BUG#12334, which was a bug in the main 5.0 tree. It's BUG#12334 which should be in the "need doc info" state.