New Feature Interpretation | MySQL 8.0 Error Log Enhancement

Keywords: Database MySQL JSON CentOS Linux

Author: Yang Taotao

MySQL 8.0 redefines error log output and filtering to improve the bloated and unreadable error log.

For example, JSON output is added and displayed in serial number and JSON suffix after the original log.

For example, MySQL on my machine saves the error log mysqld.log.00.json in JSON:

[root@centos-ytt80 mysql80]# jq . mysqld.log.00.json
{
  "log_type": 1,
  "prio": 1,
  "err_code": 12592,
  "subsystem": "InnoDB",
  "msg": "Operating system error number 2 in a file operation.",
  "time": "2019-09-03T08:16:12.111808Z",
  "thread": 8,
  "err_symbol": "ER_IB_MSG_767",
  "SQL_state": "HY000",
  "label": "Error"
}
{
  "log_type": 1,
  "prio": 1,
  "err_code": 12593,
  "subsystem": "InnoDB",
  "msg": "The error means the system cannot find the path specified.",
  "time": "2019-09-03T08:16:12.111915Z",
  "thread": 8,
  "err_symbol": "ER_IB_MSG_768",
  "SQL_state": "HY000",
  "label": "Error"
}
{
  "log_type": 1,
  "prio": 1,
  "err_code": 12216,
  "subsystem": "InnoDB",
  "msg": "Cannot open datafile for read-only: './ytt2/a.ibd' OS error: 71",
  "time": "2019-09-03T08:16:12.111933Z",
  "thread": 8,
  "err_symbol": "ER_IB_MSG_391",
  "SQL_state": "HY000",
  "label": "Error"
}

The readability and operability of error log output by JSON have been greatly enhanced. Here you can use the Linux command jq or COPY string to other JSON parsing tools to facilitate processing.

Just want to pull out the wrong information very quickly and ignore the other information.

[root@centos-ytt80 mysql80]#  jq   '.msg' mysqld.log.00.json
"Operating system error number 2 in a file operation."
"The error means the system cannot find the path specified."
"Cannot open datafile for read-only: './ytt2/a.ibd' OS error: 71"
"Cannot calculate statistics for table `ytt2`.`a` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue."
"Cannot calculate statistics for table `ytt2`.`a` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue."

The premise of using JSON output is to install JSON output components.

INSTALL COMPONENT 'file://component_log_sink_json';

//Finish setting variable SET GLOBAL log_error_services='log_filter_internal; log_sink_json';

The format is: filter rule; log output; [filter rule] log output;

View installed components

mysql> select * from mysql.component;
+--------------+--------------------+---------------------------------------+
| component_id | component_group_id | component_urn                         |
+--------------+--------------------+---------------------------------------+
|            2 |                  1 | file://component_log_sink_json        |
+--------------+--------------------+---------------------------------------+
3 rows in set (0.00 sec)

Now set up the JSON output, output to the system log at the same time output to the JSON format log.

mysql> SET persist log_error_services = 'log_filter_internal; log_sink_internal; log_sink_json';
Query OK, 0 rows affected (0.00 sec)

To test one. I have deleted the physical file of table a before.

mysql> select * from a;
ERROR 1812 (HY000): Tablespace is missing for table `ytt2`.`a`.

There are now five records in the error log.

[root@centos-ytt80 mysql80]# tailf  mysqld.log

2019-09-03T08:16:12.111808Z 8 [ERROR] [MY-012592] [InnoDB] Operating system error number 2 in a file operation.
2019-09-03T08:16:12.111915Z 8 [ERROR] [MY-012593] [InnoDB] The error means the system cannot find the path specified.
2019-09-03T08:16:12.111933Z 8 [ERROR] [MY-012216] [InnoDB] Cannot open datafile for read-only: './ytt2/a.ibd' OS error: 71
2019-09-03T08:16:12.112227Z 8 [Warning] [MY-012049] [InnoDB] Cannot calculate statistics for table `ytt2`.`a` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.
2019-09-03T08:16:14.902617Z 8 [Warning] [MY-012049] [InnoDB] Cannot calculate statistics for table `ytt2`.`a` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.

There are also five records in the JSON log.

[root@centos-ytt80 mysql80]# tailf mysqld.log.00.json

{ "log_type" : 1, "prio" : 1, "err_code" : 12592, "subsystem" : "InnoDB", "msg" : "Operating system error number 2 in a file operation.", "time" : "2019-09-03T08:16:12.111808Z", "thread" : 8, "err_symbol" : "ER_IB_MSG_767", "SQL_state" : "HY000", "label" : "Error" }
{ "log_type" : 1, "prio" : 1, "err_code" : 12593, "subsystem" : "InnoDB", "msg" : "The error means the system cannot find the path specified.", "time" : "2019-09-03T08:16:12.111915Z", "thread" : 8, "err_symbol" : "ER_IB_MSG_768", "SQL_state" : "HY000", "label" : "Error" }
{ "log_type" : 1, "prio" : 1, "err_code" : 12216, "subsystem" : "InnoDB", "msg" : "Cannot open datafile for read-only: './ytt2/a.ibd' OS error: 71", "time" : "2019-09-03T08:16:12.111933Z", "thread" : 8, "err_symbol" : "ER_IB_MSG_391", "SQL_state" : "HY000", "label" : "Error" }
{ "log_type" : 1, "prio" : 2, "err_code" : 12049, "subsystem" : "InnoDB", "msg" : "Cannot calculate statistics for table `ytt2`.`a` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.", "time" : "2019-09-03T08:16:12.112227Z", "thread" : 8, "err_symbol" : "ER_IB_MSG_224", "SQL_state" : "HY000", "label" : "Warning" }
{ "log_type" : 1, "prio" : 2, "err_code" : 12049, "subsystem" : "InnoDB", "msg" : "Cannot calculate statistics for table `ytt2`.`a` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.", "time" : "2019-09-03T08:16:14.902617Z", "thread" : 8, "err_symbol" : "ER_IB_MSG_224", "SQL_state" : "HY000", "label" : "Warning" }

Then someone might ask, what's the point? Just change the format, the rules of filtering still remain unchanged.

Now let's add filtering rules to the second log output.

Firstly, install the filter log component

INSTALL COMPONENT 'file://component_log_filter_dragnet';

mysql> SET persist log_error_services = 'log_filter_internal; log_sink_internal; log_filter_dragnet;log_sink_json';
Query OK, 0 rows affected (0.00 sec)

Keep only error s and filter out the rest.

SET GLOBAL dragnet.log_error_filter_rules = 'IF prio>=WARNING THEN drop.';

Retrieve a table that was deleted by mistake

mysql> select * from a;
ERROR 1812 (HY000): Tablespace is missing for table `ytt2`.`a`.

View error logs and JSON error logs

A Warning was found in the error log, and the JSON error log was filtered out.

2019-09-03T08:22:32.978728Z 8 [Warning] [MY-012049] [InnoDB] Cannot calculate statistics for table `ytt2`.`a` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.

Another example is that only one Warning event is allowed to be recorded every 60 seconds.

mysql> SET GLOBAL dragnet.log_error_filter_rules = 'IF prio==WARNING THEN throttle 1/60.';
Query OK, 0 rows affected (0.00 sec)

Multiple executions

mysql> select * from b;
ERROR 1812 (HY000): Tablespace is missing for table `ytt2`.`b`.
mysql> select * from b;
ERROR 1812 (HY000): Tablespace is missing for table `ytt2`.`b`.
mysql> select * from b;
ERROR 1812 (HY000): Tablespace is missing for table `ytt2`.`b`.

Now there are three warning messages in the error log

2019-09-03T08:49:06.820635Z 8 [Warning] [MY-012049] [InnoDB] Cannot calculate statistics for table `ytt2`.`b` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.

2019-09-03T08:49:31.455907Z 8 [Warning] [MY-012049] [InnoDB] Cannot calculate statistics for table `ytt2`.`b` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.
2019-09-03T08:50:00.430867Z 8 [Warning] [MY-012049] [InnoDB] Cannot calculate statistics for table `ytt2`.`b` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.


mysqld.log.00.json has only one

{ "log_type" : 1, "prio" : 2, "err_code" : 12049, "subsystem" : "InnoDB", "msg" : "Cannot calculate statistics for table `ytt2`.`b` because the .ibd file is missing. Please refer to http://dev.mysql.com/doc/refman/8.0/en/innodb-troubleshooting.html for how to resolve the issue.", "time" : "2019-09-03T08:49:06.820635Z", "thread" : 8, "err_symbol" : "ER_IB_MSG_224", "SQL_state" : "HY000", "and_n_more" : 3, "label" : "Warning" }

To sum up, I briefly introduce MySQL 8.0 error log filtering and JSON output. MySQL 8.0 component_log_filter_dragnet widget filtering rules are very flexible, you can refer to the manual, according to the grammar it provides to write their own filtered log output.

Posted by Dawg on Thu, 05 Sep 2019 00:24:48 -0700