MySQL 8.0 : New Error Logging

With MySQL 8.0, the error logging subsystem has been redesigned to use the new component architecture.

Thanks to this new redesign, now the log events can be filtered, the output can be sent to multiple destinations (different formats like JSON). All that is controlled by system variables.

This work gives the possibility for a log event to become the raw material for log processing by more modern and automated systems like filebeat for beats, kibana, etc…

Let’s check the default configuration:

mysql> select * from global_variables where VARIABLE_NAME like 'log_error_%';
+---------------------+----------------------------------------+
| VARIABLE_NAME       | VARIABLE_VALUE                         |
+---------------------+----------------------------------------+
| log_error_services  | log_filter_internal; log_sink_internal |
| log_error_verbosity | 2                                      |
+---------------------+----------------------------------------+

This means that log events will follow the following flow: first pass through log_filter_internal (built-in filter component), then through log_sink_internal (buit-in log writer component).

To enable a log component you need to use INSTALL COMPONENT command and set the log_error_services global variable as wished. To disable it use  UNINSTALL COMPONENT.

Currently the available log components are in lib/plugins:

• component_log_filter_dragnet.so
• component_log_sink_json.so
• component_log_sink_syseventlog.so
• component_log_sink_test.so

LOG OUTPUT

To specify a new output format, you need to use a log writer component (sink). So let’s try to use one.

To load a component , you need its URN. This is ‘file://‘ + the filename without the .so extension. Example, to load the writer to json component, you enable it like this:

mysql> INSTALL COMPONENT 'file://component_log_sink_json';
Query OK, 0 rows affected (0.14 sec)
mysql> SET GLOBAL log_error_services = 'log_filter_internal; log_sink_internal; log_sink_json';
Query OK, 0 rows affected (0.01 sec)
mysql> select * from global_variables where VARIABLE_NAME like 'log_error_%';
+---------------------+-------------------------------------------------------+
| VARIABLE_NAME       | VARIABLE_VALUE                                        |
+---------------------+-------------------------------------------------------+
| log_error_services  | log_filter_internal; log_sink_internal; log_sink_json |
| log_error_verbosity | 2                                                     |
+---------------------+-------------------------------------------------------+
2 rows in set (0.00 sec)

Now if I generate an entry, I will have the error in the standard error log file and also in a new json file (having the name of the error log, specified in log_error variable) with a number and the .json extension. More info here in the manual.

Let’s have a look at the new entry generated by loading the group_replication plugin in this sandbox instance.

in the traditional error log:

2018-03-13T09:13:45.846708Z 24 [ERROR] [MY-011596] [Repl] Plugin group_replication reported: 'binlog_checksum should be NONE for Group Replication'
2018-03-13T09:13:45.853491Z 24 [ERROR] [MY-011660] [Repl] Plugin group_replication reported: 'Unable to start Group Replication on boot'

and in the json error log:

{
  "prio": 1,
  "err_code": 11596,
  "subsystem": "Repl",
  "component": "plugin:group_replication",
  "SQL_state": "HY000",
  "source_file": "plugin.cc",
  "function": "check_if_server_properly_configured",
  "msg": "Plugin group_replication reported: 'binlog_checksum should be NONE for Group Replication'",
  "time": "2018-03-13T09:13:45.846708Z",
  "thread": 24,
  "err_symbol": "ER_GRP_RPL_BINLOG_CHECKSUM_SET",
  "label": "Error"
}
{
  "prio": 1,
  "err_code": 11660,
  "subsystem": "Repl",
  "component": "plugin:group_replication",
  "SQL_state": "HY000",
  "source_file": "plugin.cc",
  "function": "plugin_group_replication_init",
  "msg": "Plugin group_replication reported: 'Unable to start Group Replication on boot'",
  "time": "2018-03-13T09:13:45.853491Z",
  "thread": 24,
  "err_symbol": "ER_GRP_RPL_FAILED_TO_START_ON_BOOT",
  "label": "Error"
}

FILTERS

The new error log service gives you the possibility to use components to filter the events.

The default built-in, log_filter_internal, filters the events only based on their priority, you can specify it using the global variable log_error_verbosity (default is 2).

But there is another component available that allows you to filter on rules that you define: log_filter_dragnet

Let’s try to setup this last one:

mysql> INSTALL COMPONENT 'file://component_log_filter_dragnet'
mysql> SET GLOBAL log_error_services = 'log_filter_dragnet; log_sink_internal; log_sink_json';

mysql> SELECT * from global_variables where VARIABLE_NAME like 'log_error_ser%';
+--------------------+------------------------------------------------------+
| VARIABLE_NAME      | VARIABLE_VALUE                                       |
+--------------------+------------------------------------------------------+
| log_error_services | log_filter_dragnet; log_sink_internal; log_sink_json |
+--------------------+------------------------------------------------------+

and we can already check the available dragnet rule:

mysql> select * from global_variables where VARIABLE_NAME like 'dragnet%'\G
*************************** 1. row ***************************
 VARIABLE_NAME: dragnet.log_error_filter_rules
VARIABLE_VALUE: IF prio>=INFORMATION THEN drop. IF EXISTS source_line THEN unset source_line.
1 row in set (0.30 sec)

You can find much more information about the dragnet rule language in the manual.

CONCLUSION

As you can see the new Error Logging Service is much more powerful than prior of MySQL 8.0. It’s again another example of a new feature in 8.0.

And for those that want even more or something very specific, don’t forget that now you have also the possibility to modify directly the error logging as you have the possibility to create your own components.