MySQL的日志文件详细记录了数据库在运行时的各种活动轨迹。
MySQL通常包含以下日志文件:查询日志;错误日志;慢查询日志;二进制日志。
通过这些日志文件,我们对MySQL的运行时错误进行分析,对慢查询sql进行分析...
下面我们就来看下这些日志的详细记录情况。
准备工作:
笔者使用的MySQL版本为mysql-5.7.17,使用的是Windows版本的(笔记本比较差,虚拟机开着都费劲)。参数配置均为默认参。
1.查询日志
查询日志记录了所有对数据库请求的信息。
作为一个菜鸟,上来时候也不知道去哪里查看查询日志,甚至不知道查询日志有没有开启,怎么办呢?
答案就是:万事都可通过show variable like '%xxx%'来查询。
MySQL的所有配置项都被记录在variable中,所以我们可以通过上面的命令来查看具体的配置项。
下面我们来查看下查询日志的配置项
show variables like 'general_log%';
// 以下是笔者所在机器的结果
'general_log', 'OFF'
'general_log_file', 'DELL-PC.log'
可以看到,日志默认是关闭的,如果我们想验证这一项,需要先将general_log设置为ON,如下即可:
set global general_log=on;
然后执行查询(笔者已经提前建好表了)
select count(*) from world.country;
然后我们去验证一下,找到DELL-PC.log文件,日志内容如下所示:
2019-12-21T08:39:54.492850Z 6 Query select count(*) from world.country
LIMIT 0, 1000
总结:可以看到,通过设置general_log=on,可以通过查询日志来定位用户请求。
2.错误日志
顾名思义,这个日志文件是记录数据库在执行过程中的错误信息的。
同样,我们通过命令来获取错误日志文件路径
show variables like 'log_error';
// result:
# Variable_name, Value
'log_error', '.\\DELL-PC.err'
简单来看下这个 DELL-PC.err文件
2019-12-21T08:59:50.945125Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
2019-12-21T08:59:50.960746Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2019-12-21T08:59:50.960746Z 0 [Note] IPv6 is available.
2019-12-21T08:59:50.960746Z 0 [Note] - '::' resolves to '::';
2019-12-21T08:59:50.960746Z 0 [Note] Server socket created on IP: '::'.
2019-12-21T08:59:51.085736Z 0 [Note] Event Scheduler: Loaded 0 events
2019-12-21T08:59:51.101377Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2019-12-21T08:59:51.101377Z 0 [Note] Beginning of list of non-natively partitioned tables
2019-12-21T08:59:51.320099Z 0 [Note] End of list of non-natively partitioned tables
2019-12-21T08:59:51.320099Z 0 [Note] C:\Program Files\MySQL\MySQL Server 5.7\bin\mysqld.exe: ready for connections.
Version: '5.7.17-log' socket: '' port: 3306 MySQL Community Server (GPL)
2019-12-21T09:06:06.318907Z 3 [Note] Access denied for user 'root'@'localhost' (using password: NO)
由于MySQL刚启动,所以可以看到上面主要是一些数据库启动信息,warn级别的都是警告类信息。
如何制造一些错误信息来验证错误日志的记录呢?
我们可以在MySQL配置文件my.ini中设置一些错误的参数,比如将log-warings=1,再重新启动MySQL,可以看到在DELL-PC.err文件中有以下输出
2019-12-21T09:25:12.476132Z 0 [ERROR] unknown variable 'log-warings=1'
2019-12-21T09:25:12.477131Z 0 [ERROR] Aborting
MySQL启动失败。
总结:我们在遇到数据库启动失败的时候,可以第一时间去查看对应的错误日志,错误日志是不可被关闭的。
3.慢日志查询
慢日志,记得曾经被面试到过这个问题,就是如何知道哪些sql执行的慢,你们如何操作的?
当时一脸懵逼,还想通过应用层记录的方式去解决,现在想想还是太嫩了。
数据库已经帮我们做好了这些工作了。
通过设置慢日志的查询阈值,可以将超过这个阈值的sql记录到一个文件中去,以方便我们的查询分析。
老套路,先通过参数查询慢日志相关属性
show variables like 'long_query_time';// 查询慢sql日志阈值,超过该值的即为慢sql
// res:
# Variable_name, Value
'long_query_time', '10.000000'// 10秒
show variables like '%slow_query%';
// res
slow_query_log, ON
slow_query_log_file, DELL-PC-slow.log // 慢日志存储位置
由上述参数可知:sql执行超过10秒的会被记录到DELL-PC-slow.log文件中
下面我们来模拟一个慢sql:
select sleep(11); // 执行该sql
// res(从slow.log中截取的日志)
# Time: 2019-12-21T09:39:22.791197Z
# User@Host: root[root] @ localhost [127.0.0.1] Id: 4
# Query_time: 11.066572 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0
use world;
SET timestamp=1576921162;
select sleep(11)
LIMIT 0, 1000;
可以看到,该sql的详细执行情况被记录到res中。
扩展:
以上查询方式可能会有点麻烦,每次都要去日志文件中去捞取。目前我们还可以通过设置log_output的展示方式来从表中来获取。
show variables like 'log_output';
// res
log_output, FILE // 默认为file格式的,输入到文件中
// 修改为TABLE的方式,将日志输出到表中
set global log_output='TABLE';
// 这样我们再次执行select sleep(11);
// 然后去表中查询
select * from mysql.slow_log;
// res
# start_time, user_host, query_time, lock_time, rows_sent, rows_examined, db, last_insert_id, insert_id, server_id, sql_text, thread_id
'2019-12-21 17:47:06.125625', 'root[root] @ localhost [127.0.0.1]', '00:00:11.000046', '00:00:00.000000', '1', '0', 'world', '0', '0', '1', ?, '4'
// 倒数第二个sql_text为blob类型的,具体内容为select sleep(11) LIMIT 0, 1000
总结:
根据不同日志的适用场景,我们可以更好的了解、使用MySQL。
参考:MySQL技术内幕 InnoDB存储引擎