Bug #37933 Test "rpl_insert" fails - timing problem in replication test ?
Submitted: 7 Jul 2008 15:03 Modified: 30 Jan 2009 17:16
Reporter: Joerg Bruehe Email Updates:
Status: Closed Impact on me:
None 
Category:Tests: Replication Severity:S3 (Non-critical)
Version:5.1.26-rc OS:Any
Assigned to: Sven Sandberg CPU Architecture:Any
Tags: 51rpl

[7 Jul 2008 15:03] Joerg Bruehe
Description:
I sure hope this is just a problem with the test, not with replication.

Found in the build of 5.1.26-rc.

=====
::::::::::::::
rpl.rpl_insert 'stmt'          [ fail ]

mysqltest: In included file "./include/wait_condition.inc": At line 42: Error running query 'SELECT COUNT(*) =
 5000 FROM mysqlslap.t1': 1146 Table 'mysqlslap.t1' doesn't exist

The result from queries just before the failure was:
#
# Bug#20821: INSERT DELAYED fails to write some rows to binlog
#
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;
CREATE SCHEMA IF NOT EXISTS mysqlslap;
USE mysqlslap;
CREATE TABLE t1 (id INT, name VARCHAR(64));
SELECT COUNT(*) FROM mysqlslap.t1;
COUNT(*)
5000
=====

1) It occurred in all three modes: "stmt", "row", and "mixed".

2) Platform list varies slightly, highest chance is in the RPM builds for RedHat4 on AMD64.

In fact, I had it in Linux RPM builds only, but from my understanding of the failure (see below) this should not be significant.

How to repeat:
Run the test (sufficiently often ?).

Suggested fix:
My understanding is that it all worked on the master,
that this failure occurred only on the slave when checking for the 5,000 rows.

In the test, I do not see any enforcement that the slave already executed the "create table" (via replication) when it is instructed to wait for the 5,000 rows.

If this understanding is correct:
1) Either ensure "create table" is executed on the slave
   before starting the 5,000 row insert on the master,
2) or add a wait condition on the slave, for the "create table".
[7 Jul 2008 15:35] Bugs System
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/49106

2621 Sven Sandberg	2008-07-07
      BUG#37933: Test "rpl_insert" fails - timing problem in replication test ?
      Problem: the test syncs slave by a 'wait_condition' waiting until
      table t1 has 5000 rows. However, there is no guarantee that t1
      makes it to the slave before the wait_condition.
      Fix: sync_slave_with_master just after t1 was created.
[31 Jul 2008 1:01] BJ Dierkes
Please note, that this patch did fine for EL5-i386 however I am still failing on rpl.rpl_insert 'mix' on EL5 64bit:

rpl.rpl_innodb_bug30919 'mix'  
[ pass ]           1152
rpl.rpl_innodb_mixed_ddl 'mix' 
[ pass ]            650
rpl.rpl_innodb_mixed_dml 'mix' [ pass ]           4789
rpl.rpl_insert 'mix'           
[ fail ]
mysqltest: At line 20: command "$MYSQL_SLAP --silent --concurrency=5 --iterations=200 --query=$query --delimiter=";"" failed
The result from queries just before the failure was:
#
# Bug#20821: INSERT DELAYED fails to write some rows to binlog
#
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;
CREATE SCHEMA IF NOT EXISTS mysqlslap;
USE mysqlslap;
CREATE TABLE t1 (id INT, name VARCHAR(64));
exec of '/builddir/build/BUILD/mysql-5.1.26-rc/client/mysqlslap -uroot --port=9306 --socket=/builddir/build/BUILD/mysql-5.1.26-rc/mysql-test/var/tmp/master.sock --password=  --silent --concurrency=5 --iterations=200 --query="INSERT DELAYED INTO t1 VALUES (1, 'Dr. No'), (2, 'From Russia With Love'), (3, 'Goldfinger'), (4, 'Thunderball'), (5, 'You Only Live Twice')" --delimiter=";"' failed, error: 512, status: 2, errno: 0
More results from queries before failure can be found in /builddir/build/BUILD/mysql-5.1.26-rc/mysql-test/var/log/rpl_insert.log
Aborting: rpl.rpl_insert failed in default mode. 
To continue, re-run with '--force'.
Stopping All Servers
make: *** [test-ns] Error 1

OTHER LOG: /builddir/build/BUILD/mysql-5.1.26-rc/mysql-test/var/log/rpl_insert.log

#
# Bug#20821: INSERT DELAYED fails to write some rows to binlog
#
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;
CREATE SCHEMA IF NOT EXISTS mysqlslap;
USE mysqlslap;
CREATE TABLE t1 (id INT, name VARCHAR(64));
exec of '/builddir/build/BUILD/mysql-5.1.26-rc/client/mysqlslap -uroot --port=9306 --socket=/builddir/build/BUILD/mysql-5.1.26-rc/mysql-test/var/tmp/master.sock --password=  --silent --concurrency=5 --iterations=200 --query="INSERT DELAYED INTO t1 VALUES (1, 'Dr. No'), (2, 'From Russia With Love'), (3, 'Goldfinger'), (4, 'Thunderball'), (5, 'You Only Live Twice')" --delimiter=";"' failed, error: 512, status: 2, errno: 0

Not that I think it is related, however I did also apply the patches committed for bug:

Bug#21358

And the tests for mysqlslap were still failing... so I added the mysqlslap test to disabled.def ....  Like I said not sure if anything would be related...  but it seems the test failures keep compounding so the only way to get through a build is to disable them.

Please let me know if there is any further info that might be helpful.

Thanks.
[5 Aug 2008 5:43] Sven Sandberg
BJ Dierkes, the problem you describe is different from the present bug. Could you open a new bug report please? That way, you will get a support engineer working with your case. Please include all the information you gave above, and also include which version you have tested with. Please also say whether you see this failure every time or if it appears randomly.
[30 Jan 2009 13:28] Bugs System
Pushed into 6.0.10-alpha (revid:luis.soares@sun.com-20090129165607-wiskabxm948yx463) (version source revid:luis.soares@sun.com-20090129163120-e2ntks4wgpqde6zt) (merge vers: 6.0.10-alpha) (pib:6)
[30 Jan 2009 15:08] Bugs System
Pushed into 5.1.32 (revid:luis.soares@sun.com-20090129165946-d6jnnfqfokuzr09y) (version source revid:mats@mysql.com-20080708162309-ev227w8llwz2sqka) (merge vers: 5.1.28) (pib:6)
[30 Jan 2009 17:16] Paul DuBois
Test case changes. No changelog entry needed.
[17 Feb 2009 14:54] Bugs System
Pushed into 5.1.32-ndb-6.3.23 (revid:tomas.ulin@sun.com-20090217131017-6u8qz1edkjfiobef) (version source revid:tomas.ulin@sun.com-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)
[17 Feb 2009 16:42] Bugs System
Pushed into 5.1.32-ndb-6.4.3 (revid:tomas.ulin@sun.com-20090217134419-5ha6xg4dpedrbmau) (version source revid:tomas.ulin@sun.com-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)
[17 Feb 2009 18:18] Bugs System
Pushed into 5.1.32-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090217134216-5699eq74ws4oxa0j) (version source revid:tomas.ulin@sun.com-20090201210519-vehobc4sy3g9s38e) (merge vers: 5.1.32-ndb-6.2.17) (pib:6)