MySQL Bugs: #33173: Backup: Error log polluted by backup debug info

Bug #33173	Backup: Error log polluted by backup debug info
Submitted:	12 Dec 2007 16:37	Modified:	24 Nov 2008 17:31
Reporter:	Rafal Somla	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Backup	Severity:	S3 (Non-critical)
Version:	6.0 source	OS:	Any
Assigned to:	Jørgen Løland	CPU Architecture:	Any

Description:
Backup code contains "breakpoints" which are used for testing. It seems this code
puts a lot of debug info into the servers error log. This should probably not happen since error log is intended to be read by database users, not developers.

How to repeat:
Execute the backup_snapshot test and look into var/master.err file. It contains things like:

071212 19:33:15 [Note] /ext/mysql/bkroot/mysql-6.0-backup1/sql/mysqld: ready for connections.
Version: '6.0.5-alpha-valgrind-max-debug-log'  socket: '/ext/mysql/bkroot/mysql-6.0-backup1/mysql-test/var/tmp/master.sock'  port: 930
6  Source distribution
check_DDL_blocker(): backup: == breakpoint on 'DDL_not_blocked' ==
check_DDL_blocker(): backup: == breakpoint on 'DDL_in_progress' ==
mysql_insert: backup: == breakpoint on 'backup_cs_reading' ==
mysql_insert: backup: == breakpoint on 'commit_blocker_step_1' ==
ha_commit_trans: backup: == breakpoint on 'commit_blocker_step_1' ==
mysql_insert: backup: == breakpoint on 'backup_cs_reading' ==
mysql_insert: backup: == breakpoint on 'commit_blocker_step_1' ==
ha_commit_trans: backup: == breakpoint on 'commit_blocker_step_1' ==

(more of this)

Suggested fix:
Send the debug info to debug trace instead.

This bug may be overcome by events (OBE) rendered so by Ingo's work on WL#4259. His work should replace all calls to BACKUP_BREAKPOINT and therefore eliminate the need for this code.

It is recommended that this bug be retested against Ingo's patch to verify that the problem has either been solved or needs fixing against the new code possibly removing the BACKUP_BREAKPOINT code altogether.

Note: Ingo is in the process of completing the conversion. Check with him for latest status.

Here is an example of how the BACKUP_BREAKPOINT calls are being replaced:

@@ -143,7 +143,7 @@ my_bool DDL_blocker_class::block_DDL(THD
 {
   DBUG_ENTER("block_DDL()");
 
-  BACKUP_BREAKPOINT("DDL_in_progress");
+  DEBUG_SYNC(thd, "before_block_ddl");
 
   /*
     Only 1 DDL blocking operation can run at a time.
@@ -171,7 +171,7 @@ my_bool DDL_blocker_class::block_DDL(THD
     pthread_cond_wait(&COND_process_blocked, &THR_LOCK_DDL_blocker);
   thd->exit_cond("DDL blocker: DDL is now blocked");
 
-  BACKUP_BREAKPOINT("DDL_blocked");
+  DEBUG_SYNC(thd, "after_block_ddl");
   DBUG_RETURN(TRUE);
 }

This bug may be overcome by events (OBE) rendered so by Ingo's work on WL#4259. His work should replace all calls to BACKUP_BREAKPOINT and therefore eliminate the need for this code.

It is recommended that this bug be retested against Ingo's patch to verify that the problem has either been solved or needs fixing against the new code possibly removing the BACKUP_BREAKPOINT code altogether.

Note: Ingo is in the process of completing the conversion. Check with him for latest status.

The backup_ddl_blocker.test file sets debug options as follows:

SET GLOBAL debug="d,backup_debug:d,backup";

This causes backup and backup_debug to be written to master.err - this seems the right thing to do. If I add a codeline

DBUG_PRINT("mytag", "sometext")

and adds d,mytag to the debug option, sometext is written to master.err as well. Still not sure why DBUG_ENTER and DBUG_LEAVE for the keyword "backup" does not append to the debug trace, however.

The backup DBUG_ENTER and DBUG_LEAVE calls are ignored because they are called at a deeper depth than maxdepth. Changing the max depth writes these commands, but they end up in master.err as well. So, it seems that the cs->stack->out_file decides where this is output as well:

dbug.c#_do_enter_
(void) fprintf(cs->stack->out_file, ">%s\n", cs->func);

Stopping work on this bug until Ingo's work is done.

Fixed by WL#4259 in version 6.0.7. I don't think there's any need for documentation on this issue, but sending to doc team just in case.

No changelog entry needed.