前言

MySQL的错误日志(error log)用来记录mysqld启动和关闭过程的信息,启停slave以及死锁日志,bug,core dump 等信息。 在调研 MySQL 5.7版本的时候,遇到好几个5.7 error log的有意思的问题或者说知识点,本文做个汇总分享给大家,抛砖引玉。

基础介绍

在*nix系统上, mysqld输出error log信息的规则如下: 不指定--log-error, mysqld会将日志信息输出console上。常见的mysqld --defualts-file=/path/my.cnf,日志输出到控制台。如果指定--log-error,则 

1 如果没有指定任何文件名,则默认使用data_dir目录下的host_name.err。

2 如果给定具体的名称,没有绝对路径,--log-error=alert.log mysqld默认将日志文件写入data_dir文件夹下。

3 如果在my.cnf 中的[mysqld], [server], or [mysqld_safe] 配置了 --log-error ,则mysqld_safe 会找到指定的参数并传递给 mysqld

如果使用mysqld_safe来启动mysqld时,mysqld_safe会将mysqld的日志信息写到错误文件或者syslog中。mysqld_safe有三个相关选项:

--syslog 使用系统的syslog来记录日志,当然也会同时记录到指定的--log-error目录。在*nix系统中该参数默认是关闭的。windows系统默认是打开的。

聊聊 5.7 error log 那些事儿_java

聊聊 5.7 error log 那些事儿_java_02

--skip-syslog 没有任何日志选项时的默认配置,将日志写入到log-eror指定的日志文件中。

--log-error 将错误日志写到文件里(规则同上)。写到[mysqld], [server]和[mysqld_safe]组中的log-error选项,mysqld_safe都会使用

1 err log文件不存在导致启动失败

MySQL 5.7.20版本当初始化mysql实例时,如果my.cnf 里面配置log-error,但是log文件不存在时,启动实例会失败并且报错如下:

聊聊 5.7 error log 那些事儿_java_03

/bin/sh /opt/mysql/bin/mysqld_safe --defaults-file=/srv/my3308/my.cnf
mysqld_safe Adding /usr/lib64/libjemalloc.so.1' to LD_PRELOAD for mysqld
2018-03-14T14:06:53.386187Z mysqld_safe error: log-error set to '/srv/my3308/log/alert.log', however file don't exists. Create writable for user 'mysql'.

检查mysqld_safe源码,其实可以看到没有文件时,$logdir 并未被赋值,导致case 走了*

聊聊 5.7 error log 那些事儿_java_04

具体的bug信息参见 mysqld_safe fails to start when using a fifo for log-error [1]

目前我们的解决方法是在初始化5.7实例的时候提前创建log-error文件。还没测试其他版本,有兴趣的同学可以自己测试。

2 日志输出层级

MySQL 5.7.2引入logerrorverbosity来控制错误日志的输出等级,该参数是全局动态变量,默认值为3,有如下等级:

聊聊 5.7 error log 那些事儿_java_05

1:只记录error信息;

2:记录error和warnings信息;

3:记录error、warnings和普通的notes信息。

另外需要注意的是log_error_verbosity要替换掉旧参数log_warnings,>

log_error_verbosity was added in MySQL 5.7.2. It is preferred over, and should be used instead of, the older log_warnings system variable. See the description of log_warnings for information about how that variable relates to log_error_verbosity. In particular, assigning a value to log_warnings assigns a value to log_error_verbosity and vice versa.

大家在上MySQL 5.7的时候注意在配置文件中不要在配置log_warnings, 推荐设置log_error_verbosity为2.

关于log_warnings[2]的信息比较多,具体可以参考官方文档。

3 日志记录时间

在MySQL 5.7.2之后增加参数log_timestamps来控制error log,general log,slow log文件日志的显示时间,如果是log_output=TABLE,不受该参数影响。 比较麻烦的是在MySQL 5.7.2之后该参数默认值UTC,这样会导致日志中记录的时间与北京时间相差8个小时,导致查看日志不方便。

log_timestamps='UTC',日志记录的时间显示比国内晚8个小时。

2018-03-14T14:44:54.288783Z 51239 [Note] Aborted connection 51239 to db: 'unconnected' user: 'unauthenticated' host: '127.0.0.1' (Got timeout reading communication packets)

log_timestamps='SYSTEM' 日志记录的时间显示为本地时间。

2018-03-14T22:46:40.862704+08:00 51276 [Note] Aborted connection 51276 to db: 'unconnected' user: 'unauthenticated' host: '127.0.0.1' (Got timeout reading communication packets)

因此解决方法是在my.cnf 中配置 log_timestamps='SYSTEM'。

小结

还有一个就是死锁日志其实也是每行都带有时间戳的,这个看起来比较不习惯。

聊聊 5.7 error log 那些事儿_java_06

目前遇到的问题大概有以上几种情况,抛砖引玉,期待各位读者朋友分享更多的案例和注意事项。