MySQL Bugs: #40221: Replication failure on RBR + UPDATE the primary key

Bug #40221	Replication failure on RBR + UPDATE the primary key
Submitted:	21 Oct 2008 22:47	Modified:	20 Jan 22:33
Reporter:	Philip Stoev
Status:	Closed
Category:	Server: RBR	Severity:	S2 (Serious)
Version:	5.1-bzr, 5.1-rpl, 6.0-bzr	OS:	Any
Assigned to:	Andrei Elkin	Target Version:	5.1.31
Triage:	Triaged: D2 (Serious)

Description:
When executing a non-concurrent transactional workload which updates the primary key,
row-based replication fails as follows:

081021 23:44:59 [ERROR] Slave SQL: Could not execute Delete_rows event on table test.t1;
Can't find record in 't1', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the
event's master log master-bin.000001, end_log_pos 7910, Error_code: 1032
081021 23:44:59 [Warning] Slave: Can't find record in 't1' Error_code: 1032

How to repeat:
Please accept my apologies for the unsimplifed test case. Please let me know if a better
test case is required.

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

SET binlog_format = 'row';

CREATE TABLE `t1` (pk int auto_increment, `int` int, primary key (pk)) ENGINE=innodb;
INSERT IGNORE INTO t1 VALUES (NULL, NULL);
INSERT IGNORE INTO t1 VALUES (NULL, '9');
INSERT IGNORE INTO t1 VALUES (NULL, '1');
INSERT IGNORE INTO t1 VALUES (NULL, '9');
INSERT IGNORE INTO t1 VALUES (NULL, '2');
INSERT IGNORE INTO t1 VALUES (NULL, '3');
INSERT IGNORE INTO t1 VALUES (NULL, '3');
INSERT IGNORE INTO t1 VALUES (NULL, '6');
INSERT IGNORE INTO t1 VALUES (NULL, '9');
INSERT IGNORE INTO t1 VALUES (NULL, '8');
UPDATE `t1` SET `pk` = 1 WHERE `pk` > 2;
DELETE FROM `t1` WHERE `pk` > 3 LIMIT 9;
INSERT INTO `t1` ( `pk` ) VALUES ( 5 );
DELETE FROM `t1` WHERE `pk` = 6 LIMIT 9;
UPDATE `t1` SET `pk` = 8 WHERE `pk` > 7;
SET AUTOCOMMIT=OFF;
START TRANSACTION;
START TRANSACTION;
UPDATE `t1` SET `pk` = 0 WHERE `pk` = 8;
DELETE FROM `t1` WHERE `pk` > 0 LIMIT 5;
UPDATE `t1` SET `pk` = 3 WHERE `pk` < 1;
INSERT INTO `t1` ( `pk` ) VALUES ( 0 );
START TRANSACTION;
INSERT INTO `t1` ( `pk` ) VALUES ( 2 );
UPDATE `t1` SET `pk` = 0 WHERE `pk` > 2;
START TRANSACTION;
UPDATE `t1` SET `pk` = 2 WHERE `pk` > 9;
UPDATE `t1` SET `pk` = 1 WHERE `pk` > 9;
INSERT INTO `t1` ( `pk` ) VALUES ( 5 );
UPDATE `t1` SET `pk` = 5 WHERE `pk` < 0;
INSERT INTO `t1` ( `pk` ) VALUES ( 0 );
INSERT INTO `t1` ( `pk` ) VALUES ( 4 );
DELETE FROM `t1` WHERE `pk` = 1 LIMIT 6;
START TRANSACTION;
UPDATE `t1` SET `pk` = 6 WHERE `pk` < 6;
INSERT INTO `t1` ( `pk` ) VALUES ( 2 );
UPDATE `t1` SET `pk` = 4 WHERE `pk` = 6;
DELETE FROM `t1` WHERE `pk` = 3 LIMIT 5;
START TRANSACTION;
UPDATE `t1` SET `pk` = 0 WHERE `pk` = 7;
INSERT INTO `t1` ( `pk` ) VALUES ( 0 );
START TRANSACTION;
INSERT INTO `t1` ( `pk` ) VALUES ( 6 );
UPDATE `t1` SET `pk` = 0 WHERE `pk` = 1;
UPDATE `t1` SET `pk` = 2 WHERE `pk` > 7;
INSERT INTO `t1` ( `pk` ) VALUES ( 7 );
INSERT INTO `t1` ( `pk` ) VALUES ( 0 );
DELETE FROM `t1` WHERE `pk` < 2 LIMIT 5;
DELETE FROM `t1` WHERE `pk` = 2 LIMIT 2;
DELETE FROM `t1` WHERE `pk` < 3 LIMIT 0;
START TRANSACTION;
START TRANSACTION;
UPDATE `t1` SET `pk` = 7 WHERE `pk` < 7;
UPDATE `t1` SET `pk` = 9 WHERE `pk` < 0;
START TRANSACTION;
DELETE FROM `t1` WHERE `pk` > 5 LIMIT 6;
DELETE FROM `t1` WHERE `pk` > 5 LIMIT 2;
DELETE FROM `t1` WHERE `pk` > 1 LIMIT 9;
INSERT INTO `t1` ( `pk` ) VALUES ( 7 );
DELETE FROM `t1` WHERE `pk` < 8 LIMIT 8;
DELETE FROM `t1` WHERE `pk` > 4 LIMIT 8;
INSERT INTO `t1` ( `pk` ) VALUES ( 5 );
START TRANSACTION;
DELETE FROM `t1` WHERE `pk` > 2 LIMIT 7;
START TRANSACTION;
INSERT INTO `t1` ( `pk` ) VALUES ( 7 );
UPDATE `t1` SET `pk` = 0 WHERE `pk` > 3;
UPDATE `t1` SET `pk` = 5 WHERE `pk` > 8;
START TRANSACTION;
INSERT INTO `t1` ( `pk` ) VALUES ( 7 );
INSERT INTO `t1` ( `pk` ) VALUES ( 9 );
INSERT INTO `t1` ( `pk` ) VALUES ( 6 );
START TRANSACTION;
START TRANSACTION;
UPDATE `t1` SET `pk` = 9 WHERE `pk` > 3;
UPDATE `t1` SET `pk` = 8 WHERE `pk` > 9;
UPDATE `t1` SET `pk` = 0 WHERE `pk` > 1;
INSERT INTO `t1` ( `pk` ) VALUES ( 9 );
START TRANSACTION;
START TRANSACTION;
UPDATE `t1` SET `pk` = 8 WHERE `pk` > 8;
INSERT INTO `t1` ( `pk` ) VALUES ( 5 );
START TRANSACTION;
START TRANSACTION;
DELETE FROM `t1` WHERE `pk` > 4 LIMIT 5;
UPDATE `t1` SET `pk` = 3 WHERE `pk` > 0;
START TRANSACTION;
081021 23:01:39    6 Query      INSERT INTO `t1` ( `pk` ) VALUES ( 8 );
UPDATE `t1` SET `pk` = 7 WHERE `pk` < 5;
INSERT INTO `t1` ( `pk` ) VALUES ( 0 );
INSERT INTO `t1` ( `pk` ) VALUES ( 8 );
START TRANSACTION;
START TRANSACTION;
UPDATE `t1` SET `pk` = 5 WHERE `pk` < 4;
INSERT INTO `t1` ( `pk` ) VALUES ( 6 );
START TRANSACTION;
DELETE FROM `t1` WHERE `pk` > 9 LIMIT 8;
DELETE FROM `t1` WHERE `pk` > 3 LIMIT 3;
DELETE FROM `t1` WHERE `pk` > 1 LIMIT 6;
INSERT INTO `t1` ( `pk` ) VALUES ( 6 );
INSERT INTO `t1` ( `pk` ) VALUES ( 3 );
DELETE FROM `t1` WHERE `pk` > 7 LIMIT 6;
INSERT INTO `t1` ( `pk` ) VALUES ( 8 );
INSERT INTO `t1` ( `pk` ) VALUES ( 5 );
DELETE FROM `t1` WHERE `pk` > 0 LIMIT 5;
DELETE FROM `t1` WHERE `pk` = 7 LIMIT 3;
INSERT INTO `t1` ( `pk` ) VALUES ( 1 );
UPDATE `t1` SET `pk` = 1 WHERE `pk` > 1;
INSERT INTO `t1` ( `pk` ) VALUES ( 2 );
START TRANSACTION;
INSERT INTO `t1` ( `pk` ) VALUES ( 5 );
START TRANSACTION;
UPDATE `t1` SET `pk` = 3 WHERE `pk` < 7;
DELETE FROM `t1` WHERE `pk` < 0 LIMIT 4;
DELETE FROM `t1` WHERE `pk` < 8 LIMIT 5;
START TRANSACTION;
UPDATE `t1` SET `pk` = 6 WHERE `pk` < 5;
DELETE FROM `t1` WHERE `pk` = 5 LIMIT 8;
START TRANSACTION;
INSERT INTO `t1` ( `pk` ) VALUES ( 8 );
DELETE FROM `t1` WHERE `pk` < 6 LIMIT 9;
DELETE FROM `t1` WHERE `pk` < 0 LIMIT 6;
INSERT INTO `t1` ( `pk` ) VALUES ( 7 );
INSERT INTO `t1` ( `pk` ) VALUES ( 7 );
UPDATE `t1` SET `pk` = 7 WHERE `pk` > 7;
INSERT INTO `t1` ( `pk` ) VALUES ( 9 );
UPDATE `t1` SET `pk` = 4 WHERE `pk` < 9;
START TRANSACTION;
INSERT INTO `t1` ( `pk` ) VALUES ( 6 );
INSERT INTO `t1` ( `pk` ) VALUES ( 8 );
DELETE FROM `t1` WHERE `pk` > 0 LIMIT 3;
UPDATE `t1` SET `pk` = 1 WHERE `pk` = 8;
UPDATE `t1` SET `pk` = 2 WHERE `pk` = 2;
UPDATE `t1` SET `pk` = 5 WHERE `pk` < 4;
DELETE FROM `t1` WHERE `pk` = 0 LIMIT 2;
INSERT INTO `t1` ( `pk` ) VALUES ( 5 );
INSERT INTO `t1` ( `pk` ) VALUES ( 2 );
START TRANSACTION;

--save_master_pos
--connection slave
--sync_with_master

Thank you for the report.

Verified as described.

triage: This is a very common and simple scenario that people are likely to hit soon after
starting to use RBR/MBR replication. Not likely to be a regression from 5.1.29 but given
the common use case recommending to be fixed by 5,1 GA (same logic as with bug*40360 that
wasn't a 5.1.29 regression either).
Setting tag to SR51GA

The distilled test for the bug has merely 6 executive instuctions:

CREATE TABLE `t1` (pk int auto_increment primary key) ENGINE=innodb;
START TRANSACTION;                         /* empty */
INSERT INTO `t1` ( `pk` ) VALUES ( 1 );
INSERT INTO `t1` ( `pk` ) VALUES ( 2 );
UPDATE `t1` SET `pk` = 3 WHERE `pk` < 3;
commit;

In the end, the slave and the master are inconsistent:

connection master;
select * from t1;

pk
1
2

connection slave;
select * from t1;

pk
2
3

Trudy, Omer, fyi.

The case is not a regression of 5.1.29 as far as I have verified.
Still, it's inconsistency issue which can be gained as simple as to run the 6 lines I
provided in comments earlier.

br,

Andrei

Analysis showed that on the place of UPDATE there can be INSERT or other type of query
that modifies more that one prim key value and ends up with the dup key error.

triage: discussion following new information, however most believe there is not enough
here to ask for a re-excalation (after was already rejected and given the state of 5.1.30
- keeping values/target/tag as is

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/commits/59514

2701 Andrei Elkin	2008-11-21
      Bug #40221 Replication failure on RBR + UPDATE the primary key
      
      A transaction could result in having an extra event after a query that errored e.g
because of 
      a dup key. Such a query is rolled back in innodb, as specified, but has not been in
binlog.
      It appeares that the binlog engine did not always register for a query (statement)
because 
      the previous query had not reset  at its statement commit time. Because of that
fact there was no
      roll-back to the trx_data->before_stmt_pos position and a the pending event of the
errorred query
      could become flushed to the binlog file.
      
      Fixed with deploying the reset of trx_data->before_stmt_pos at the end of the query
processing.

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/commits/59952

2712 Andrei Elkin	2008-11-26
      Bug #40221 Replication failure on RBR + UPDATE the primary key
            
      A transaction could result in having an extra event after a query that
      errored e.g because of a dup key. Such a query is rolled back in
      innodb, as specified, but has not been in binlog. 
      It appeares that the binlog engine did not always register for a query
      (statement) because the previous query had not reset at its statement
      commit time. Because of that fact there was no roll-back to the
      trx_data->before_stmt_pos position and a the pending event of the
      errorred query could become flushed to the binlog file.
      
      Fixed with deploying the reset of trx_data->before_stmt_pos at the end
      of the query processing.

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/commits/60205

2712 Andrei Elkin	2008-11-28
      Bug #40221 Replication failure on RBR + UPDATE the primary key
            
      A transaction could result in having an extra event after a query that
      errored e.g because of a dup key. Such a query is rolled back in
      innodb, as specified, but has not been in binlog. 
      It appeares that the binlog engine did not always register for a query
      (statement) because the previous query had not reset at its statement
      commit time. Because of that fact there was no roll-back to the
      trx_data->before_stmt_pos position and a the pending event of the
      errorred query could become flushed to the binlog file.
      
      Fixed with deploying the reset of trx_data->before_stmt_pos at the end
      of the query processing.

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/commits/60414

2727 Andrei Elkin	2008-12-02
      Bug #40221 Replication failure on RBR + UPDATE the primary key
      
      A transaction could result in having an extra event after a query that
      errored e.g because of a dup key. Such a query is rolled back in
      innodb, as specified, but has not been in binlog.
      It appeares that the binlog engine did not always register for a query
      (statement) because the previous query had not reset at its statement
      commit time. Because of that fact there was no roll-back to the
      trx_data->before_stmt_pos position and a the pending event of the
      errorred query could become flushed to the binlog file.
      
      Fixed with deploying the reset of trx_data->before_stmt_pos at the end
      of the query processing.

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/commits/60955

2728 Andrei Elkin	2008-12-08
      Bug #40221  	Replication failure on RBR + UPDATE the primary key
      
      Extending bug#40221 regression test: 1. include INSERT 2. convert prim key +
autoinc to
      unique.

pushed to bugteam trees, starting from 5.1.

Pushed into 5.1.31 (revid:joro@sun.com-20090115053147-tx1oapthnzgvs1ro) (version source
revid:azundris@mysql.com-20081230114838-cn52tu180wcrvh0h) (merge vers: 5.1.31) (pib:6)

Documented in the 5.1.31 changelog as follows:

        When using row-based replication, an update of a primary key that was
        rolled back on the master due to a duplicate key error was not rolled
        back on the slave. 

Set status to NDI pending merge to 6.0 tree.

Pushed into 5.1.31-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090119095303-uwwvxiibtr38djii)
(version source revid:tomas.ulin@sun.com-20090115073240-1wanl85vlvw2she1) (merge vers:
5.1.31-ndb-6.2.17) (pib:6)

Pushed into 5.1.31-ndb-6.3.21 (revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl)
(version source revid:tomas.ulin@sun.com-20090119104956-guxz190n2kh31fxl) (merge vers:
5.1.31-ndb-6.3.21) (pib:6)

Set status back to NDI pending merge to 6.0 tree.

Pushed into 5.1.31-ndb-6.4.1 (revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5)
(version source revid:tomas.ulin@sun.com-20090119144033-4aylstx5czzz88i5) (merge vers:
5.1.31-ndb-6.4.1) (pib:6)

Set back to NDI pending merge to 6.0.

Pushed into 6.0.10-alpha (revid:joro@sun.com-20090119171328-2hemf2ndc1dxl0et) (version
source revid:azundris@mysql.com-20081230114916-c290n83z25wkt6e4) (merge vers:
6.0.9-alpha) (pib:6)

Fix also documented in 6.0.10 changelog; closed.