Bug #37200 rpl_switch_stm_row_mixed fails sporadically in pushbuild
Submitted: 4 Jun 2008 17:23 Modified: 29 Jul 2008 9:52
Reporter: Sven Sandberg Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.1, 6.0 OS:Any
Assigned to: Sven Sandberg CPU Architecture:Any
Tags: insert delayed, pushbuild, rpl_switch_stm_row_mixed, sporadic, test case, test failure
Triage: D3 (Medium)

[4 Jun 2008 17:23] Sven Sandberg
Description:
rpl_switch_stm_row_mixed fails sporadically (very rarely) in pushbuild, with the following result mismatch:

==== begin result mismatch ====
rpl.rpl_switch_stm_row_mixed 'mix' [ fail ]

mysqltest: At line 570: command "diff_files" failed with error 1

The result from queries just before the failure was:
< snip >
DROP TABLE IF EXISTS t13;
CREATE TABLE t13 (data CHAR(64));
INSERT INTO t13 VALUES (USER());
INSERT INTO t13 VALUES (my_user());
INSERT INTO t13 VALUES (CURRENT_USER());
INSERT INTO t13 VALUES (my_current_user());
--- /dev/shm/var-n_mix-100/tmp/rpl_switch_stm_row_mixed_master.sql	2008-05-28 15:48:28.988917236 +0300
+++ /dev/shm/var-n_mix-100/tmp/rpl_switch_stm_row_mixed_slave.sql	2008-05-28 15:48:29.258824436 +0300
@@ -122,11 +122,6 @@
 INSERT INTO `t21` VALUES ('foo6_2_8d2298dc-7e04-102b-b0d9-00d06806ad18');
 INSERT INTO `t21` VALUES ('foo6_3_8d22e5bc-7e04-102b-b0d9-00d06806ad18');
 INSERT INTO `t21` VALUES ('foo6_3_8d23162c-7e04-102b-b0d9-00d06806ad18');
-INSERT INTO `t21` VALUES ('delay_1_');
-INSERT INTO `t21` VALUES ('delay_2_8d2e2472-7e04-102b-b0d9-00d06806ad18');
-INSERT INTO `t21` VALUES ('delay_6_');
-INSERT INTO `t21` VALUES ('0.08733753216204936');
-INSERT INTO `t21` VALUES ('2.345');
 INSERT INTO `t22` VALUES ('1');
 INSERT INTO `t22` VALUES ('8d151ef0-7e04-102b-b0d9-00d06806ad18');
 INSERT INTO `t3` VALUES ('try_50_11');

More results from queries before failure can be found in /dev/shm/var-n_mix-100/log/rpl_switch_stm_row_mixed.log

Stopping All Servers
Restoring snapshot of databases
==== end result mismatch ====

The reason is that we do not wait until INSERT DELAYED statements are replicated to the slave. More precisely, the test does this:

lines 285-294:
  On master, INSERT DELAYED INTO t2 VALUES ...

lines 296-297
  On master, Wait until all inserted rows are found, by calling
  SELECT count(*) FROM t2.

line 353:
  sync_slave_with_master;

However, in mixed and row mode, rows are written to the binlog *after* they have been written to the table. So it is not guaranteed that the rows are in the binlog when it is being sync'ed. In fact, it is not guaranteed that the rows ever make it to the binlog: maybe the insert delayed thread does not get any more CPU cycles until the test ends.

How to repeat:
.

Suggested fix:
Wait until the rows show up in t2 on slave instead of on master.
[9 Jun 2008 13:23] Sven Sandberg
Patch committed at
http://lists.mysql.com/commits/47454
[30 Jun 2008 11:03] 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/48730

2681 Sven Sandberg	2008-06-30
      BUG#37200: rpl_switch_stm_row_mixed fails sporadically in pushbuild
      Problem: rpl_switch_stm_row_mixed did not wait until row events generated by
      INSERT DELAYED were written to the master binlog before it synchronized slave
      with master. This caused sporadic errors where these rows were missing on
      slave.
      Fix: wait until all rows appear on the slave.
      This is a backport, applying the same to 5.1-bugteam as was previously
      applied to 6.0-rpl
[30 Jun 2008 11:07] 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/48733

2681 Sven Sandberg	2008-06-30
      BUG#37200: rpl_switch_stm_row_mixed fails sporadically in pushbuild
      Problem: rpl_switch_stm_row_mixed did not wait until row events generated by
      INSERT DELAYED were written to the master binlog before it synchronized slave
      with master. This caused sporadic errors where these rows were missing on
      slave.
      Fix: wait until all rows appear on the slave.
      This is a backport, applying the same to 5.1-bugteam as was previously
      applied to 6.0-rpl
[30 Jun 2008 11:09] 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/48734

2681 Sven Sandberg	2008-06-30
      BUG#37200: rpl_switch_stm_row_mixed fails sporadically in pushbuild
      Problem: rpl_switch_stm_row_mixed did not wait until row events generated by
      INSERT DELAYED were written to the master binlog before it synchronized slave
      with master. This caused sporadic errors where these rows were missing on
      slave.
      Fix: wait until all rows appear on the slave.
      This is a backport, applying the same to 5.1-bugteam as was previously
      applied to 6.0-rpl
[1 Jul 2008 19:20] 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/48836

2682 Patrick Crews	2008-07-01 [merge]
      upmerge into 5.1
[2 Jul 2008 14:50] 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/48883

2683 Sven Sandberg	2008-07-02
      BUG#37200: rpl_switch_stm_row_mixed fails sporadically in pushbuild
      The previous fix for the bug was incomplete. The test failed because
      t2 did not exist on the slave (since the slave was lagging) when the
      wait_condition was executed. Fixed by inserting sync_slave_with_master
      just after t2 was created.
[2 Jul 2008 15:01] 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/48885

2683 Sven Sandberg	2008-07-02
      BUG#37200: rpl_switch_stm_row_mixed fails sporadically in pushbuild
      The previous fix for the bug was incomplete. The test failed
      because t2 did not exist on the slave (since the slave was
      lagging) when the
      wait_condition was executed. Fixed by inserting
      sync_slave_with_master just after t2 was created.
[2 Jul 2008 15:02] 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/48886

2683 Sven Sandberg	2008-07-02
      BUG#37200: rpl_switch_stm_row_mixed fails sporadically in pushbuild
      The previous fix for the bug was incomplete. The test failed
      because t2 did not exist on the slave (since the slave was
      lagging) when the
      wait_condition was executed. Fixed by inserting
      sync_slave_with_master just after t2 was created.
[2 Jul 2008 15:02] 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/48887

2683 Sven Sandberg	2008-07-02
      BUG#37200: rpl_switch_stm_row_mixed fails sporadically in pushbuild
      The previous fix for the bug was incomplete. The test failed
      because t2 did not exist on the slave (since the slave was
      lagging) when the
      wait_condition was executed. Fixed by inserting
      sync_slave_with_master just after t2 was created.
[2 Jul 2008 17:05] 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/48896

2684 Timothy Smith	2008-07-02 [merge]
      Up-merge syntax fix from 5.0-bugteam.
[3 Jul 2008 8:24] 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/48925

2684 Sven Sandberg	2008-07-03
      BUG#37200: rpl_switch_stm_row_mixed fails sporadically in pushbuild
      This bug has been fixed in two slightly different ways in
      6.0-rpl and {5.1,6.0}-bugteam. To avoid future merge
      problems, I'm now copying the 6.0-rpl fix to 5.1-bugteam.
[28 Jul 2008 16:47] Bugs System
Pushed into 5.1.28  (revid:joerg@mysql.com-20080714105031-88hmr2baz5di9xej) (version source revid:joerg@mysql.com-20080714105031-88hmr2baz5di9xej) (pib:3)
[28 Jul 2008 19:32] Paul Dubois
Test case change. No 5.1.x changelog entry needed.

Setting report to Patch Queued pending push of fix to 6.0.x.
[29 Jul 2008 9:07] Georgi Kodinov
Pushed into 6.0.7-alpha.
[29 Jul 2008 9:52] Jon Stephens
Closed per comment from Paul.
[30 Jan 2009 13:27] 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)