Sunday, March 5, 2017

Improved Logging Messages

Introduction

Logging is a very important
diagnostic tool for understanding the behavior of the application as well as
troubleshooting any issue with the application. Since MySQL Enterprise Backup
(MEB) is a command line application, there is little interaction with the
myriad of operations going on behind the scenes. Thus, logging messages are very
important for knowing the progress of current operation as well as learning
more about errors should they occur. The messages logged by MEB are written to
the console and the log file as depicted in the following diagram, which looks
similar to the Tee command in UNIX.


By default, MEB creates the log file in the default ‘<backup_dir>/meta’
directory with a name like MEB_<Date.time>_<operation_name>.log. For example – MEB created a log
file with the name, ‘MEB_2017-02-24.07-47-09_backup.log’, for the backup
operation executed to save the log messages. User may specify any other existing directory
to create the log file using the --messages-logdir= <directory_ path>
option. Users may also skip the log file creation using the --skip-messages-logdir
option, but it is not recommended.

Background

Prior to 4.1 release, the log messages are printed as shown
below.


Notice how the messages seem to
interlace, making it harder to read a logical flow from the output. There were
several reasons for this.

  • MEB is a multithreaded application. From the output, there was no way to determine which thread printed the message. This is very crucial information to know when diagnosing problems or performance.
  • The log messages contained trace levels starting with the string, ‘mysqlbackup:’. But this did not convey any useful information. Furthermore, some of these log messages are printed without any timestamp prefixes.

The trace levels of the
log messages, in the order of increasing fineness, are:

  • 0 - INFO (information,
    warnings, errors)
  • 1 - FINE (more information given than at trace level 0)
  • 2 - FINER (finer level
    of information given than at trace level 1)
  • 3 - FINEST (finest
    level of information that can be given)

The improvements

Logging has been greatly improved In the 4.1
release. They are now printed as shown below. 


The improvements are small but
have a profound effect on readability and usability. These improvements include
the following.

  • MEB now prints each thread name that it creates. The thread name is an abbreviation derived from the thread description. They will
    also be helpful in analyzing the work performed by each thread. The following
    table shows several examples

Thread Name  Thread Description
 RDR1  ReaDeR thread #1
 PCR1  ProCessoR thread #1
 WTR1  WriTeR thread #1
 CLD1  CLouD thread #1
 RLR1  Redo Log Reader thread #1
 RLP1  Redo Log Processor thread #1
 RLW1  Redo Log Writer thread #1
 ALW1  Apply Log Worker thread #1

  • Every message that includes a trace level is
    now prefixed with the timestamp. 
  • The logger module has been improved for
    better performance.

Summary

We
hope these small improvements will be useful for troubleshooting purpose. Try
out the latest version and provide us feedback on how we can improve it
further. For more details and usage samples, please refer MySQL Enterprise
Backup 4.1 User’s Guide .

Join the discussion

Comments ( 0 )
Please enter your name.Please provide a valid email address.Please enter a comment.CAPTCHA challenge response provided was incorrect. Please try again.Captcha
 

Visit the Oracle Blog

 

Contact Us

Oracle

Integrated Cloud Applications & Platform Services