MySQL慢日志

1、MySQL慢日志概要说明

慢查询日志由执行时间超过 long_query_time参数配置且大于 min_examined_row_limit参数设置的 SQL 语句组成，慢查询日志可用于查找执行时间较长且因此适合优化的查询。然而，检查执行时间较长的查询日志也是一项耗时的任务；为了使检查慢 sql更容易，可以使用 mysqldumpslow命令或者 pt_query_digest 工具来处理慢查询日志文件获取汇总后的慢 sql 信息。

慢 sql 记录中sql 执行获取初始锁的时间不计入执行时间，mysqld在执行完并且释放所有锁后将一条语句写入慢查询日志，因此日志顺序可能与执行顺序不同。

2、MySQL慢日志控制参数

默认情况下，慢查询日志slow_query_log参数是关闭的，即参数配置为 0；开启慢日志：slow_query_log=1，开启后使用slow_query_log_file指定慢日志文件的路径：slow_query_log_file=file_namelog_output。

开启后，慢日志记录阈值由参数long_query_time 参数控制，该参数最小值为 0，默认值为 10s，参数可以指定到微秒级别。

mysql> show variables like '%long_query_time%';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 0.000005 |
+-----------------+----------+
1 row in set (0.01 sec)


慢日志默认情况下，不记录管理语句，也不记录不使用索引进行查找的查询；管理慢语句是否记录受log_slow_admin_statements参数控制（管理命令包含： ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, 和 REPAIR TABLE.）和 不使用索引进行查找的慢查询是否记录受log_queries_not_using_indexes参数控制。

mysql> show variables like '%log_slow_admin_statements%';
+---------------------------+-------+
| Variable_name | Value |
+---------------------------+-------+
| log_slow_admin_statements | OFF |
+---------------------------+-------+
1 row in set (0.01 sec)

mysql> show variables like '%log_queries_not_using_indexes%';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF |
+-------------------------------+-------+
1 row in set (0.01 sec)


⚠️ 慢查询记录可以记录到数据库的慢查询表中，但一般不建议将慢查询记录到数据库表中。

如果不指定慢查询日志文件的名称，则默认名称为 host_name-slow.log, 除非给出绝对路径名来指定不同的目录，否则服务器会在数据目录中创建慢查询文件.

需要在运行时更改日志文件名，可以动态修改slow_query_log_file系统变量；如果需要永久生效则需要同步修改my.cnf 配置文件。

mysql> show variables like '%slow_query_log_file%';
+-----------------------------+--------------------------------------+
| Variable_name | Value |
+-----------------------------+--------------------------------------+
| slow_query_log_file | /var/lib/mysql/40ab34673e74-slow.log |
+-----------------------------+--------------------------------------+
7 rows in set (0.01 sec)
mysql> set global slow_query_log_file='/var/lib/mysql/40ab34673e74-slow01.log';
Query OK, 0 rows affected (0.01 sec)

mysql> \q
Bye
bash-4.4# ls -lhrt /var/lib/mysql/40ab34673e74-slow*
-rw-r----- 1 mysql mysql 2.9K May 16 08:12 /var/lib/mysql/40ab34673e74-slow.log
-rw-r----- 1 mysql mysql 876 May 16 08:13 /var/lib/mysql/40ab34673e74-slow01.log


要在写入慢查询日志的语句中包含不使用索引进行行查找的查询，需要启用 log_queries_not_using_indexes 系统变量。

当记录不使用索引的查询时，慢查询日志可能会增长的较快；可以通过设置 log_throttle_queries_not_using_indexes 系统变量对这些查询设置速率限制。

默认情况下，log_throttle_queries_not_using_indexes变量为 0，表示没有限制，大于 0 的配置会限制每分钟可写入慢查询日志的此类查询的数量。第一个此类查询执行时会打开一个 60 秒的窗口，在该窗口中服务器会记录达到给定限制内的该类查询，超过限制的该类其他查询会不在记录详细信息。如果窗口结束时存在不被记录的该类的慢查询，服务器会记录一个摘要标明有多少个查询未被记录以及在这些查询中花费的总时间。下一个 60 秒的窗口开始于下一个可以记录的未使用索引的查询。

服务器按以下顺序使用控制参数来确定是否将查询写入慢查询日志

1. 该查询不是管理语句，除非log_slow_admin_statements已启用。
2. 该查询执行时间大于 long_query_time，或者 log_queries_not_using_indexes 已启用并且查询不使用任何索引进行行查找。
3. 该查询扫描行数大于 min_examined_row_limit 参数配置。
4. 根据log_throttle_queries_not_using_indexes参数设置，未达到该参数限制。

系统log_timestamps变量控制写入慢查询日志文件（以及通用查询日志文件和错误日志）的消息中时间戳的时区。它不会影响写入日志表的通用查询日志和慢查询日志消息的时区，但可以使用CONVERT_TZ()或通过设置会话time_zone 系统变量将从这些表检索的行从本地系统时区转换为任何所需的时区。

注意：5.7 版本不记录查询缓存处理的查询。

默认情况下，从库不会将复制查询写入慢查询日志。要更改此设置，请启用系统变量 log_slow_replica_statements （从 MySQL 8.0.26 开始）或 log_slow_slave_statements （在 MySQL 8.0.26 之前）。请注意，如果使用基于行的复制 ( binlog_format=ROW)，则这些系统变量无效。只有当查询以statment格式记录在二进制日志中时，即当binlog_format=STATEMENT设置时，或者当binlog_format=MIXED设置并且语句以语句格式记录时，查询才会在从库的慢查询日志中记录 。即使log_slow_replica_statements或log_slow_slave_statements开启，在binlog_format=MIXED并以行格式记录或在binlog_format=ROW设置时慢查询也不会记录到副本的慢查询日志中。

3、慢查询日志记录的内容

3.1 基本字段信息

如果启用慢查询日志并配置了慢日志文件作为输出目标，则写入日志的每个语句前面都有一行以字符开头 #并包含以下字段（所有字段都在一行上）：

Query_time: duration

语句执行时间（以秒为单位）。

Lock_time: duration

获取锁的时间（以秒为单位）。

Rows_sent: N

发送到客户端的行数。

Rows_examined:

服务器层检查的行数（不计算存储引擎内部的任何处理）。

# Time: 2024-05-16T07:12:59.068855Z
# User@Host: root[root] @ localhost [] Id: 5
# Query_time: 0.008817 Lock_time: 0.000551 Rows_sent: 1024 Rows_examined: 1024
SET timestamp=1715843579;
select * from addr;


3.2 额外字段信息

在从 MySQL 8.0.14以后的版本中，log_slow_extra启用后还会记录额外的部分字段输出到慢查询文件中。

写入慢查询日志文件的每个语句前面都有一个SET 包含时间戳的语句。从 MySQL 8.0.14以后的版本，时间戳指示慢语句开始执行的时间。在 8.0.14 之前，时间戳标识慢sql被记录时间（在语句执行完成后）。

写入慢查询日志的语句中的密码由服务器重写，不会以纯文本形式出现。

从 MySQL 8.0.29以后的版本，无法解析的语句（例如由于语法错误）不会写入慢查询日志。

额外字段说明参考如下：

• Thread_id: ID 语句线程标识符。

• Errno: error_number 语句错误号，如果没有发生错误则为 0。

• Killed: N 如果语句终止，则错误号指示原因；如果语句正常终止，则错误号为 0。

• Bytes_received: N Bytes_received语句的值 。

• Bytes_sent: N Bytes_sent语句的值 。

• Read_first: N Handler_read_first 语句的值 。

• Read_last: N Handler_read_last 语句的值 。

• Read_key: N Handler_read_key语句的值 。

• Read_next: N Handler_read_next 语句的值 。

• Read_prev: N Handler_read_prev 语句的值 。

• Read_rnd: N Handler_read_rnd语句的值 。

• Read_rnd_next: N Handler_read_rnd_next 语句的值 。

• Sort_merge_passes: N Sort_merge_passes 语句的值 。

• Sort_range_count: N Sort_range语句的值 。

• Sort_rows: N Sort_rows语句的值 。

• Sort_scan_count: N Sort_scan语句的值 。

• Created_tmp_disk_tables: N Created_tmp_disk_tables 语句的值 。

• Created_tmp_tables: N Created_tmp_tables 语句的值 。

• Start: timestamp 语句执行开始时间。

• End: timestamp 语句执行结束时间。

# Time: 2024-05-16T08:52:56.904916Z
# User@Host: root[root] @ localhost [] Id: 12
# Query_time: 0.000759 Lock_time: 0.000020 Rows_sent: 10 Rows_examined: 10 Thread_id: 12 Errno: 0 Killed: 0 Bytes_received: 34 Bytes_sent: 234 Read_first: 1 Read_last: 0 Read_key: 1 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 10 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2024-05-16T08:52:56.904157Z End: 2024-05-16T08:52:56.904916Z
SET timestamp=1715849576;
select * from addr limit 10;