MySQL Bugs: #37733: rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild

Bug #37733	rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild
Submitted:	30 Jun 2008 7:21	Modified:	12 Aug 2008 17:26
Reporter:	Sven Sandberg	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	5.1, 6.0	OS:	Any
Assigned to:	Mats Kindahl	CPU Architecture:	Any
Tags:	disabled, pushbuild, rpl_flushlog_loop, sporadic, test failure

Description:
 TEST: rpl.rpl_flushlog_loop 'row'
 WHERE: 6.0-bugteam/mattiasj on Mon Jun 9 18:39:19 2008/'rh-x86-32' GCov/ps_row
 URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0-bugteam&order=18
 --
 WHERE: 5.1-bugteam/davi on Wed Jun 18 16:21:22 2008/'sapsrv1' Autopush/n_stm
 URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-5.1-bugteam&order=26
 --
 WHERE: 5.1-bugteam/gshchepa on Tue Jun 24 17:02:21 2008/'pb-valgrind-*' Valgrind/n_stm
 URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-5.1-bugteam&order=31
 --
 WHERE: 5.1-bugteam/gshchepa on Wed Jun 25 10:47:18 2008/'pb-valgrind-*' Valgrind/n_stm
 URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-5.1-bugteam&order=32
 --
 Exists on many more places, too: https://intranet.mysql.com/secure/pushbuild/xref.pl?testname=rpl.rpl_flushlog_loop

Failure: 

rpl.rpl_flushlog_loop 'stmt'   [ fail ]

mysqltest: At line 50: query 'INSERT INTO t1 VALUE(1)' failed: 1146: Table 'test.t1' doesn't exist

The result from queries just before the failure was:
< snip >
start slave;
show variables like 'relay_log%';
Variable_name	Value
relay_log	MYSQLTEST_VARDIR/master-data/relay-log
relay_log_index	
relay_log_info_file	relay-log.info
relay_log_purge	ON
relay_log_space_limit	0
stop slave;
change master to master_host='127.0.0.1',master_user='root',
master_password='',master_port=MASTER_PORT;
start slave;
stop slave;
change master to master_host='127.0.0.1',master_user='root',
master_password='',master_port=SLAVE_PORT;
start slave;

let $result_pattern= '%127.0.0.1%root%slave-bin.000001%slave-bin.000001%Yes%Yes%0%0%None%' ;

--source include/wait_slave_status.inc

More results from queries before failure can be found in /dev/shm/var-n_stm-110/log/rpl_flushlog_loop.log

Stopping All Servers
Restoring snapshot of databases
==========================================================

Another variant of failure in the same test:

 WHERE: bk_5.1-maint2/msvensson@shellback.(none) on Tue May 6 17:12:55 2008/'sapsrv2' -max/ps_row
 URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=mysql-5.1-maint2&order=64
 --
 WHERE: bk_6.0-rpl/msvensson@pilot.mysql.com on Fri May 2 20:11:53 2008/'pb-valgrind-*' Valgrind/rpl_binlog_row
 URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=mysql-6.0-rpl&order=42

Failure:

rpl.rpl_flushlog_loop                    [ fail ]

CURRENT_TEST: rpl.rpl_flushlog_loop
mysqltest: At line 45: query 'CREATE TABLE t1 (a INT KEY) ENGINE= MyISAM' failed: 1050: Table 't1' already exists

The result from queries just before the failure was:
< snip >
start slave;
show variables like 'relay_log%';
Variable_name	Value
relay_log	MYSQLD_DATADIR/relay-log
relay_log_index	
relay_log_info_file	relay-log.info
relay_log_purge	ON
relay_log_space_limit	0
stop slave;
change master to master_host='127.0.0.1',master_user='root',
master_password='',master_port=MASTER_PORT;
start slave;
stop slave;
change master to master_host='127.0.0.1',master_user='root',
master_password='',master_port=SLAVE_PORT;
start slave;

let $result_pattern= '%127.0.0.1%root%slave-bin.000001%slave-bin.000001%Yes%Yes%0%0%None%' ;

--source include/wait_slave_status.inc

More results from queries before failure can be found in /dev/shm/var-ps_row-122/4/log/rpl_flushlog_loop.log 

 - saving '/dev/shm/var-ps_row-122/4/log/rpl.rpl_flushlog_loop/' to '/dev/shm/var-ps_row-122/log/rpl.rpl_flushlog_loop/'

Retrying test, attempt(2/3)...

worker[4]clean_dir: /dev/shm/var-ps_row-122/4/tmp
worker[4]unlink: '/dev/shm/var-ps_row-122/4/tmp/check-mysqld.2.result'
worker[4]unlink: '/dev/shm/var-ps_row-122/4/tmp/check-mysqld.1.result'
worker[4]clean_dir: /dev/shm/pbtmp-ps_row-122/4
worker[4]unlink: '/dev/shm/pbtmp-ps_row-122/4/mysqld.1.sock'
worker[4]unlink: '/dev/shm/pbtmp-ps_row-122/4/mysqld.2.sock'
worker[4]rmdir: '/dev/shm/pbtmp-ps_row-122/4/mysqld.2'
worker[4]rmdir: '/dev/shm/pbtmp-ps_row-122/4/mysqld.1'
worker[4]Stopping all servers...

How to repeat:
-

I had all these happen during the build of 5.1.26-rc, too.

I had a third one, specific to Windows-64.

All of them are also reported as #37768.

Sadly, reporters had different assessment of this bug's impact.

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/49743

2628 Sven Sandberg	2008-07-15
      BUG#37733: rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild
      Post-push fix. The previous patch did 'reset master' at the wrong place.

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/49744

2628 Sven Sandberg	2008-07-15
      BUG#37733: rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild
      Post-push fix. The previous patch did 'reset master' at the wrong place.

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/49772

2629 Sven Sandberg	2008-07-15
      BUG#38127: main.mysqlbinlog_base64 fails sporadically on pushbuild
      This is not a fix to the bug. I'm just pushing a change to the
      test case that will produce debug info when the test fails next
      time.

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/49805

2630 Sven Sandberg	2008-07-16
      BUG#37733: rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild
      Post-post-push fix. The result file for rpl_rbr_to_sbr needs to be 
      updated. While I was there, made rpl_rbr_to_sbr clean up after itself
      by reverting @@binlog_format to the value it had before the test
      started.

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/49806

2630 Sven Sandberg	2008-07-16
      BUG#37733: rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild
      Post-post-push fix. The result file for rpl_rbr_to_sbr needs to be 
      updated. While I was there, made rpl_rbr_to_sbr clean up after itself
      by reverting @@binlog_format to the value it had before the test
      started.

A test case is disabled in 6.0 due to often failures.

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/50335

2675 Sven Sandberg	2008-07-23
      BUG#37733: rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild
      BUG#37884: rpl_row_basic_2myisam and rpl_row_basic_3innodb fail sporadically in pushbuild
      These have been fixed in 5.1-rpl. Re-applying fix for BUG#37884
      in 5.1-bugteam, and disabling rpl_flushlog_loop for BUG#37733 in
      5.1-bugteam.

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/50336

2675 Sven Sandberg	2008-07-23
      BUG#37733: rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild
      BUG#37884: rpl_row_basic_2myisam and rpl_row_basic_3innodb fail sporadically in pushbuild
      These have been fixed in 5.1-rpl. Re-applying fix for BUG#37884
      in 5.1-bugteam, and disabling rpl_flushlog_loop for BUG#37733 in
      5.1-bugteam.

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/50337

2675 Sven Sandberg	2008-07-23
      BUG#37733: rpl.rpl_flushlog_loop 'row' fails sporadically on pushbuild
      BUG#37884: rpl_row_basic_2myisam and rpl_row_basic_3innodb fail sporadically in pushbuild
      These have been fixed in 5.1-rpl. Re-applying fix for BUG#37884
      in 5.1-bugteam, and disabling rpl_flushlog_loop for BUG#37733 in
      5.1-bugteam.

Pushed into 6.0.7-alpha  (revid:sven@mysql.com-20080723143402-7w1p843x2ewm6p9m) (version source revid:davi.arnaut@sun.com-20080812141852-8e6knbqclpfd8irn) (pib:3)

Pushed into 5.1.28  (revid:sven@mysql.com-20080723143402-7w1p843x2ewm6p9m) (version source revid:davi.arnaut@sun.com-20080812142843-he05ncsggstbn57z) (pib:3)

Test case changes. No changelog entry needed.

Pushed into 6.0.7-alpha  (revid:cbell@mysql.com-20080822132131-uveo6wiuecy6m2b8) (version source revid:cbell@mysql.com-20080822132131-uveo6wiuecy6m2b8) (pib:3)

Pushed into 6.0.7-alpha  (revid:sven@mysql.com-20080723143402-7w1p843x2ewm6p9m) (version source revid:john.embretsen@sun.com-20080808091208-ht48kyzsk7rim74g) (pib:3)

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)

Pushed into 5.1.32 (revid:luis.soares@sun.com-20090129165946-d6jnnfqfokuzr09y) (version source revid:sven@mysql.com-20080716100050-va2u87ht5mh5qjw0) (merge vers: 5.1.28) (pib:6)

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)

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)

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)