Bug #47994 Interruption of BACKUP command reported multiple times.
Submitted: 12 Oct 2009 11:55 Modified: 2 Mar 2010 2:24
Reporter: Rafal Somla Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Backup Severity:S3 (Non-critical)
Version: OS:Any
Assigned to: Thava Alagu CPU Architecture:Any
Tags: backup team tree

[12 Oct 2009 11:55] Rafal Somla
Description:
When BACKUP command is interrupted at certain places, it pushes on error stack the same error message several times:

SHOW WARNINGS;
Level   Code    Message
Error   1317    Query execution was interrupted
Error   1317    Query execution was interrupted
Error   1317    Query execution was interrupted
Error   1317    Query execution was interrupted
Warning 1777    Operation aborted

How to repeat:
The following test script repeats the problem. It can be observed when BACKUP is interrupted at sync points 'before_backup_privileges' and 'after_backup_start_backup' but not at other places.

#
# Setup
#

let $bdir=`SELECT @@backupdir`;

--disable_warnings
DROP DATABASE IF EXISTS bup_intr;
--error 0,1
--remove_file $bdir/bup_intr.bkp
--enable_warnings

CREATE DATABASE bup_intr;
USE bup_intr;

CREATE TABLE t1(a int);
INSERT INTO  t1 VALUES (1),(2),(3);

--connect (killer,localhost,root,,)
--connection default

#let $sync_point= before_backup_privileges;
let $sync_point= after_backup_start_backup;

let $id=`select connection_id()`;

PURGE BACKUP LOGS;
SET DEBUG_SYNC='reset';
eval SET DEBUG_SYNC='$sync_point SIGNAL here WAIT_FOR go';
SET DEBUG_SYNC='backup_restore_ctx_dtor SIGNAL here';

--echo #
--echo # Start the command.
--echo #
--send
BACKUP DATABASE bup_intr TO 'bup_intr.bkp';

  --connection killer

  --echo #
  --echo # Wait for the command to reach its synchronization point,
  --echo # then kill it.
  --echo #
  SET DEBUG_SYNC='now WAIT_FOR here';
  eval KILL QUERY $id;
  SET DEBUG_SYNC='now SIGNAL go';

--connection default

--echo #
--echo # Reap the command and show results.
--echo #
--error ER_QUERY_INTERRUPTED
reap;
SHOW WARNINGS;

#
# Cleanup
# 

SET DEBUG_SYNC='reset';
--disable_warnings
DROP DATABASE IF EXISTS bup_intr;
--error 0,1
--remove_file $bdir/bup_intr.bkp
--enable_warnings

--exit

Suggested fix:
Only one "Query execution was interrupted" should be reported.
[29 Oct 2009 21:33] Thava Alagu
Some APIs in si_objects.cc don't provide ways to distinguish return failure from success. This could sometimes cause backup to continue to attempt to execute multiple queries even after being interrupted. This results in multiple warnings in the stack. Even after fixing this, in the case killing query, we may end up with two "query interrupted" warning messages on the stack (one from the service API query and the one for the main backup command query). I would rather leave this as it is without attempting to reduce this two to one, as the fix involves relatively major changes with the risk of potentially losing some warnings that may be useful in trouble shooting.
[30 Oct 2009 0: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/88663

2853 Thava Alagu	2009-10-30
      Bug#47994 - Interruption of BACKUP command reported multiple times.
      
      Added additional checks to catch interruption of the command earlier
      to stop the backup kernel from executing further queries.
      Removed some duplicate pushing of warnings.
      modified:
        mysql-test/suite/backup/r/backup_intr_errors.result
        mysql-test/suite/backup/t/backup_intr_errors.test
        sql/backup/backup_info.cc
        sql/si_objects.cc
        sql/si_objects.h
[30 Oct 2009 17:31] Ingo Strüwing
Patch might not (completely) solve the problem. Please see email. Back to in-progress for now.
[5 Nov 2009 2: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/89393

2888 Thava Alagu	2009-11-05
      BUG#47994 : Interruption of BACKUP command reported multiple times.
      
      When backup session is interrupted at certain stages, multiple duplicate
      warning messages are generated.
      
      Added additional checks to catch interruption of the command earlier
      to stop the backup kernel from executing further queries.
      Removed some duplicate pushing of warnings.
      modified:
        mysql-test/suite/backup/r/backup_bml_block.result
        mysql-test/suite/backup/r/backup_intr_errors.result
        mysql-test/suite/backup_engines/r/backup_interruption.result
        sql/backup/backup_info.cc
        sql/backup/kernel.cc
        sql/backup/logger.h
        sql/si_objects.cc
        sql/si_objects.h
[6 Nov 2009 6:36] 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/89551

2888 Thava Alagu	2009-11-06
      BUG#47994 : Interruption of BACKUP command reported multiple times.
      
      When backup session is interrupted at certain stages, multiple duplicate
      warning messages are generated.
      
      Added additional checks to catch interruption of the command earlier
      to stop the backup kernel from executing further queries.
      Removed some duplicate pushing of warnings. 
      modified:
        mysql-test/suite/backup/r/backup_errors.result
        mysql-test/suite/backup/t/backup_errors.test
        mysql-test/suite/backup_engines/r/backup_interruption.result
        sql/backup/backup_info.cc
        sql/backup/backup_kernel.h
        sql/backup/kernel.cc
        sql/backup/logger.h
        sql/share/errmsg-utf8.txt
        sql/share/errmsg.txt
        sql/si_logs.cc
        sql/si_logs.h
        sql/si_objects.cc
        sql/si_objects.h
[6 Nov 2009 14:09] Ingo Strüwing
Approved pending changes. Please see email.
[8 Nov 2009 19:31] 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/89721

2888 Thava Alagu	2009-11-09
      BUG#47994 : Interruption of BACKUP command reported multiple times.
      
      When backup session is interrupted at certain stages, multiple duplicate
      warning messages are generated.
      
      Added additional checks to catch interruption of the command earlier 
      to stop the backup kernel from executing further queries.
      Removed some duplicate pushing of warnings.
[16 Nov 2009 10:03] Rafal Somla
Waiting for new patch from Thava.
[17 Nov 2009 17:41] 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/90727

2891 Thava Alagu	2009-11-17
      BUG#47994 : Interruption of BACKUP command reported multiple times.
      
      When backup session is interrupted at certain stages, multiple 
      duplicate warning messages are generated.
      
      Added additional checks to catch interruption of the command 
      earlier to stop backup kernel from executing further queries.
      Removed some duplicate pushing of warnings.
[17 Nov 2009 18:18] Rafal Somla
Good to push.
[17 Nov 2009 19:28] 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/90746

2891 Thava Alagu	2009-11-18
      BUG#47994 : Interruption of BACKUP command reported multiple times.
      
      When backup session is interrupted at certain stages, multiple 
      duplicate warning messages are generated.
      
      Added additional checks to catch interruption of the command 
      earlier to stop backup kernel from executing further queries.
      Removed some duplicate pushing of warnings.
     @ sql/si_objects.cc
        Removed some redundant pushing of messages. 
        Still user may get some duplicate query interrupted messages.
        Todo: The duplicate messages should be filtered out when they are
        pushed into thread warnings stack.
[17 Nov 2009 19:44] 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/90750

2891 Thava Alagu	2009-11-18
      BUG#47994 : Interruption of BACKUP command reported multiple times.
      
      When backup session is interrupted at certain stages, multiple 
      duplicate warning messages are generated.
      
      Added additional checks to catch interruption of the command 
      earlier to stop backup kernel from executing further queries.
      Removed some duplicate pushing of warnings.
     @ sql/si_objects.cc
        Removed some redundant pushing of messages. 
        Still user may get some duplicate query interrupted messages.
        Todo: The duplicate messages should be filtered out when they are
        pushed into thread warnings stack.
[20 Feb 2010 9:16] Bugs System
Pushed into 6.0.14-alpha (revid:ingo.struewing@sun.com-20100218152520-s4v1ld76bif06eqn) (version source revid:ingo.struewing@sun.com-20100119103538-wtp5alpz4p2jayl5) (merge vers: 6.0.14-alpha) (pib:16)
[2 Mar 2010 2:24] Paul DuBois
Noted in 6.0.14 changelog.

Interruption of BACKUP DATABASE resulted in spurious duplicate error
messages.