|
，中间重复过程省略
root@localhost[tempdb]> insert into tb_slow select * from tb_slow;
Query OK, 26528 rows affected (4.40 sec)
Records: 26528 Duplicates: 0 Warnings: 0
root@localhost[tempdb]> system tail /var/lib/mysql/suse11b-slow.log
/usr/sbin/mysqld, Version: 5.5.39-log (MySQL Community Server (GPL)). started with:
Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock
Time Id Command Argument
# Time: 141004 22:05:48
# User@Host: root[root] @ localhost []
# Query_time: 4.396858 Lock_time: 0.000140 Rows_sent: 0 Rows_examined: 53056
use tempdb;
SET timestamp=1412431548;
insert into tb_slow select * from tb_slow;
....再次插入一些记录....
root@localhost[tempdb]> insert into tb_slow select * from tb_slow;
Query OK, 212224 rows affected (37.51 sec)
Records: 212224 Duplicates: 0 Warnings: 0
root@localhost[tempdb]> select table_schema,table_name,count(*) from tb_slow
-> group by table_schema,table_name order by 3,2;
+--------------------+----------------------------------------------+----------+
| table_schema | table_name | count(*) |
+--------------------+----------------------------------------------+----------+
| information_schema | COLLATION_CHARACTER_SET_APPLICABILITY | 1024 |
| performance_schema | cond_instances | 1024 |
...........
| mysql | user | 21504 |
+--------------------+----------------------------------------------+----------+
83 rows in set (1.58 sec)
root@localhost[tempdb]> system tail /var/lib/mysql/suse11b-slow.log
# User@Host: root[root] @ localhost []
# Query_time: 37.514172 Lock_time: 0.000123 Rows_sent: 0 Rows_examined: 424448
SET timestamp=1412431806;
insert into tb_slow select * from tb_slow;
# Time: 141004 22:10:47
# User@Host: root[root] @ localhost []
# Query_time: 1.573293 Lock_time: 0.000183 Rows_sent: 83 Rows_examined: 424614
SET timestamp=1412431847;
select table_schema,table_name,count(*) from tb_slow --这条SQL被记录下来了，其查询时间为1.573293s
group by table_schema,table_name order by 3,2;
root@localhost[tempdb]> show variables like '%log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF |
+-------------------------------+-------+
root@localhost[tempdb]> set global log_queries_not_using_indexes=1;
Query OK, 0 rows affected (0.00 sec)
--查看表tb_slow索引信息，表tb_slow无任何索引
root@localhost[tempdb]> show index from tb_slow;
Empty set (0.00 sec)
root@localhost[tempdb]> select count(*) from tb_slow;
+----------+
| count(*) |
+----------+
| 424448 |
+----------+
1 row in set (0.20 sec)
root@localhost[tempdb]> system tail -n3 /var/lib/mysql/suse11b-slow.log
# Query_time: 0.199840 Lock_time: 0.000152 Rows_sent: 1 Rows_examined: 424448
SET timestamp=1412432188;
select count(*) from tb_slow; --此次查询时间为0.199840，被记录的原因是因为没有走索引，因为表本身没有索引
4、格式化慢查询日志
结构化慢查询日志就是把慢查询日志中的重要信息按照便于阅读以及按照特定的排序方式来提取SQL。
这种方式有点类似于Oracle中有个tkprof来格式化oracle的trace文件。
对于前面的慢查询日志我们使用mysqldumpslow来提取如下：
suse11b:~ # mysqldumpslow -s at,al /var/lib/mysql/suse11b-slow.log
Reading mysql slow query log from /var/lib/mysql/suse11b-slow.log
Count: 4 Time=16.87s (67s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@localhost
insert into tb_s |