Bug #40184 Replication failure with RBR + Innodb + TRUNCATE
Submitted: 20 Oct 2008 17:11 Modified: 26 Feb 2009 21:22
Reporter: Philip Stoev Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Row Based Replication ( RBR ) Severity:S2 (Serious)
Version:5.1-bzr OS:Any
Assigned to: Assigned Account CPU Architecture:Any

[20 Oct 2008 17:11] Philip Stoev
Description:
Using TRUNCATE in a concurrent scenario with insert/update/delete in transactions on Innodb breaks row-based replication:

# 20:08:49 Slave thread has stopped with error: Could not execute Update_rows event on table test.table10_innodb_int_autoinc; Can't find record in 'table10_innodb_int_autoinc', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 20829
# 20:08:49 Slave thread has stopped with error: Could not execute Update_rows event on table test.table10_innodb_int_autoinc; Can't find record in 'table10_innodb_int_autoinc', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 20829

How to repeat:
A test case will be uploaded shortly.
[20 Oct 2008 17:13] Philip Stoev
ZZ file

Attachment: bug40184.zz (text/plain), 126 bytes.

[20 Oct 2008 17:13] Philip Stoev
YY file

Attachment: bug40184.yy (application/octet-stream, text), 400 bytes.

[20 Oct 2008 17:15] Philip Stoev
To reproduce with the Random Query Generator:

1 clone the mysql-test-extra-6.0 tree

$ cd mysql-test-extra-6.0/mysql-test/gentest
$ perl runall.pl \
  --basedir=/path/to/mysql-5.1/ \
  --rpl_mode=row \
  --gendata=conf/rpl_table.zz \
  --grammar=conf/rpl_table.yy \
  --mysqld=--innodb_lock_wait_timeout=1 \
  --queries=1000000 \
  --duration=1200 \
  --mysqld=--log-output=none \
  --engine=Innodb \
  --threads=2

This will proceed to run a replication test and will declare a failure when the slave thread stops.
[20 Oct 2008 18:17] Valeriy Kravchuk
Thank you for a bug report. Verified just as described:

openxs@suse:/home2/openxs/bzr/mysql-test-extra-6.0/mysql-test/gentest> perl runall.pl --basedir=/home2/openxs/dbs/5.1 --rpl_mode=row --gendata=/home2/openxs/bug40184.zz --grammar=/home2/openxs/bug40184.yy --mysqld=--innodb_lock_wait_timeout=1 --queries=1000000 --duration=1200 --mysqld=--log-output=none --engine=InnoDB --threads=2
# 01:24:09 Please see http://inside.mysql.com/wiki/Category:RandomQueryGenerator for more information on this test framework.
# 01:24:09 Starting
# 01:24:09 # runall.pl \
# 01:24:09 # --basedir=/home2/openxs/dbs/5.1 \
# 01:24:09 # --rpl_mode=row \
# 01:24:09 # --gendata=/home2/openxs/bug40184.zz \
# 01:24:09 # --grammar=/home2/openxs/bug40184.yy \
# 01:24:09 # --mysqld=--innodb_lock_wait_timeout=1 \
# 01:24:09 # --queries=1000000 \
# 01:24:09 # --duration=1200 \
# 01:24:09 # --mysqld=--log-output=none \
# 01:24:09 # --engine=InnoDB \
# 01:24:09 # --threads=2
# 01:24:09 Running perl mysql-test-run.pl --start-and-exit --mysqld=--innodb --mysqld="--innodb_lock_wait_timeout=1" --mysqld="--log-output=none" --mysqld=--default-storage-engine=InnoDB --mysqld=--relay-log=master-relay-bin --mysqld=--loose-innodb --mysqld=--loose-falcon-debug-mask=2 --mysqld=--secure-file-priv= --mysqld=--max-allowed-packet=16Mb --master_port=19306 rpl_alter --slave_port=19308 .
Logging: mysql-test-run.pl --start-and-exit --mysqld=--innodb --mysqld=--innodb_lock_wait_timeout=1 --mysqld=--log-output=none --mysqld=--default-storage-engine=InnoDB --mysqld=--relay-log=master-relay-bin --mysqld=--loose-innodb --mysqld=--loose-falcon-debug-mask=2 --mysqld=--secure-file-priv= --mysqld=--max-allowed-packet=16Mb --master_port=19306 rpl_alter --slave_port=19308
MySQL Version 5.1.30
Using dynamic switching of binlog format
Using default engine 'InnoDB'
Using ndbcluster when necessary, mysqld supports it
Setting mysqld to support SSL connections
Binaries are debug compiled
Using MTR_BUILD_THREAD      = 0
Using MASTER_MYPORT         = 19306
Using MASTER_MYPORT1        = 19307
Using SLAVE_MYPORT          = 19308
Using SLAVE_MYPORT1         = 19309
Using SLAVE_MYPORT2         = 19310
Using NDBCLUSTER_PORT       = 9311
Using NDBCLUSTER_PORT_SLAVE = 9312
Using IM_PORT               = 9313
Using IM_MYSQLD1_PORT       = 9314
Using IM_MYSQLD2_PORT       = 9315
 - adding combinations
Killing Possible Leftover Processes
Removing Stale Files
Creating Directories
Installing Master Database
Installing Slave1 Database
=======================================================

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

Servers started, exiting
# 01:24:18 Establishing replication, mode row ...
# 01:24:19 Starting
# 01:24:19 # gentest.pl \
# 01:24:19 # --gendata=/home2/openxs/bug40184.zz \
# 01:24:19 # --engine=InnoDB \
# 01:24:19 # --rpl_mode=row \
# 01:24:19 # --threads=2 \
# 01:24:19 # --queries=1000000 \
# 01:24:19 # --duration=1200 \
# 01:24:19 # --dsn1=dbi:mysql:host=127.0.0.1:port=19306:user=root:database=test \
# 01:24:19 # --grammar=/home2/openxs/bug40184.yy
# 01:24:19 Creating table table10_innodb_int_autoinc .
# 01:24:19 Reporters: ErrorLog, Backtrace
# 01:24:20 Validators: FalconErrors, ErrorMessageCorruption, ReplicationSlaveStatus
# 01:24:20 Starting 2 processes, 1000000 queries each, duration 1200 seconds.
# 01:24:20 Started periodic reporting process...
# 01:24:21 Slave thread has stopped with error: Could not execute Update_rows event on table test.table10_innodb_int_autoinc; Can't find record in 'table10_innodb_int_autoinc', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 35209
# 01:24:21 Killing periodic reporting process with pid 6792...
# 01:24:21 Slave thread has stopped with error: Could not execute Update_rows event on table test.table10_innodb_int_autoinc; Can't find record in 'table10_innodb_int_autoinc', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 35209
# 01:24:26 Killing child process with pid 6793...
# 01:24:26 Test completed with failure status 103.
openxs@suse:/home2/openxs/bzr/mysql-test-extra-6.0/mysql-test/gentest>
[26 Feb 2009 21:22] Mats Kindahl
Duplicate of BUG#42643.
[26 Feb 2009 22:30] Omer Barnir
triage: values updated to match original although bug is a 'dup'