关于long_query_time参数的一个测试

创建测试表，其建表语句如下：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 = 1slow_query_log_file = /data/mysql/mysql3306/slow_statement.loglong_query_time = 0log_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: 10SET 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: 0SET 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: 11SET timestamp=1522377749;update test1 set b=’yy’ where b=’a’;
小结1：当参数long_query_time设置为0，则执行时长大于0s的语句都会记录到slowlog里面。
============================================================================

数据库slow日志相关参数配置：slow_query_log = 1slow_query_log_file = /data/mysql/mysql3306/slow_statement.loglong_query_time = 0.0001log_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: 10SET 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: 0SET 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: 11SET timestamp=1522378345;update test1 set b=’yy’ where b=’a’;
小结2：当参数long_query_time设置为0.0001，则执行时长大于0.0001s的语句都会记录到slowlog里面。
=============================================================================
数据库slow日志相关参数配置：slow_query_log = 1slow_query_log_file = /data/mysql/mysql3306/slow_statement.loglong_query_time = 1log_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: 1050SET 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.sockTime 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，需要纠正这个认知。

相关推荐: MySQL存储引擎知多少

MySQL是我们经常使用的数据库处理系统(DBMS)，不知小伙伴们有没有注意过其中的“存储引擎”(storage_engine)呢?有时候面试题中也会问道MySQL几种常用的存储引擎的区别。这次就简短侃一下存储引擎那些事儿。 先去查一下“引擎”概念。 引擎(E…