Improved Logging Messages
By Rahul Sisondia -Oracle on Mar 04, 2017
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.
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)
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.
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 .