Mysql 慢查询日志          

博客分类:mysql

mysql 

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

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

Java代码 复制代码 收藏代码spinner.gif

  1. log-slow-queries=mysql_slow.log  

  2. long_query_time=3  

               log-slow-queries=mysql_slow.log
               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,那说明服务器的慢查询日志已            
          经开启了。如下显示:

Java代码 复制代码 收藏代码spinner.gif

  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)  

mysql> show variables like '%slow%';
+---------------------+----------------+
| Variable_name       | Value          |
+---------------------+----------------+
| log_slow_queries    | ON             |
| slow_launch_time    | 2              |
| slow_query_log      | ON             |
| slow_query_log_file | mysql_slow.log |
+---------------------+----------------+
4 rows in set (0.00 sec)


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

Java代码 复制代码 收藏代码spinner.gif

  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)  

mysql> show variables like '%long%';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 3.000000 |
+-----------------+----------+
1 row in set (0.00 sec)


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

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

Java代码 复制代码 收藏代码spinner.gif

  1.      mysql> select * from wei where text='orange';  

  2. +---------+--------+  

  3. | id      | text   |  

  4. +---------+--------+  

  5. 4103519 | orange |  

  6. +---------+--------+  

     mysql> select * from wei where text='orange';
+---------+--------+
| id      | text   |
+---------+--------+
| 4103519 | orange |
+---------+--------+


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

Java代码 复制代码 收藏代码spinner.gif

  1. mysql> select * from wei where text='xishizhaohua';  

  2. Empty set (3.82 sec)  

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


Java代码 复制代码 收藏代码spinner.gif

  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)  

[mysql> select * from wei where id=4564;
+------+--------------------+
| id   | text               |
+------+--------------------+
| 4564 | yyyyyyyyyyyyyyyyyy |
+------+--------------------+
1 row in set (0.02 sec)


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

cc6fdedf-9252-39d3-9a81-cbdff6ca43da.png

现在我们可以查看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命令查看慢查询语句,如下图:
    
460f2a9f-b343-333a-ab2d-61e7ec3d89ab.png

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

Java代码 复制代码 收藏代码spinner.gif

  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  

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


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

Java代码 复制代码 收藏代码spinner.gif

  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)  

mysql> select * from wei where text='orange';
+---------+--------+
| id      | text   |
+---------+--------+
| 4103519 | orange |
+---------+--------+
1 row in set (0.33 sec)


Java代码 复制代码 收藏代码spinner.gif

  1. mysql> select * from wei where text='xishizhaohua';  

  2. Empty set (0.01 sec)  

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