Bug #49358 Some backup log messages are not properly formatted
Submitted: 2 Dec 2009 16:29 Modified: 24 Feb 2010 23:34
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Backup Severity:S3 (Non-critical)
Version:6.0-backup OS:Any
Assigned to: Chuck Bell CPU Architecture:Any

[2 Dec 2009 16:29] Philip Stoev
Description:
Hello,

Restore seems to print the following log message, maybe due to WL #5174 MySQL Backup disabled events option.

EVENT testdb_S.e1_4_S IS DISABLED.

which is not formatted in the style of the rest of the messages in the error log.

The message has no timestamp, no warn/error prefix, and is all uppercase, rather than sentence case. Also, it is not clear why an event was disabled, and that it happened in relation to backup.

Also, the message is frequently truncated like this:

...
EVENT testdb_S.e1_4_S IS DISABLED.
EVENT testdb_S.e1091202 19:27:06 [Note] Restore: Restore completed

which seems to indicate that some sort of a direct printf with a buffer was used rather than the normal mysqld logging functions.

How to repeat:
code inspection
[3 Dec 2009 7:31] Rafal Somla
This is reported from sql/backup/kernel.cc:1539. Indeed, function backup::Logger::report_event_disabled() uses regular printf() to write the message. I suggest to use the usual backup reporting method, that is, call backup::Logger::report_error(log_level::WARNING,...). This will correctly log the message to all appropriate destinations.
[9 Dec 2009 19:14] Chuck Bell
While there is no (easy) way to test it, the problem has been fixed using the suggestion above. It now prints:

091209 22:06:37 [Warning] Restore: The event 'bup_events.e1' was disabled during restore.
091209 22:06:37 [Warning] Restore: The event 'bup_events.e4' was disabled during restore.

:D
[9 Dec 2009 19:46] 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/93390

2904 Chuck Bell	2009-12-09
      BUG#49358 : Some backup log messages are not properly formatted
      
      The code includes an extra printf() call that was originally
      used during debugging of the original patch. 
      
      This patch removes the offensive call and refactors the warning
      generation code as suggested in the bug report. Note: This
      change is not needed to solve the bug -- removing the printf()
      solves the bug.
     @ sql/backup/logger.cc
        Refactored message generation as suggested. But not needed 
        b/c write_message() was called correctly. This change eliminates
        the sprintf() which was erroneously targeted as the problem
        but eventually calls the same write_message() method.
     @ sql/si_objects.cc
        Removed offensive printf() call. It is not needed.
[10 Dec 2009 13:15] Rafal Somla
Approved.
[10 Dec 2009 14:19] 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/93519
[14 Dec 2009 14: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/93925

2908 Chuck Bell	2009-12-14 [merge]
      BUG#49358 : Some backup log messages are not properly formatted
      
      The code includes an extra printf() call that was originally
      used during debugging of the original patch. 
      
      This patch removes the offensive call and refactors the warning
      generation code as suggested in the bug report. Note: This
      change is not needed to solve the bug -- removing the printf()
      solves the bug.
     @ sql/backup/logger.cc
        Refactored message generation as suggested. But not needed 
        b/c write_message() was called correctly. This change eliminates
        the sprintf() which was erroneously targeted as the problem
        but eventually calls the same write_message() method.
     @ sql/si_objects.cc
        Removed offensive printf() call. It is not needed.
[15 Dec 2009 20: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/94272

2912 Chuck Bell	2009-12-15 [merge]
      BUG#49358 : Some backup log messages are not properly formatted
      
      The code includes an extra printf() call that was originally
      used during debugging of the original patch. 
      
      This patch removes the offensive call and refactors the warning
      generation code as suggested in the bug report. Note: This
      change is not needed to solve the bug -- removing the printf()
      solves the bug.
     @ sql/backup/logger.cc
        Refactored message generation as suggested. But not needed 
        b/c write_message() was called correctly. This change eliminates
        the sprintf() which was erroneously targeted as the problem
        but eventually calls the same write_message() method.
     @ sql/si_objects.cc
        Removed offensive printf() call. It is not needed.
[20 Feb 2010 9:18] 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)
[24 Feb 2010 23:34] Paul DuBois
Noted in 6.0.14 changelog.

Some MySQL Backup log messages were improperly formatted.