MySQL慢查询日志相关设置

来源：这里教程网时间：2026-03-01 16:09:17 作者：

问题：开启慢查询日志后，超过long_query_time的操作哪些不会记录到慢日志文件中？ mysql> show global variables like '%slow%'; +---------------------------+-----------------------------+ | Variable_name | Value | +---------------------------+-----------------------------+ | log_slow_admin_statements | OFF | | log_slow_extra | OFF | | log_slow_slave_statements | OFF | | slow_launch_time | 2 | | slow_query_log | ON | | slow_query_log_file | /app/mysql/log/slow3306.log | +---------------------------+-----------------------------+ 6 rows in set (0.01 sec) mysql> show global variables like 'long_query_time'; +-----------------+----------+ | Variable_name | Value | +-----------------+----------+ | long_query_time | 1.000000 | +-----------------+----------+ 1 row in set (0.01 sec) 首先来看几种最普通的操作（1）sleep （2）正常的表查询（3）查询过程中会话中断（4）包含排序、分组等操作 mysql> select sleep(1) ; +----------+ | sleep(1) | +----------+ | 0 | +----------+ 1 row in set (1.00 sec) mysql> select count(1) from test.account t1,test.account t2; +----------------+ | count(1) | +----------------+ | 35116409328100 | +----------------+ 1 row in set (1.08 sec) mysql> select count(1) from test.account t1,test.account t2,test.account t3,information_schema.tables; ^C^C -- query aborted ERROR 1317 (70100): Query execution was interrupted mysql> select * from account t1 order by name limit 100000,1; +---------+-------------+---------+---------------------+---------------------+-------------------+ | id | name | partkey | created_at | updated_at2 | conform_pay_state | +---------+-------------+---------+---------------------+---------------------+-------------------+ | 1134998 | name1134998 | e1 | 2021-10-15 13:36:08 | 2021-10-15 13:36:08 | 3 | +---------+-------------+---------+---------------------+---------------------+-------------------+ 1 row in set (23.63 sec) mysql> select substr(name,4,3),count(1) from account t1 group by substr(name,4,3) limit 2; +------------------+----------+ | substr(name,4,3) | count(1) | +------------------+----------+ | e34 | 74076 | | e35 | 74076 | +------------------+----------+ 2 rows in set (6.81 sec) 日志内容： # Time: 2021-11-25T20:50:24.421438+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64077 # Query_time: 1.000365 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 1 SET timestamp=1637844623; select sleep(1); # Time: 2021-11-25T20:51:12.203789+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64077 # Query_time: 1.078180 Lock_time: 0.000291 Rows_sent: 1 Rows_examined: 0 SET timestamp=1637844671; select count(1) from test.account t1,test.account t2; # Time: 2021-11-25T20:51:43.745724+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64077 # Query_time: 8.127499 Lock_time: 0.001228 Rows_sent: 0 Rows_examined: 27259 SET timestamp=1637844695; select count(1) from test.account t1,test.account t2,test.account t3,information_schema.tables; # Time: 2021-11-25T21:53:56.716651+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64141 # Query_time: 23.629454 Lock_time: 0.000146 Rows_sent: 1 Rows_examined: 6025911 SET timestamp=1637848413; select * from account t1 order by name limit 100000,1; # Time: 2021-11-25T21:55:09.622017+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64141 # Query_time: 6.810800 Lock_time: 0.000199 Rows_sent: 2 Rows_examined: 5925910 SET timestamp=1637848502; select substr(name,4,3),count(1) from account t1 group by substr(name,4,3) limit 2; 这些都被正常记录到慢日志文件中。再看几种较为复杂的场景：（5）操作被阻塞 @会话1： mysql> begin; Query OK, 0 rows affected (0.00 sec) mysql> select * from account where id=1134998 for update; +---------+------------+---------+---------------------+---------------------+-------------------+ | id | name | partkey | created_at | updated_at2 | conform_pay_state | +---------+------------+---------+---------------------+---------------------+-------------------+ | 1134998 | namea12345 | e1 | 2021-11-25 21:59:54 | 2021-11-25 21:59:54 | 3 | +---------+------------+---------+---------------------+---------------------+-------------------+ 1 row in set (0.00 sec) @会话2： mysql> update account set name='namea111111' where id=1134998; 由于会话2需要等待会话1释放锁，一直处于阻塞状态，直到会话1 commit Query OK, 1 row affected (41.99 sec) Rows matched: 1 Changed: 1 Warnings: 0 虽然耗时41.99秒，但由于不是执行耗时，因此慢日志未记录（6）DDL操作 mysql> alter table account drop column testcol; Query OK, 0 rows affected (24.63 sec) Records: 0 Duplicates: 0 Warnings: 0 也不会被记录到慢日志中。 ########################################################## 根据官方文档，5.7版本中，记录慢日志需要顺序满足以下逻辑： 1.语句不能是管理语句（ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE,REPAIR TABLE），除非开启了log_slow_admin_statements 2.语句耗时超过long_query_time，或者开启了log_queries_not_using_indexes参数的情况下查询未使用索引（小于long_query_time也会被记录） 3.语句需要至少扫描了min_examined_row_limit行 4.设置了log_throttle_queries_not_using_indexes参数时，语句没有被压缩显示不会记录查询缓存处理的语句(仅5.7版本涉及，8.0版本已经没有缓存) 从库默认不会记录replicated到的语句；如果开启log_slow_slave_statements，并且binlog_format是statement 或者binlog_format=MIXED且语句是按statement同步的，则可以被放入慢日志文件。因此 5.7\8.0版本mysql中需要设置如下参数（个人总结），可以记录阻塞情况以外的大部分可疑慢查询语句。 slow_query_log=1 long_query_time=5 [根据实际情况调整] log_slow_admin_statements=1 log_queries_not_using_indexes=1 global min_examined_row_limit=10000 log_throttle_queries_not_using_indexes=10 log_slow_extra=1 释义：开启慢查询日志，记录超过5秒的语句，包含管理类语句，包含未使用索引的语句且每分钟最多记录10条这样的语句，超过10条的部分将被压缩记录。记录慢查询的额外信息（起止时间、thread_id、是否被kill等）相关实例1：下面是设置log_throttle_queries_not_using_indexes=2后，一分钟内6次执行未使用索引的语句，后面四次被压缩记录了。 # Time: 2021-11-25T22:38:48.769946+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64141 # Query_time: 0.001497 Lock_time: 0.000147 Rows_sent: 1 Rows_examined: 1000 SET timestamp=1637851128; select * from test1 where name='name34'; # Time: 2021-11-25T22:38:48.777614+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64142 # Query_time: 0.001219 Lock_time: 0.000095 Rows_sent: 1 Rows_examined: 1000 SET timestamp=1637851128; select * from test1 where name='name35'; # Time: 2021-11-25T22:40:02.848238+08:00 # User@Host: [] @ [] Id: 64195 # Query_time: 0.004725 Lock_time: 0.000398 Rows_sent: 1 Rows_examined: 1 SET timestamp=1637851202; throttle: 4 'index not used' warning(s) suppressed.; 《《《《《有额外的四条语句未使用索引相关实例2：开启log_slow_extra前后，同一sql的日志差异: # Time: 2021-11-25T22:56:07.740623+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64141 # Query_time: 7.300167 Lock_time: 0.000403 Rows_sent: 0 Rows_examined: 29583 SET timestamp=1637852160; select count(1) from test.account t1,test.account t2,test.account t3,information_schema.tables; # Time: 2021-11-25T22:58:36.141562+08:00 # User@Host: root[root] @ [127.0.0.1] Id: 64141 # Query_time: 11.336944 Lock_time: 0.000852 Rows_sent: 0 Rows_examined: 37156 Thread_id: 64141 Errno: 1160 Killed: 1053 Bytes_received: 0 Bytes_sent: 0 Read_first: 3 Read_last: 0 Read_key: 5132 Read_next: 20528 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 4654 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: 2021-11-25T22:58:24.804618+08:00 End: 2021-11-25T22:58:36.141562+08:00 SET timestamp=1637852304; select count(1) from test.account t1,test.account t2,test.account t3,information_schema.tables;