Bug #40160 main.backup_progress fails sporadically on pushbuild
Submitted: 19 Oct 2008 20:29 Modified: 15 Nov 2008 0:42
Reporter: Sven Sandberg Email Updates:
Status: Closed Impact on me:
None 
Category:Tests Severity:S7 (Test Cases)
Version:6.0 OS:Any
Assigned to: Chuck Bell CPU Architecture:Any
Tags: backup_progress, pushbuild, sporadic, test failure

[19 Oct 2008 20:29] Sven Sandberg
Description:
Sporadic pushbuild failure, only on sol10-amd64-a so far:

main.backup_progress           [ fail ]

mysqltest: At line 169: query 'SELECT backup_state FROM mysql.online_backup AS ob JOIN backup_progress.t1_res as t1 ON ob.backup_id = t1.id' failed: 1146: Table 'backup_progress.t1_res' doesn't exist

The result from queries just before the failure was:
< snip >
con2: Send restore command.
RESTORE FROM 'backup_progress_orig.bak';
con1: Wait for the restore to be started.
SET DEBUG_SYNC= 'now WAIT_FOR started';
Warnings:
Warning	1720	debug sync point wait timed out
con1: Display progress
select * from backup_progress.t1_res;
id
SELECT MAX(backup_id) INTO @bup_id FROM mysql.online_backup WHERE command LIKE "RESTORE FROM%";
INSERT INTO backup_progress.t1_res (id) VALUES (@bup_id);
SELECT backup_state FROM mysql.online_backup AS ob JOIN backup_progress.t1_res as t1 ON ob.backup_id = t1.id;
backup_state
running
con1: Let restore step to running state.
SET DEBUG_SYNC= 'now SIGNAL do_run WAIT_FOR running';
Warnings:
Warning	1720	debug sync point wait timed out
con1: Display progress
SELECT backup_state FROM mysql.online_backup AS ob JOIN backup_progress.t1_res as t1 ON ob.backup_id = t1.id;

More results from queries before failure can be found in /tmp/var-ps_stm_threadpool-6/log/backup_progress.log

Stopping All Servers
Restoring snapshot of databases
Saving core

How to repeat:
e.g., here: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0-rpl-merge&order=... sol10-amd64-a/ps_stm_threadpool

xref: http://tinyurl.com/6q39qf
[30 Oct 2008 8:03] Rafal Somla
When working on this bug, I propose to replace JOINs by a simpler and equivallent construct:

=== modified file 'mysql-test/t/backup_logs.test'
--- mysql-test/t/backup_logs.test       2008-08-29 22:37:36 +0000
+++ mysql-test/t/backup_logs.test       2008-10-30 08:00:17 +0000
@@ -158,8 +158,7 @@ SET DEBUG_SYNC= 'now WAIT_FOR started';
 --echo con1: Display progress
 select * from backup_logs.t1_res;
 SELECT MAX(backup_id) INTO @bup_id FROM mysql.backup_progress;
-INSERT INTO backup_logs.t1_res (id) VALUES (@bup_id);
-SELECT notes FROM mysql.backup_progress AS ob JOIN backup_logs.t1_res as t1 ON ob.backup_id = t1.id;
+SELECT notes FROM mysql.backup_progress WHERE backup_id=@bup_id;
[4 Nov 2008 20:08] 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/57833

2727 Chuck Bell	2008-11-04
      BUG#40160 : main.backup_progress fails sporadically on pushbuild
      
      Test contains non-deterministic behaviour when using SELECTs to
      examine backup logs. Patch uses debug insert to control
      backup_ids and complex SELECTs removed. Also used PURGE BACKUP
      LOGS to assist in deterministic results.
[5 Nov 2008 9:01] Jørgen Løland
Good to push
[5 Nov 2008 14:35] Rafal Somla
Good to push.
[14 Nov 2008 14:50] Bugs System
Pushed into 6.0.9-alpha  (revid:cbell@mysql.com-20081104200801-c455io1lb9gvqrmd) (version source revid:jorgen.loland@sun.com-20081114134411-xypyf8wyjc2nm3ly) (pib:5)
[15 Nov 2008 0:42] Paul DuBois
Test case changes. No changelog entry needed.