Bug #47699 rpl.rpl_backup_block fails sporadically
Submitted: 29 Sep 2009 7:02 Modified: 14 Dec 2010 6:24
Reporter: Alexander Nozdrin 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: Libing Song CPU Architecture:Any
Tags: experimental, pb2, sporadic, test failure

[29 Sep 2009 7:02] Alexander Nozdrin
Description:
@@ -218,8 +218,8 @@
 Replicate_Ignore_Table	#
 Replicate_Wild_Do_Table	
 Replicate_Wild_Ignore_Table	
-Last_Errno	0
-Last_Error	
+Last_Errno	1590
+Last_Error	The incident RESTORE_ON_MASTER occured on the master. Message: A restore operation was initiated on the master.
 Skip_Counter	#
 Exec_Master_Log_Pos	#
 Relay_Log_Space	#
@@ -236,13 +236,13 @@
 Master_SSL_Verify_Server_Cert	No
 Last_IO_Errno	0
 Last_IO_Error	
-Last_SQL_Errno	0
-Last_SQL_Error	
+Last_SQL_Errno	1590
+Last_SQL_Error	The incident RESTORE_ON_MASTER occured on the master. Message: A restore operation was initiated on the master.
 Replicate_Ignore_Server_Ids	
 Master_Server_Id	1
 # Show the slave started without an error.
 Last_SQL_Error
-
+The incident RESTORE_ON_MASTER occured on the master. Message: A restore operation was initiated on the master.
 # Showing tables on slave.
 SHOW FULL TABLES FROM rpl_backup_block;
 Tables_in_rpl_backup_block	Table_type

mysqltest: Result content mismatch

How to repeat:
http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&test_failure_id=2348627&...
[29 Sep 2009 7:02] Alexander Nozdrin
The test case has been marked experimental.
[26 Oct 2009 6: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/88110

3649 Li-Bing.Song@sun.com	2009-10-26
      Bug#47699  	rpl.rpl_backup_block fails sporadically
      
      After 'START SLAVE' is executed, An unexpected error 'RESTORE_ON_MASTER' 
      appears in Last_Error. On Slave, The Last_Error is cleared after 
      'START SLAVE [SQL_THREAD]' has returned. 'SHOW SLAVE STATUS' sometimes is 
      executed earlier than that Last_Error is cleared. So the last error which 
      has happened before 'START SLAVE' still appears in the slave status.
      
      This patch wrote code to clear error before 'START SLAVE [SQL_THREAD]' returns.
[5 Nov 2009 9: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/89423

3694 Li-Bing.Song@sun.com	2009-11-05
      Bug#47699  	rpl.rpl_backup_block fails sporadically
      
      After 'START SLAVE' is executed, An unexpected error 'RESTORE_ON_MASTER' 
      appears in Last_Error. On Slave, The Last_Error is cleared after 
      'START SLAVE [SQL_THREAD]' has returned. 'SHOW SLAVE STATUS' sometimes is 
      executed earlier than that Last_Error is cleared. So the last error which 
      has happened before 'START SLAVE' still appears in the slave status.
      
      This patch wrote code to clear error before 'START SLAVE [SQL_THREAD]' returns.
[12 Nov 2009 9:47] Libing Song
Please re-triage this bug. 

This bug happens because the old error of the sql thread is not cleared until 'START SLAVE' has returned. sporadically, 'SHOW SLAVE STATUS' following the 'START SLAVE' will be executed before the sql thread clears the old error.

Even through rpl_backup_block only exists in mysql6.0, while the code of mysql5.1 
is same as mysql6.0. so this bug will happen in mysql5.1 sporadically.
[18 Jan 2010 19:16] Andrei Elkin
LiBing, the bug could have been fixed with Bug #50175 or bug#50176 pushed to backup-port tree.
[8 Nov 2010 10:23] Libing Song
Sketch of a test case in MTR to reproduce the bug.

Attachment: test.patch.tgz (application/x-compressed-tar, text), 765 bytes.

[9 Nov 2010 12:25] Libing Song
A  patch for this bug.

Attachment: bug47699.patch.bundle (application/octet-stream, text), 8.04 KiB.

[10 Nov 2010 6:00] 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/123356

3343 Li-Bing.Song@sun.com	2010-11-10
      Bug#47699 rpl.rpl_backup_block fails sporadically
      
      It failed because an error appeared in Slave_SQL_Error,
      the test case expects that no error happens. The reason is
      that START SLAVE released the lock and returned before it cleared
      the error, so there was a possibility that Slave_SQL_Error was not
      0 when doing the following:
      START SLAVE SQL_THREAD;
      SHOW SLAVE STATUS;
      
      After this patch, clearing error always happens before START SLAVE
      releases the lock.
[18 Nov 2010 4:45] 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/124217

3343 Li-Bing.Song@sun.com	2010-11-18
      Bug#47699 rpl.rpl_backup_block fails sporadically
      
      It failed because an error appeared in Slave_SQL_Error,
      the test case expects that no error happens. The reason is
      that START SLAVE released the lock and returned before it cleared
      the error, so there was a possibility that Slave_SQL_Error was not
      0 when doing the following:
      START SLAVE SQL_THREAD;
      SHOW SLAVE STATUS;
      
      After this patch, clearing error always happens before START SLAVE
      releases the lock.
[28 Nov 2010 9:15] 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/125239

3404 Li-Bing.Song@sun.com	2010-11-28
      Bug#47699 rpl.rpl_backup_block fails sporadically
            
      It failed because an error appeared in Slave_SQL_Error,
      the test case expects that no error happens. The reason is
      that START SLAVE released the lock and returned before it cleared
      the error, so there was a possibility that Slave_SQL_Error was not
      0 when doing the following:
      START SLAVE SQL_THREAD;
      SHOW SLAVE STATUS;
            
      After this patch, clearing error always happens before START SLAVE
      releases the lock.
[28 Nov 2010 9:22] Libing Song
Pushed into mysql-trunk-bugfixing.
[30 Nov 2010 9:26] 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/125460

3392 Li-Bing.Song@sun.com	2010-11-30
      BUG#47699
      Postfix, moved the test for this bug from rpl_slave_status to
      rpl_slave_start.test. As the other tests in rpl_slave_status don't need
      debug_sync.
[5 Dec 2010 12:44] Bugs System
Pushed into mysql-trunk 5.6.1 (revid:alexander.nozdrin@oracle.com-20101205122447-6x94l4fmslpbttxj) (version source revid:alexander.nozdrin@oracle.com-20101205122447-6x94l4fmslpbttxj) (merge vers: 5.6.1) (pib:23)
[14 Dec 2010 6:24] Jon Stephens
Issue doesn't appear in a 5.6 release, so no changelog entry required. Closed.