Mysql 慢查询日志

mysql慢查询日志对于跟踪有问题的查询非常有用，可以分析出代码实现中耗费资源的sql语句，对我们程序的优化有很高的参考。本篇主要将慢查询日志的开启，日志分析，这也是优化SQL程序的一般步骤中至关重要的一步。 

1.mysql慢查询日志 
          打开mysql的慢查询日志很简单,只需要在mysql的配置文件里(windows系统是my.ini,linux系统是my.cnf)的[mysqld]下面加上 

 

1. log-slow-queries=mysql_slow.log  
2. long_query_time=3  

          其中log-slow-queries为日志的文件名，可以指定目录，如log-slow-queries=D:\mysql_slow.log; long_query_time为定义多长的查询我们定义为慢查询，并记录在log-slow-queries 指定的文件中，在这里我们定义超过3秒的查询进行记录。 
          配置完成以后重启Mysql服务器，执行show variables like '%slow%';查看慢查询日志是否开启，如果slow_query_log和log_slow_queries显示为on，那说明服务器的慢查询日志已           
          经开启了。如下显示： 

 

1. mysql> show variables like '%slow%';  
2. +---------------------+----------------+  
3. | Variable_name       | Value          |  
4. +---------------------+----------------+  
5. | log_slow_queries    | ON             |  
6. | slow_launch_time    | 2              |  
7. | slow_query_log      | ON             |  
8. | slow_query_log_file | mysql_slow.log |  
9. +---------------------+----------------+  
10. 4 rows in set (0.00 sec)  

slow_launch_time跟慢查询日志没有任何关系, 它代表的是thread create的一个阈值，如果要看 long_query_time，可以用 

 

1. mysql> show variables like '%long%';  
2. +-----------------+----------+  
3. | Variable_name   | Value    |  
4. +-----------------+----------+  
5. | long_query_time | 3.000000 |  
6. +-----------------+----------+  
7. 1 row in set (0.00 sec)  

  2.mysql慢查询日志分析 
             建表如下图，建表勿要给text加上索引，否则可能出现不了超过3秒的查询，数据表填充了4194304条数据。 
             


            我们来执行一个超过3秒的查询，如下： 
    

 

1.      mysql> select * from wei where text='orange';  
2. +---------+--------+  
3. | id      | text   |  
4. +---------+--------+  
5. | 4103519 | orange |  
6. +---------+--------+  

1 row in set (3.79 sec) 
再执行一个超过3秒的和一个没有超过3秒的： 

 

1. mysql> select * from wei where text='xishizhaohua';  
2. Empty set (3.82 sec)  

 

 

1. [mysql> select * from wei where id=4564;  
2. +------+--------------------+  
3. | id   | text               |  
4. +------+--------------------+  
5. | 4564 | yyyyyyyyyyyyyyyyyy |  
6. +------+--------------------+  
7. 1 row in set (0.02 sec)  

可以通过下面的命令查看现在这个session有多少个慢查询： 

  

现在我们可以查看mysql_slow.log（win7默认在C:\ProgramData\MySQL\MySQL Server 5.1\data下面），里边内容如下，内容比较明了，包括查询花费的语句及时间，还包括查询时的时间戳等信息，其中Rows_examined为检查的行数，对我们优化也很有帮助 
# Time: 121017 17:38:54 
# User@Host: root[root] @ localhost [127.0.0.1] 
# Query_time: 3.794217 Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 4194304 
SET timestamp=1350466734; 
select * from wei where text='orange'; 
# Time: 121017 17:46:22 
# User@Host: root[root] @ localhost [127.0.0.1] 
# Query_time: 3.819219  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 4194304 
SET timestamp=1350467182; 
select * from wei where text='xishizhaohua'; 

3.优化 
          其实定位到了慢查询语句就已经完成了一大不了，执行explain或者desc命令查看慢查询语句，如下图： 
   
  

          问题很明显，解决方式也很明显，建索引了。 

 

1. mysql> create index text_index on wei(text);  
2. Query OK, 4194304 rows affected (1 min 58.07 sec)  
3. Records: 4194304  Duplicates: 0  Warnings: 0  

然后在执行查询操作，用时明显少了很多。 

 

1. mysql> select * from wei where text='orange';  
2. +---------+--------+  
3. | id      | text   |  
4. +---------+--------+  
5. | 4103519 | orange |  
6. +---------+--------+  
7. 1 row in set (0.33 sec)  

 

 

1. mysql> select * from wei where text='xishizhaohua';  
2. Empty set (0.01 sec)