本文介绍MySQL慢查询日志的配置与分析，包括慢查询日志的开启方法、参数详解及日志内容解析，有助于数据库性能优化。
相关文章：
慢查询日志是 MySQL 提供的一种日志记录，用于记录查询时间超过 long_query_time 的 SQL，并且还要对 min_examined_row_limit 进行校验 (若扫描行数小于该参数，则不会记录到慢查询日志中)
慢查询日志可用于查找执行时间较长的查询，用于 SQL 优化，默认不开启，需要我们通过 slow_query_log 来手动设置
此外慢查询日志不仅支持将日志记录写入文件中，也支持将日志记录写入数据库中
官方文档：The Slow Query Log
官方文档：mysqldumpslow
一、慢查询日志参数
-
注意：以下配置的所有改动仅对当前有效，想要永久有效，需要修改 MySQL 的配置文件
my.cnf，并重启 MySQL -
slow_query_log
-
是否开启慢查询日志：1=开启，0=关闭
-
默认情况下，慢查询日志是禁用的，我们可以通过设置
slow_query_log来开启，如下所示mysql> show variables like 'slow_query_log'; +----------------+-------+ | Variable_name | Value | +----------------+-------+ | slow_query_log | OFF | +----------------+-------+ 1 row in set (0.00 sec) mysql> set global slow_query_log = 1; Query OK, 0 rows affected (0.12 sec) mysql> show variables like 'slow_query_log'; +----------------+-------+ | Variable_name | Value | +----------------+-------+ | slow_query_log | ON | +----------------+-------+ 1 row in set (0.00 sec)
-
-
slow_query_log_file
-
慢查询日志存储路径
-
slow_query_log_file用于指定慢查询日志的存储路径，如果未指定，系统会默认给一个缺省的文件host_name-slow.log(此处为MyAliyunServer-slow.log，MyAliyunServer为我的服务器名称)mysql> show variables like 'slow_query_log_file'; +---------------------+------------------------------------------------------------+ | Variable_name | Value | +---------------------+------------------------------------------------------------+ | slow_query_log_file | /usr/local/mysql/mysql-5.7.25/data/MyAliyunServer-slow.log | +---------------------+------------------------------------------------------------+ 1 row in set (0.00 sec)
-
-
long_query_time
-
慢查询阈值，当 SQL 查询时间大于该值时，则将其记录到慢查询日志中
-
long_query_time默认为 10s，当运行时间正好等于long_query_time时，此时 SQL 并不会被记录下来，也就是说，只有大于long_query_time时，SQL 才会被记录下来 -
从 MySQL 5.1 开始，
long_query_time开始以微秒来记录 SQL 语句的运行时间，之前仅用秒为单位记录 (如果记录到数据库中，只会记录整数部分，而不会记录微秒部分) -
对于真正程序运行来讲，10s 已经是非常非常慢的了，通常情况下，如果 SQL 的执行时间超过 1s，我们就认为这条 SQL 是比较慢的了，此处我们将
long_query_time的值改为 1smysql> show variables like '%long_query_time%'; +-----------------+-----------+ | Variable_name | Value | +-----------------+-----------+ | long_query_time | 10.000000 | +-----------------+-----------+ 1 row in set (0.01 sec) mysql> set global long_query_time = 1; Query OK, 0 rows affected (0.00 sec) mysql> show variables like '%long_query_time%'; +-----------------+-----------+ | Variable_name | Value | +-----------------+-----------+ | long_query_time | 10.000000 | +-----------------+-----------+ 1 row in set (0.00 sec) -
如上所示，我们修改了
long_query_time，但是再次查询时，long_query_time仍然为 10s，难道是没有修改成功吗？-
这是因为，在使用命令
set global long_query_time = 1进行修改后，需要重新连接或新开一个会话才能看到修改后的值，而我们直接用show variables like '%long_query_time%';查看的仍然是当前会话的变量值 -
另外我们也可以不用重新连接或新开一个会话，而是使用
show global variables like '%long_query_time%';命令来查看，如下所示mysql> show global variables like '%long_query_time%'; +-----------------+----------+ | Variable_name | Value | +-----------------+----------+ | long_query_time | 1.000000 | +-----------------+----------+ 1 row in set (0.00 sec)
-
-
此时，我们在 MySQL 中执行下面 SQL 语句，然后我们再去查看对应的慢查询日志 (
MyAliyunServer-slow.log)，就会发现这条 SQL 已经被记录在内了mysql> select sleep(3); +----------+ | sleep(3) | +----------+ | 0 | +----------+ 1 row in set (3.00 sec)[root@MyAliyunServer data]# cat MyAliyunServer-slow.log /usr/local/mysql/mysql-5.7.25/bin/mysqld, Version: 5.7.25-log (Source distribution). started with: Tcp port: 0 Unix socket: /var/lib/mysql/mysql.sock Time Id Command Argument # Time: 2020-07-12T12:32:07.842181Z # User@Host: root[root] @ localhost [] Id: 2 # Query_time: 3.000327 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 SET timestamp=1594557127; select sleep(3);
-
-
log_output
-
日志存储方式，共有三种，如下所示
-
log_output=‘FILE’
- 表示将日志存入文件，默认值是 ‘FILE’
-
log_output=‘TABLE’
- 表示将日志存入数据库，会将日志写入 mysql.slow_log 表中
-
log_output=‘FILE,TABLE’
-
表示将日志同时存入文件和数据库中
-
日志记录到系统的专用日志表中，要比记录到文件中耗费更多的系统资源，因此对于需要启用慢查询日志，又需要能够获得更高的系统性能，那么建议优先记录到文件中
-
-
-
此处，我们尝试下将日志记录到数据库中，先将
log_output的值改为TABLEmysql> show variables like 'log_output'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | log_output | FILE | +---------------+-------+ 1 row in set (0.01 sec) mysql> set global log_output = 'TABLE'; Query OK, 0 rows affected (0.00 sec) mysql> show variables like 'log_output'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | log_output | TABLE | +---------------+-------+ 1 row in set (0.00 sec) -
然后我们在 MySQL 中执行下面 sql 语句，然后我们再去查看对应的慢查询日志 (
mysql.slow_log)，就会发现这条 sql 已经被记录在内了mysql> select sleep(3); +----------+ | sleep(3) | +----------+ | 0 | +----------+ 1 row in set (3.00 sec) mysql> select * from mysql.slow_log; +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+----+----------------+-----------+-----------+-----------------+-----------+ | start_time | user_host | query_time | lock_time | rows_sent | rows_examined | db | last_insert_id | insert_id | server_id | sql_text | thread_id | +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+----+----------------+-----------+-----------+-----------------+-----------+ | 2020-07-12 20:43:41.552020 | root[root] @ localhost [] | 00:00:03.000202 | 00:00:00.000000 | 1 | 0 | | 0 | 0 | 0 | select sleep(3) | 2 | +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+----+----------------+-----------+-----------+-----------------+-----------+ 1 row in set (0.00 sec)
-
-
log_queries_not_using_indexes
-
是否开启将未使用索引的查询记录到慢查询日志中：1=开启，0=关闭
-
如果对 SQL 进行调优的话，建议开启此参数；此外如果开启了此参数，全表扫描 (full index scan) 的 SQL 也会被记录到慢查询日志中
-
此处，我们来验证下全表扫描的 SQL 是否会被记录到慢查询日志中，先开启
log_queries_not_using_indexesmysql> set global log_output='FILE'; Query OK, 0 rows affected (0.00 sec) mysql> show variables like 'log_queries_not_using_indexes'; +-------------------------------+-------+ | Variable_name | Value | +-------------------------------+-------+ | log_queries_not_using_indexes | OFF | +-------------------------------+-------+ 1 row in set (0.00 sec) mysql> set global log_queries_not_using_indexes = 1; Query OK, 0 rows affected (0.00 sec) mysql> show variables like 'log_queries_not_using_indexes'; +-------------------------------+-------+ | Variable_name | Value | +-------------------------------+-------+ | log_queries_not_using_indexes | ON | +-------------------------------+-------+ 1 row in set (0.01 sec) -
此时，我们在 MySQL 中执行下面 SQL 语句，然后我们再去查看对应的慢查询日志 (
MyAliyunServer-slow.log)，就会发现这条 SQL 已经被记录在内mysql> select * from mysql.user;# Time: 2020-07-12T13:14:07.245976Z # User@Host: root[root] @ localhost [] Id: 3 # Query_time: 0.000455 Lock_time: 0.000290 Rows_sent: 4 Rows_examined: 4 SET timestamp=1594559647; select * from mysql.user;
-
-
log_throttle_queries_not_using_indexes
-
当开启
log_queries_not_using_indexes记录不使用索引的查询到慢查询日志中时，慢查询日志可能会迅速增长，因此我们可以通过设置log_throttle_queries_not_using_indexes来限制此类查询每分钟记录到慢查询日志中的数量 -
默认为 0，表示没有限制；正值表示限制不使用索引的查询每分钟记录到慢查询日志中的数量
mysql> show variables like 'log_throttle_queries_not_using_indexes'; +----------------------------------------+-------+ | Variable_name | Value | +----------------------------------------+-------+ | log_throttle_queries_not_using_indexes | 0 | +----------------------------------------+-------+ 1 row in set (0.00 sec) mysql> set global log_throttle_queries_not_using_indexes = 1; Query OK, 0 rows affected (0.00 sec) mysql> show variables like 'log_throttle_queries_not_using_indexes'; +----------------------------------------+-------+ | Variable_name | Value | +----------------------------------------+-------+ | log_throttle_queries_not_using_indexes | 1 | +----------------------------------------+-------+ 1 row in set (0.00 sec)
-
-
slow_queries
-
用于查询有多少条慢查询语句
-
注意：查询得到的记录仅对当前有效，当 MySQL 重启后，慢查询语句条数会被清零
mysql> show global status like 'slow_queries'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | Slow_queries | 1 | +---------------+-------+ 1 row in set (0.00 sec)
-
二、慢查询日志内容
[root@MyAliyunServer data]# cat MyAliyunServer-slow.log
/usr/local/mysql/mysql-5.7.25/bin/mysqld, Version: 5.7.25-log (Source distribution). started with:
Tcp port: 0 Unix socket: /var/lib/mysql/mysql.sock
Time Id Command Argument
# Time: 2020-07-12T12:32:07.842181Z
# User@Host: root[root] @ localhost [] Id: 2
# Query_time: 3.000327 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0
SET timestamp=1594557127;
select sleep(3);
| 参数名 | 作用 |
|---|---|
| Query_time | SQL 执行时间，单位秒 |
| Lock_time | 获取锁的时间，单位秒 |
| Rows_sent | 发送给客户端的行数 |
| Rows_examined | 服务器检索的行数 (不计算存储引擎内部的任何处理) |
三、mysqldumpslow 日志分析工具
-
mysqldumpslow 用于解析 MySQL 慢查询日志文件并总结其内容
-
命令格式
- mysqldumpslow [options] [log_file …]
-
格式说明
参数名 含义 options 命令参数 log_file 慢查询日志文件 -
命令参数
参数名 含义 -a 不要把所有的数字都抽象为 N，把字符串都抽象为 S -n [N] 至少具有数量为 N 的抽象数字 –debug / -d 在 debug 模式下运行 -g [pattern] 仅考虑与 grep 命令匹配 (正则表达式) 的查询 –help 查看命令帮助信息 -h [host_name] 以 MySQL 服务器的主机名来作为 *-slow.log 的文件名 -i [name] MySQL 服务器实例的名称 (如果使用的是 mysql.server 启动脚本) -l 不要从总时间中减去锁定时间 -r 颠倒排序顺序 -s [sort_type] 如何对输出进行排序
t, at：按查询的时间或平均查询时间来进行排序
l, al：按锁定时间或平均锁定时间来进行排序
r, ar：按发送的行或发送的平均行来进行排序
c：按计数来进行排序
默认情况下，mysqldumpslow 按平均查询时间来进行排序 (即 -s at)-t [N] 查看慢查询日志中的前 N 条记录 –verbose 详细模式，查看有关程序功能的更多信息 -
示例
-
查看按平均时间进行排序的第一条 SQL
[root@MyAliyunServer ~]# mysqldumpslow -s at -t 1 /usr/local/mysql/mysql-5.7.25/data/MyAliyunServer-slow.log Reading mysql slow query log from /usr/local/mysql/mysql-5.7.25/data/MyAliyunServer-slow.log Count: 3 Time=1214.73s (3644s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@2hosts CALL add_student_record(N)
-
-
输出说明
参数名 作用 Count 出现次数 Time 最长执行时间 Lock 获取锁的时间 Rows 发送给客户端的行数
扫一扫
3981
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
