MySQL Bugs: #46588: Backup fails to return ER_BACKUP_CONTEXT

Bug #46588	Backup fails to return ER_BACKUP_CONTEXT_CREATE
Submitted:	6 Aug 2009 19:43	Modified:	28 Oct 2009 22:22
Reporter:	Chuck Bell	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Backup	Severity:	S3 (Non-critical)
Version:	5.4.4	OS:	Any
Assigned to:	Rafal Somla	CPU Architecture:	Any

Description:
The code in kernel.cc is designed to return an error if there is a problem creating a context object. See line #486 in stream.cc.

If you use debug insertion (see below), the server will crash. The problem appears in kernel.cc @ line#1169. Note that this is after the error has been handled by the debug insertion test (see below) and appears to be during closing of the context object.

How to repeat:
The crash can be reproduced using this patch:

=== modified file 'sql/backup/kernel.cc'
--- sql/backup/kernel.cc        2009-07-28 06:25:23 +0000
+++ sql/backup/kernel.cc        2009-08-06 19:40:15 +0000
@@ -153,7 +153,12 @@ execute_backup_command(THD *thd,

   Backup_restore_ctx context(thd); // reports errors

-  if (!context.is_valid())
+  res= !context.is_valid();
+
+  // Error code insertion for ER_BACKUP_CONTEXT_CREATE.
+  DBUG_EXECUTE_IF("ER_BACKUP_CONTEXT_CREATE", res= 1;);
+
+  if (res)
     DBUG_RETURN(send_error(context, ER_BACKUP_CONTEXT_CREATE));

You can run this test to see the failure with the above patch:

--echo #
--echo # Create database and data to test.
--echo #
CREATE DATABASE backup_test;
CREATE TABLE backup_test.t1 (a char(30)) ENGINE=MEMORY;
INSERT INTO backup_test.t1 VALUES ("01 Test Basic database example"); 
INSERT INTO backup_test.t1 VALUES ("02 Test Basic database example"); 
INSERT INTO backup_test.t1 VALUES ("03 Test Basic database example"); 
INSERT INTO backup_test.t1 VALUES ("04 Test Basic database example"); 
INSERT INTO backup_test.t1 VALUES ("05 Test Basic database example"); 
INSERT INTO backup_test.t1 VALUES ("06 Test Basic database example"); 
INSERT INTO backup_test.t1 VALUES ("07 Test Basic database example"); 

CREATE TABLE backup_test.t2 (a char(30)) ENGINE=MYISAM;
INSERT INTO backup_test.t2 VALUES ("11 Test Basic database example"); 
INSERT INTO backup_test.t2 VALUES ("12 Test Basic database example"); 
INSERT INTO backup_test.t2 VALUES ("13 Test Basic database example"); 

--echo #
--echo # Now create more database objects for test.
--echo #
CREATE PROCEDURE backup_test.p1(p1 CHAR(20))
  INSERT INTO backup_test.t1 VALUES ("50");

CREATE TRIGGER backup_test.trg AFTER INSERT ON backup_test.t1 FOR EACH ROW
 INSERT INTO backup_test.t1 VALUES('Test objects count');

CREATE FUNCTION backup_test.f1() RETURNS INT RETURN (SELECT 1);

CREATE VIEW backup_test.v1 as SELECT * FROM backup_test.t1;

CREATE EVENT backup_test.e1 ON SCHEDULE EVERY 1 YEAR DO
  DELETE FROM backup_test.t1 WHERE a = "not there";

--echo #
--echo # Now we need some privileges
--echo #
GRANT ALL ON backup_test.* TO 'joe'@'user';

--replace_column 1 #
BACKUP DATABASE backup_test TO 'orig.bak';

SET SESSION debug="+d,ER_BACKUP_CONTEXT_CREATE";
--replace_column 1 #
--error ER_BACKUP_CONTEXT_CREATE
BACKUP DATABASE backup_test TO '1.bak';

Suggested fix:
Unknown.

When repaired, you can activate test case 30a and 30b in backup_errors_debug_2.test with:

#
# Test case 31 must be run once for backup and once for restore.
#
# Test for error ER_BACKUP_CONTEXT_CREATE.
LET $caseno = 31a;
LET $errno = $ER_BACKUP_CONTEXT_CREATE;
LET $errname = ER_BACKUP_CONTEXT_CREATE;
LET $operation = BACKUP;
--source suite/backup/include/test_for_error.inc

# Test for error ER_BACKUP_CONTEXT_CREATE.
LET $caseno = 31b;
LET $errno = $ER_BACKUP_CONTEXT_CREATE;
LET $errname = ER_BACKUP_CONTEXT_CREATE;
LET $operation = RESTORE;
--source suite/backup/include/test_for_error.inc

Cannot repeat using latest team tree.

Reopened because the problem has reoccurred.

REFINED PROBLEM DESCRIPTION

The code path forced by the above test violates assumption that backup::Logger reporting methods are called only when logger instance is initialized (after a call to Logger::init()). 

This happens, because in the test scenario the Backup_restore_ctx instance is destroyed before a call to Backup_restore_ctx::prepare_for_{backup,restore}() methods, where logger is initialized. In the destructor, method Backup_restore_ctx::close() calls fatal_error() (kernel.cc:1204) which then calls Logger::report_state(BUP_ERRORS) (backup_kernel.h:265). This is invalid if logger was not initialized and leads to assertion failure.

PROPOSED SOLUTION

In Backup_restore_ctx::close() call Logger::report_state() only if logger has been initialized. That is, only if the context object is in state PREPARED_FOR_BACKUP or PREPARED_FOR_RESTORE.

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

2873 Rafal Somla	2009-09-24
      Bug#46588 - Backup fails to return ER_BACKUP_CONTEXT_CREATE
      
      The problem was that a call to Logger::report_state(BUP_ERRORS)
      inside Backup_restore_ctx::close() could happen before BACKUP or
      RESTORE operation has started and the logger has been initialized.
      
      This patch adds a guard to the report_state() call so that it is
      done only when the logger has been initialized.
     @ mysql-test/suite/backup/t/backup_errors_debug_2.test
        - Re-enable test cases which previously lead to crash.
     @ sql/backup/backup_kernel.h
        - Call report_state() in Backup_restore_ctx::close()
          only when logger is initialized.

Looks fine. Approved.

Pushed to team 6.0-backup tree.
revision-id:rafal.somla@sun.com-20090924144008-vor3rdlbwfmfnhg7

Pushed into 6.0.14-alpha (revid:alik@sun.com-20091025133616-ca4inerav4vpdnaz) (version source revid:ingo.struewing@sun.com-20090928125502-9t9uqhzsp87vmgnx) (merge vers: 6.0.14-alpha) (pib:13)

Noted in 6.0.14 changelog.

If a context object creation failed, BACKUP DATABASE crashed rather
than handling the error.