新特性解读 | MySQL 8.0 错误日志增强特性

MySQL 8.0 重新定义了错误日志输出和过滤，改善了原来臃肿并且可读性很差的错误日志。

比如增加了 JSON 输出，在原来的日志后面以序号以及 JSON 后缀的方式展示

比如我机器上的 MySQL 以 JSON 保存的错误日志 mysqld.log.00.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"
}

以 JSON 输出错误日志后可读性和可操作性增强了许多。这里可以用 Linux 命令 jq 或者把这个字串 COPY 到其他解析 JSON 的工具方便处理。

只想非常快速的拿出错误信息，忽略其他信息。

[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."

使用 JSON 输出的前提是安装 JSON 输出部件。

INSTALL COMPONENT 'file://component_log_sink_json';

完了在设置变量 SET GLOBAL log_error_services = 'log_filter_internal; log_sink_json';

格式为：过滤规则；日志输出；[过滤规则]日志输出；

查看安装好的部件

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)

现在设置 JSON 输出，输出到系统日志的同时输出到 JSON 格式日志。

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

来测试一把。我之前已经把表 a 物理文件删掉了。

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

现在错误日志里有 5 条记录。

[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.

JSON 日志里也有 5 条记录。

[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" }

那可能有人就问了，这有啥意义呢？只是把格式变了，过滤的规则我看还是没变。

那我们现在给第二条日志输出加过滤规则

先把过滤日志的部件安装起来

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)

只保留 error，其余的一律过滤掉。

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

检索一张误删的表

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

查看错误日志和 JSON 错误日志

发现错误日志里有一条 Warning，JSON 错误日志里的被过滤掉了。

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.

再举个例子，每 60 秒只允许记录一个 Warning 事件

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

多次执行

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`.

现在错误日志里有三条 warning 信息

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 只有一条

{ "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" }

总结，我这里简单介绍了下 MySQL 8.0 的错误日志过滤以及 JSON 输出。MySQL 8.0 的 component_log_filter_dragnet 部件过滤规则非常灵活，可以参考手册，根据它提供的语法写出自己的过滤掉的日志输出。