Bug #25228 rpl_relayspace.test fails on powermacg5, vm-win2003-32-a, sles10-ia64-a
Submitted: 21 Dec 2006 7:57 Modified: 12 Oct 2010 15:16
Reporter: Ingo Struewing Email Updates:
Status: Can't repeat
Category:Tests: Replication Severity:S2 (Serious)
Version:4.1.23, 5.1.21-bk OS:Any
Assigned to: Serge Kozlov Target Version:5.1+
Tags: sporadic, pushbuild, test failure, pbfail
Triage: Triaged: D3 (Medium)

[21 Dec 2006 7:57] Ingo Struewing
Description:
Quote from
https://intranet.mysql.com/~knielsen/pb/getlog.pl?dir=mysql-4.1-engines&entry=istruewing@c...

rpl_relayspace                 [ fail ]

Errors are (from
/Users/henry/pb/mysql-4.1-engines/31/mysql-4.1.23-pb31/mysql-test/var/log/mysqltest-time)
:
mysqltest: Result content mismatch
(the last lines may be the most important ones)
Below are the diffs between actual and expected results:
-------------------------------------------------------
*** r/rpl_relayspace.result	Thu Dec 21 02:38:18 2006
--- r/rpl_relayspace.reject	Thu Dec 21 05:48:02 2006
***************
*** 16,19 ****
  start slave;
  select master_pos_wait('master-bin.001',200,6)=-1;
  master_pos_wait('master-bin.001',200,6)=-1
! 0
--- 16,19 ----
  start slave;
  select master_pos_wait('master-bin.001',200,6)=-1;
  master_pos_wait('master-bin.001',200,6)=-1
! 1
-------------------------------------------------------
Please follow the instructions outlined at

How to repeat:
See pushbuild log.
[10 Jan 2007 22:19] Andrei Elkin
The test has `sleep 2' which might be not always enough for slave io thread to
receive master's data.
Increasing would help but not absolutely.
The right solution is to wait for the event with slave io thread using
wait_slave_status.

One of earliest regressions of this test found on bug db:
/home/mysqldev/pb/mysql-5.0/push-ingo@mysql.com-20060506152308.info/mysql-5.0.22-standard/mysql-test/var-ps_stm-5/log/mysqltest-time)
:\nmysqltest: Result content mismatch\n(the last lines may be
the most important ones)\nBelow are the diffs between actual and expected
results:\n-------------------------------------------------------\n***
r/rpl_relayspace.result\tSat May  6 16:34:26 2006\n--- r/rpl_relayspace.reject\tSun May 
7 07:08:21 2006\n***************\n*** 16,19 ****\n  start slave;\n  select
master_pos_wait('master-bin.001',200,6)=-1;\n 
master_pos_wait('master-bin.001',200,6)=-1\n! 0\n--- 16,19 ----\n  start slave;\n  select
master_pos_wait('master-bin.001',200,6)=-1;\n 
master_pos_wait('master-bin.001',200,6)=-1\n! 1\n
[22 Jan 2007 9:25] Alexander Barkov
This test does not seem to fail anylonger.
Either it was fixed by some patch pushed after Ingo noticed the problem.
Or this is a sporadic bug, rarely hapenning. 
Setting status to "Can't repeat" as negotiated with Ingo.
[1 Aug 2007 21:19] Timothy Smith
Hi, I'm re-opening this, as it shows up in current MySQL 5.1 trees, but this time on
platform vm-win2003-32-a.

For example, see these pushes.

https://intranet.mysql.com/~tsmith/bugs/showpush.pl?dir=mysql-5.1-new-maint&order=713
https://intranet.mysql.com/~tsmith/bugs/showpush.pl?dir=mysql-5.1-opt&order=285

I suspect the problem is here:

connection slave;
reset slave;
start slave io_thread;
# Give the I/O thread time to block.
sleep 2;
# a Bug caused the I/O thread to refuse stopping.
stop slave io_thread;
reset slave;

The "sleep 2" probably is to blame; the slave io_thread doesn't have time to start up and
actually block on the busy server.
[3 Aug 2007 11:14] 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/32064

ChangeSet@1.2500, 2007-08-03 14:14:33+03:00, gkodinov@magare.gmz +1 -0
  Bug #25228: rpl_relayspace.test fails on powermacg5, vm-win2003-32-a
  
  A test case was waiting for a fixed number of seconds for a specific 
  state of the slave IO thread to take place.
  Fixed by waiting in a loop for that specific thread state instead 
  (or timeout).
[15 Aug 2007 9:48] Bugs System
Pushed into 5.1.22-beta
[15 Aug 2007 9:51] Bugs System
Pushed into 5.0.48
[25 Aug 2007 14:19] Paul DuBois
Test case change. No changelog entry needed.
[19 Jun 2008 6:56] Sven Sandberg
Re-opening since the test fails, e.g., on 
https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0&order=5
and
https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0&order=4

The test is incorrectly constructed, as the output contains the result of the query:

select master_pos_wait('master-bin.001',200,6)=-1;

There are two problems with this line:
 - The result of the query depends on timing, so the test is nondeterministic. This is
what causes the test to fail.
 - It was a long time since our binlogs were called *.001. They are now called *.000001.
So I wonder if this does anything useful at all.
[17 Dec 2008 11:28] Sven Sandberg
xref searches:
rpl.rpl_relayspace         http://tinyurl.com/5tue98
rpl.rpl_relayspace 'row'   http://tinyurl.com/6lazog
rpl.rpl_relayspace 'mix'   http://tinyurl.com/6a8rok
[19 Jan 2009 12:51] 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/63542

2748 Serge Kozlov	2009-01-19
      Bug#25228:
      1. Added waiting proper state of slave for start/stop commands
      2. Name of binlog file imported from SHOW SLAVE STATUS.
      3. Updated result file.
[19 Jan 2009 15:13] 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/63562

2748 Serge Kozlov	2009-01-19
      Bug#25228:
      1. Added waiting proper state of slave for start/stop commands
      2. Name of binlog file imported from SHOW MASTER STATUS.
      3. Updated result file.
[10 Sep 2009 9:49] Luís Soares
A recent occurrence, and on linux:

rpl.rpl_relayspace                       w8 [ fail ]
        Test ended at 2009-09-08 14:25:31

CURRENT_TEST: rpl.rpl_relayspace
---
/export/home/pb2/test/sb_3-733919-1252404502.53/mysql-5.1.39-linux-x86_64-test/mysql-test/suite/rpl/r/rpl_relayspace.result	2009-09-08
13:04:07.000000000 +0300
+++
/export/home/pb2/test/sb_3-733919-1252404502.53/mysql-5.1.39-linux-x86_64-test/mysql-test/suite/rpl/r/rpl_relayspace.reject	2009-09-08
15:25:30.000000000 +0300
@@ -16,4 +16,4 @@
 start slave;
 select master_pos_wait('master-bin.001',200,6)=-1;
 master_pos_wait('master-bin.001',200,6)=-1
-0
+1

mysqltest: Result content mismatch

 - saving
'/export/home/pb2/test/sb_3-733919-1252404502.53/mysql-5.1.39-linux-x86_64-test/mysql-test/var-ps_row/8/log/rpl.rpl_relayspace/'
to
'/export/home/pb2/test/sb_3-733919-1252404502.53/mysql-5.1.39-linux-x86_64-test/mysql-test/var-ps_row/log/rpl.rpl_relayspace/'

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

Link:
http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&test_failure_id=2308500
[17 Oct 2009 9:06] 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/87224

3671 Georgi Kodinov	2009-10-17
      Made the test case experimental since it fails in mysql-pe and mysql-pe-stage
because of bug #25228.
[17 Oct 2009 9:08] Georgi Kodinov
Still happens on ubuntu in mysql-pe and mysql-pe-stage
[11 Nov 2009 6:49] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091110093407-rw5g8dys2baqkt67) (version
source revid:alik@sun.com-20091109080109-7dxapd5y5pxlu08w) (merge vers: 6.0.14-alpha)
(pib:13)