Bug #26366 RBR fails with DELETE on concurrent locked InnoDB tables
Submitted: 14 Feb 2007 12:35 Modified: 25 Oct 2007 8:56
Reporter: Giuseppe Maxia Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Row Based Replication ( RBR ) Severity:S2 (Serious)
Version:5.1.16 OS:Linux (Linux, Mac OS X)
Assigned to: Assigned Account CPU Architecture:Any
Tags: bfsm_2007_10_18, innodb, locks, RBR, replication

[14 Feb 2007 12:35] Giuseppe Maxia
Description:
When several sessions try to access a locked InnoDB table, row-based replication fails after a DELETE FROM statement.

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

rpl_row_lock_innodb            [ fail ]

Errors are (from /Users/gmax/install/51/mysql-test/var/log/mysqltest-time) :
mysqltest: At line 27: could not sync with master ('select master_pos_wait('master-bin.000001', 988)' returned NULL)
(the last lines may be the most important ones)
Result from queries before failure can be found in /Users/gmax/install/51/mysql-test/var/log/rpl_row_lock_innodb.log.

Notice that, if TRUNCATE is used instead of DELETE, replication still holds.

How to repeat:
Please see attached file for test case and logs.
[14 Feb 2007 12:41] Giuseppe Maxia
see the attached README.txt file

Attachment: rpl_row_lock.tar.gz (application/gzip, text), 9.19 KiB.

[14 Feb 2007 13:12] Giuseppe Maxia
For a quick examination, here is the slave error log:

CURRENT_TEST: rpl_row_lock_innodb
070214 15:08:39 [Warning] Setting lower_case_table_names=2 because file system for /Users/gmax/install/51/mysql-test/var/slave-data/ is case insensitive
070214 15:08:39 [Warning] One can only use the --user switch if running as root

070214 15:08:39 [Note] /Users/gmax/install/51/sql/.libs/mysqld: ready for connections.
Version: '5.1.16-beta-log'  socket: '/Users/gmax/install/51/mysql-test/var/tmp/slave.sock'  port: 9308  Source distribution
070214 15:08:39 [Note] SCHEDULER: Loaded 0 events
070214 15:08:39 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log '/Users/gmax/install/51/mysql-test/var/log/slave-relay-bin.000001' position: 4
070214 15:08:39 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:9306',replication started in log 'FIRST' at position 4
070214 15:08:39 [ERROR] Slave: Error in Delete_rows event: row application failed, Error_code: 137
070214 15:08:39 [ERROR] Slave: Error in Delete_rows event: error during transaction execution on table test.t1, Error_code: 137
070214 15:08:39 [ERROR] Slave (additional info): Unknown error Error_code: 1105
070214 15:08:39 [Warning] Slave: Unknown error Error_code: 1105
070214 15:08:39 [Warning] Slave: Unknown error Error_code: 1105
070214 15:08:39 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000001' position 789
070214 15:09:09 [Note] /Users/gmax/install/51/sql/.libs/mysqld: Normal shutdown

070214 15:09:09 [Note] SCHEDULER: Purging queue. 0 events
070214 15:09:09 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013)
070214 15:09:09 [Note] Slave I/O thread killed while reading event
070214 15:09:09 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 988
070214 15:09:11 [Note] /Users/gmax/install/51/sql/.libs/mysqld: Shutdown complete
[25 Oct 2007 8:49] Mats Kindahl
Bug is present in 5.1.17, but is not possible to repeat in 5.1.18 (and later). Bug closed in normal manner since it was a real bug present, and repeatable, in versions prior to  5.1.18.
[25 Oct 2007 9:24] Mats Kindahl
Bug was probably fixed by patch for BUG#22583.