详解MySQL慢日志（上）query_time\start_time\lock_time 的坑

http://blog.itpub.net/29773961/viewspace-2147315/

〇 log_output
枚举型，动态参数。
用于设置slow log和general log的输出对象。
可以设置为none，table，file，分别代表：不输出，存于表，存于文件。

并且也可以组合设置：
比如SET GLOBAL log_output='table,file';
则代表同时输出到表和文件中。

如果设置SET GLOBAL log_output='none,file' 或 'none,table' 或 'table,file,none' 均代表'none'

〇 slow_query_log与slow_query_log_file
slow_query_log 布尔型，动态参数，默认为OFF。
用于控制是否开启slow log。

slow_query_log_file 动态参数，指定slow log文件的名称和路径。
若未设置，则slow log的文件名取默认值$host_name-slow.log，存放于$datadir下。

〇 long_query_time
动态参数，默认值为10。
记录执行时间（real time）超过该值以上的SQL。

〇 log_queries_not_using_indexes
布尔型，动态参数，默认为OFF。
若开启，则表示记录所有未使用索引的SQL，无论是否超过long_query_time所设置的值。
不遵循long_query_time。

mysql> SET SESSION long_query_time=10000;
Query OK, 0 rows affected (0.00 sec)
mysql> CREATE TABLE test.slow(id int);
Query OK, 0 rows affected (0.03 sec)
mysql> INSERT INTO test.slow SELECT 1;
Query OK, 1 row affected (0.01 sec)
Records: 1 Duplicates: 0 Warnings: 0
mysql> SELECT * FROM test.slow WHERE id=1;
+------+
| id |
+------+
| 1 |
+------+
1 row in set (0.00 sec)
mysql> SELECT start_time, query_time,lock_time,sql_text FROM mysql.slow_log;
+----------------------------+-----------------+-----------------+------------------------------------+
| start_time | query_time | lock_time | sql_text |
+----------------------------+-----------------+-----------------+------------------------------------+
| 2017-11-16 15:09:32.114488 | 00:00:00.000346 | 00:00:00.000166 | SELECT * FROM test.slow WHERE id=1 |
+----------------------------+-----------------+-----------------+------------------------------------+
1 row in set (0.00 sec)

此时上面这一条SQL被记录到slow log，并且忽略了long_query_time的设置。

加一个索引，再多一次查询：

mysql> ALTER TABLE test.slow ADD PRIMARY KEY pk(id);
Query OK, 0 rows affected (0.14 sec)
Records: 0 Duplicates: 0 Warnings: 0
mysql> SELECT * FROM test.slow WHERE id=1;
+----+
| id |
+----+
| 1 |
+----+
1 row in set (0.00 sec)
mysql> SELECT start_time, query_time,lock_time,sql_text FROM mysql.slow_log;
+----------------------------+-----------------+-----------------+----------------------------------------------------------------------+
| start_time | query_time | lock_time | sql_text |
+----------------------------+-----------------+-----------------+----------------------------------------------------------------------+
| 2017-11-16 15:09:32.114488 | 00:00:00.000346 | 00:00:00.000166 | SELECT * FROM test.slow WHERE id=1 |
| 2017-11-16 15:10:50.196590 | 00:00:00.000437 | 00:00:00.000148 | SELECT start_time, query_time,lock_time,sql_text FROM mysql.slow_log |
+----------------------------+-----------------+-----------------+----------------------------------------------------------------------+
2 rows in set (0.00 sec)

可以发现第二次SELECT的SQL的没有被记录到slow log。
至于这条查询slow log的语句本身被记录到slow log，也是因为这条查mysql.slow_log的SQL没有使用到索引。

因为开启该参数造成slow log暴涨的案例：
http://blog.itpub.net/29773961/viewspace-1811829/

〇 log_throttle_queries_not_using_indexes
整型，动态参数，默认为0。
如果log_queries_not_using_indexes开启，
那么log_throttle_queries_not_using_indexes用于限制每分钟所记录的slow log数量。
设置为0则表示“不限制”。

〇 log_slow_admin_statements
布尔型，动态参数，默认为OFF。5.7后新增的参数。
可用于控制slow log是否记录数据库管理的SQL。
若开启，则表示记录这些SQL。
数据库管理的SQL包括：
ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, REPAIR TABLE。

遵循long_query_time。

第一次执行check table，时间超过2秒，但未被记录。
第二次执行check table，开启log_queries_not_using_indexes，超过2秒，被记录。

mysql> SELECT @@long_query_time, @@log_queries_not_using_indexes;
+-------------------+---------------------------------+
| @@long_query_time | @@log_queries_not_using_indexes |
+-------------------+---------------------------------+
| 2.000000 | 0 |
+-------------------+---------------------------------+
1 row in set (0.00 sec)
mysql> CHECK TABLE test.t0;
+---------+-------+----------+----------+
| Table | Op | Msg_type | Msg_text |
+---------+-------+----------+----------+
| test.t0 | check | status | OK |
+---------+-------+----------+----------+
1 row in set (4.28 sec)
mysql> SET GLOBAL log_slow_admin_statements = 1;
Query OK, 0 rows affected (0.00 sec)
mysql> CHECK TABLE test.t0;
+---------+-------+----------+----------+
| Table | Op | Msg_type | Msg_text |
+---------+-------+----------+----------+
| test.t0 | check | status | OK |
+---------+-------+----------+----------+
1 row in set (4.27 sec)
mysql> SELECT start_time, query_time,lock_time,sql_text FROM mysql.slow_log;
+----------------------------+-----------------+-----------------+---------------------+
| start_time | query_time | lock_time | sql_text |
+----------------------------+-----------------+-----------------+---------------------+
| 2017-11-16 15:31:24.378343 | 00:00:04.271940 | 00:00:00.000134 | CHECK TABLE test.t0 |
+----------------------------+-----------------+-----------------+---------------------+
1 row in set (0.00 sec)

〇 log_slow_slave_statements
布尔型，动态参数，默认为OFF。5.7后新增的参数。
开启后，在slave上将会记录超过long_query_time的日志记录。
即便开启了这个选项，也不会立刻生效，新的变更需要再一次START SLAVE后生效。

〇 min_examined_row_limit
整型，动态参数，默认为0。
设置该值，则表示返回行数大于等于该值的sql，将会被记录到slow log中。

mysql> SET SESSION long_query_time=0, SESSION min_examined_row_limit=5;
Query OK, 0 rows affected (0.00 sec)
mysql> SELECT * FROM test.t0 LIMIT 4;
…………
4 rows in set (0.00 sec)
mysql> SELECT * FROM test.t0 LIMIT 5;
…………
5 rows in set (0.00 sec)
mysql> SELECT * FROM test.t0 LIMIT 10;
…………
10 rows in set (0.00 sec)
mysql> SELECT start_time, query_time,lock_time,sql_text FROM mysql.slow_log;
+----------------------------+-----------------+-----------------+--------------------------------+
| start_time | query_time | lock_time | sql_text |
+----------------------------+-----------------+-----------------+--------------------------------+
| 2017-11-17 16:08:14.851394 | 00:00:00.000286 | 00:00:00.000134 | SELECT * FROM test.t0 LIMIT 5 |
| 2017-11-17 16:08:16.744389 | 00:00:00.000284 | 00:00:00.000135 | SELECT * FROM test.t0 LIMIT 10 |
+----------------------------+-----------------+-----------------+--------------------------------+
2 rows in set (0.00 sec)

个人认为大多数场景都无需刻意设置该值，取默认为0就好。

〇 log-short-format
默认为FLASE，该选项仅仅为启动时选项，并不支持系统变量。
如果该选项被激活，则表示在slow log中记录更少的信息。

〇 log_timestamps
枚举型，动态，默认为UTC，5.7.2后出现。
这个参数是用于控制记录在error log、general log、slow log中，对应日期时区的选项。

更多可参考：
http://blog.itpub.net/29773961/viewspace-2146053/

〇参考文档：
MySQL 5.7 Reference Manual - 5.1.3 Server Option and Variable Reference

作者微信公众号（持续更新）

ITPub博客

详解MySQL慢日志（下）选项参数篇

最新文章