创建测试表，其建表语句如下：
mysql> show create table test1;
+-------+----------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table |
+-------+----------------------------------------------------------------------------------------------------------------------------------------------------+
| test1 | CREATE TABLE `test1` (
`a` int(10) DEFAULT NULL,
`b` varchar(10) DEFAULT NULL,
KEY `test_index_a` (`a`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 |
+-------+----------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
插入测试数据：
mysql> insert into test1 values (1,'a'),(2,'a'),(3,'a'),(4,'d'),(5,'e'),(6,'f'),(7,'g'),(8,'h'),(9,'i'),(10,'j');
Query OK, 10 rows affected (0.00 sec)
Records: 10 Duplicates: 0 Warnings: 0
mysql> select * from test1;
+------+------+
| a | b |
+------+------+
| 1 | a |
| 2 | a |
| 3 | a |
| 4 | d |
| 5 | e |
| 6 | f |
| 7 | g |
| 8 | h |
| 9 | i |
| 10 | j |
+------+------+
10 rows in set (0.00 sec)
数据库slow日志相关参数配置：
slow_query_log = 1
slow_query_log_file = /data/mysql/mysql3306/slow_statement.log
long_query_time = 0
log_queries_not_using_indexes = 0
session A：
mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)
mysql> update test1 set b='xx' where b='a';
Query OK, 3 rows affected (0.00 sec)
Rows matched: 3 Changed: 3 Warnings: 0
mysql> commit;
Query OK, 0 rows affected (0.01 sec)
session B：
mysql> update test1 set b='yy' where b='a';
Query OK, 0 rows affected (9.38 sec)
Rows matched: 0 Changed: 0 Warnings: 0
mysql> commit;
Query OK, 0 rows affected (0.00 sec)
慢日志记录：
# Time: 2018-03-30T02:42:16.027553Z
# User@Host: root[root] @ localhost [] Id: 47
# Query_time: 0.001280 Lock_time: 0.000310 Rows_sent: 0 Rows_examined: 10
SET timestamp=1522377736;
update test1 set b='xx' where b='a';
# Time: 2018-03-30T02:42:29.785509Z
# User@Host: root[root] @ localhost [] Id: 47
# Query_time: 0.008619 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
SET timestamp=1522377749;
commit;
# Time: 2018-03-30T02:42:29.785817Z
# User@Host: root[root] @ localhost [] Id: 48
# Query_time: 9.375238 Lock_time: 9.374875 Rows_sent: 0 Rows_examined: 11
SET timestamp=1522377749;
update test1 set b='yy' where b='a';
小结1：当参数long_query_time设置为0，则执行时长大于0s的语句都会记录到slowlog里面。
============================================================================
数据库slow日志相关参数配置：
slow_query_log = 1
slow_query_log_file = /data/mysql/mysql3306/slow_statement.log
long_query_time = 0.0001
log_queries_not_using_indexes = 0
session A：
mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)
mysql> update test1 set b='xx' where b='a';
Query OK, 3 rows affected (0.01 sec)
Rows matched: 3 Changed: 3 Warnings: 0
mysql> commit;
Query OK, 0 rows affected (0.01 sec)
session B;
mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)
mysql> update test1 set b='yy' where b='a';
Query OK, 0 rows affected (8.63 sec)
Rows matched: 0 Changed: 0 Warnings: 0
mysql> commit;
Query OK, 0 rows affected (0.00 sec)
慢日志记录：
# Time: 2018-03-30T02:52:11.214300Z
# User@Host: root[root] @ localhost [] Id: 3
# Query_time: 0.001435 Lock_time: 0.000561 Rows_sent: 0 Rows_examined: 10
SET timestamp=1522378331;
update test1 set b='xx' where b='a';
# Time: 2018-03-30T02:52:25.326360Z
# User@Host: root[root] @ localhost [] Id: 3
# Query_time: 0.007641 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
SET timestamp=1522378345;
commit;
# Time: 2018-03-30T02:52:25.327693Z
# User@Host: root[root] @ localhost [] Id: 4
# Query_time: 8.629981 Lock_time: 8.629332 Rows_sent: 0 Rows_examined: 11
SET timestamp=1522378345;
update test1 set b='yy' where b='a';
小结2：当参数long_query_time设置为0.0001，则执行时长大于0.0001s的语句都会记录到slowlog里面。
=============================================================================
数据库slow日志相关参数配置：
slow_query_log = 1
slow_query_log_file = /data/mysql/mysql3306/slow_statement.log
long_query_time = 1
log_queries_not_using_indexes = 0
session A：
mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)
mysql> update test1 set b='xx' where b='a';
Query OK, 3 rows affected (0.00 sec)
Rows matched: 3 Changed: 3 Warnings: 0
mysql> commit;
Query OK, 0 rows affected (0.00 sec)
session B：
mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)
mysql> update test1 set b='yy' where b='a';
Query OK, 0 rows affected (10.13 sec)
Rows matched: 0 Changed: 0 Warnings: 0
mysql> commit;
Query OK, 0 rows affected (0.00 sec)
慢日志记录：
# Time: 2018-03-30T02:56:32.433616Z
# User@Host: root[root] @ localhost [] Id: 5
# Query_time: 0.001227 Lock_time: 0.000149 Rows_sent: 1 Rows_examined: 1050
SET timestamp=1522378592;
SHOW VARIABLES LIKE 'pid_file';
/usr/local/mysql/bin/mysqld, Version: 5.7.20-log (MySQL Community Server (GPL)). started with:
Tcp port: 3306 Unix socket: /data/mysql/mysql3306/mysql3306.sock
Time Id Command Argument
小结3：当参数long_query_time设置为1，则执行时长不大于1s的语句不会记录到slowlog里面。
总结：从上面3个实验可以发现，参数long_query_time影响了慢SQL在slowlog的记录。只有运行时长大于long_query_time参数的SQL，才会记录到slowlog。这个运行时长，是不包括由于事务锁等待消耗的时间的。
也就是说，exec_time= query_time - lock_time。 当exec_time >= long_query_time的SQL才会被记录到慢SQL里面。很多人会误认为只有query_time>= long_query_time就会记录到slowlog，需要纠正这个认知。
