MySQL Bugs: #43166: SQL statements executed by BACKUP/RESTORE are logged in server query log.

Bug #43166	SQL statements executed by BACKUP/RESTORE are logged in server query log.
Submitted:	25 Feb 2009 5:54	Modified:	28 Jun 2009 0:13
Reporter:	Rafal Somla	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Backup	Severity:	S3 (Non-critical)
Version:	6.0-beta	OS:	Any
Assigned to:	Chuck Bell	CPU Architecture:	Any

Description:
Internally, BACKUP and RESTORE  statements execute SQL queries to obtain object metadata or to create objects. These internal queries are logged in the server log as in this example:

 2 Query     RESTORE FROM 'db1.bak' OVERWRITE
 2 Execute   DROP DATABASE IF EXISTS `db1`
 2 Execute   CREATE DATABASE `db1` /*!40100 DEFAULT CHARACTER SET latin1 */
 2 Execute   DROP TABLE IF EXISTS `db1`.`t1`
 2 Execute   USE `db1`
 2 Execute   CREATE TABLE `t1` (
  `a` int(11) DEFAULT NULL
) ENGINE=MyISAM DEFAULT CHARSET=latin1
 2 Execute   DROP PROCEDURE IF EXISTS `db1`.`p1`
 ...

Note that after the log entry for RESTORE, the statements which are executed inside RESTORE are logged. This is in contrast with, e.g., situation when a stored procedure is called. Then only CALL proc() is logged, but not the statements executed within the procedure.

How to repeat:
Execute something like this:

CREATE DATABASE db1;
CREATE TABLE db1.t1(a int);
BACKUP DATABASE db1 TO 'db1.bak';
RESTORE FROM 'db1.bak' OVERWRITE;

And see server's query log.

Suggested fix:
It should be easy to disable logging of the statements executed by si_objects implementation. This should be done in si_objects - backup code would not need any changes.

Solution found. May be used to fix BUG#43395. If so, I will add a note.

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

2803 Chuck Bell	2009-03-19
      BUG#43166 SQL statements executed by BACKUP/RESTORE are logged in server query log
      
      This patch turns off the general log during backup and restore
      to avoid writing the intermedia queries to the log.
      modified:
        sql/backup/backup_kernel.h
        sql/backup/kernel.cc
        sql/si_objects.cc
        sql/si_objects.h

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

2803 Chuck Bell	2009-03-19
      BUG#43166 SQL statements executed by BACKUP/RESTORE are logged in server query log
      
      This patch turns off the general log during backup and restore
      to avoid writing the intermedia queries to the log.
      added:
        mysql-test/suite/backup/r/backup_general_log.result
        mysql-test/suite/backup/t/backup_general_log.test
      modified:
        sql/backup/backup_kernel.h
        sql/backup/kernel.cc
        sql/si_objects.cc
        sql/si_objects.h

I want to point at alternative solution:

Instead of adding new "disable general query log" service to si_objects, modify its implementation so that any SQL statements executed from there will not be logged. 

This can be done in Si_session_context::reset_si_ctx() which prepares execution context for SQL code executed from within si_objects (via run_service_interface_sql() function). The logging could be disabled there and re-enabled, if needed, in Si_session_context::restore_si_ctx.

With this solution, the backup code would remain unchanged. Also, it makes sense for other potential clients of si_objects - arguably, they don't want the queries executed from there to be logged in the server log. Actually, they (the clients of si_object) should not care whether si_objects services are implemented with SQL queries or by other means.

The new methods were added to si_objects because at least one other place in the code needs to be able to turn off the general log. See BUG#43395. These new methods enable any portion of code to disable writing to the general log. Thus, the design in the patch is the best choice going forward.

The current design means that si_objects methods will log SQL statements to the general query log unless user of these services disables the log explicitly. The fact that general query log should be also disabled during trigger/event firing does not justify such a design. I think more logical would be to implement si_objects methods so that they don't leave any trace in server logs.

Note that disabling the query log is a matter of a single statement:

 thd->options|= OPTION_LOG_OFF;

Thus I don't think it is a problem if this is done inside si_object methods instead of being done just once. Already, Si_session_context::reset_si_ctx() is doing a couple of such assignments and seems to be a perfect place for doing them. Also, having a separate service for setting/clearing this single flag could be considered an overkill.

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

2700 Chuck Bell	2009-04-29
      BUG#43166 SQL statements executed by BACKUP/RESTORE are logged in server query log
      
      This patch turns off the general log during backup and restore
      to avoid writing the intermedia queries to the log.
      added:
        mysql-test/suite/backup/r/backup_general_log.result
        mysql-test/suite/backup/t/backup_general_log.test
      modified:
        sql/si_objects.cc
        sql/si_objects.h

Good to push

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

2800 Chuck Bell	2009-05-05
      BUG#43166 SQL statements executed by BACKUP/RESTORE are logged in server query log
      
      This patch turns off the general log during backup and restore
      to avoid writing the intermediate queries to the log.
      added:
        mysql-test/suite/backup/r/backup_general_log.result
        mysql-test/suite/backup/t/backup_general_log.test
      modified:
        sql/si_objects.cc
        sql/si_objects.h

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

2802 Chuck Bell	2009-05-05
      BUG#43166 SQL statements executed by BACKUP/RESTORE are logged in server query log
      
      This patch turns off the general log during backup and restore
      to avoid writing the intermediate queries to the log.
      added:
        mysql-test/suite/backup/r/backup_general_log.result
        mysql-test/suite/backup/t/backup_general_log.test
      modified:
        sql/si_objects.cc
        sql/si_objects.h

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

2805 Chuck Bell	2009-05-06
      Patch contains fixes for test failures for:
      * (BUG#43166) backup_general_log
      * (WL#4612) rpl_backup
      modified:
        mysql-test/suite/backup/r/backup_general_log.result
        mysql-test/suite/backup/t/backup_general_log.test
        mysql-test/suite/rpl/t/rpl_backup_block.test

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

2806 Chuck Bell	2009-05-06
      Patch contains additional fixes for test failures for:
      * (BUG#43166) backup_general_log
      * (WL#4612) rpl_backup
      modified:
        mysql-test/suite/backup/r/backup_general_log.result
        mysql-test/suite/backup/t/backup_general_log.test
        mysql-test/suite/rpl/r/rpl_backup_block.result
        mysql-test/suite/rpl/t/rpl_backup_block.test

Pushed to 6.0.11-alpha.

Merged to azalea June 2

Noted in 6.0.11 changelog.

SQL statements executed by BACKUP DATABASE and RESTORE were logged in
the general query log.