慢查询

1.慢查询参数

mysql> show variables like 'slow_query_log%';
+---------------------+----------------------------+
| Variable_name       | Value                      |
+---------------------+----------------------------+
| slow_query_log      | OFF                        |
| slow_query_log_file | /mysqldata1/rhel5-slow.log |
+---------------------+----------------------------+

该参数是动态参数,可以在线打开

mysql> set GLOBAL slow_query_log=ON;
Query OK, 0 rows affected (0.04 sec)

mysql> show variables like '%query_time%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+

设置long_query_time这个阈值后,MySQL会记录运行时间超过该值的所有SQL语句。

mysql> show variables like '%not_using_index%';
+----------------------------------------+-------+
| Variable_name                          | Value |
+----------------------------------------+-------+
| log_queries_not_using_indexes          | OFF   |
| log_throttle_queries_not_using_indexes | 0     |
+----------------------------------------+-------+

log_queries_not_using_indexes
如果运行的SQL语句没有使用索引,则MySQL数据库同样会将这条SQL语句记录到慢查询日志文件。
log_throttle_queries_not_using_indexes
表示每分钟允许记录到slow log的且未使用索引的SQL语句次数。默认是0,表示没有限制

慢查询日志中记录的内容:

# Time: 140726  3:34:49
# User@Host: root[root] @  [192.168.1.37]  Id:     5
# Query_time: 0.038704  Lock_time: 0.000109 Rows_sent: 1  Rows_examined: 1
SET timestamp=1406316889;
select * from `test`.`t1` limit 0, 50;
# Time: 140726  3:35:43
# User@Host: root[root] @  [192.168.1.101]  Id:     7
# Query_time: 0.000235  Lock_time: 0.000122 Rows_sent: 9  Rows_examined: 9
use test;
SET timestamp=1406316943;
select `ENGINE`, `SUPPORT` from information_schema.Engines;
# Time: 140726  3:35:44
# User@Host: root[root] @  [192.168.1.101]  Id:     7
# Query_time: 0.000609  Lock_time: 0.000139 Rows_sent: 6  Rows_examined: 6
SET timestamp=1406316944;
select * from `test`.`t3` limit 0, 50;
# Time: 140726  3:36:14
# User@Host: root[root] @  [192.168.1.101]  Id:     7
# Query_time: 0.000244  Lock_time: 0.000096 Rows_sent: 1  Rows_examined: 6
SET timestamp=1406316974;
select * from t3 where f2 = 'e';

2.mysqldumpslow工具

当慢查询日志很大时,可能查看会比较困难,这时可以使用mysqldumpslow命令来进行分析
$ mysqldumpslow mysql_3301_slow.log

2.1 得到执行时间最长的10条SQL语句

$ mysqldumpslow -s al -n 10 mysql_3301_slow.log

3. 慢查询表

MySQL可以将慢查询的日志记录放入一张表中,这使得用户的查询更加方便和直观。慢查询表为:mysql.slow_log

mysql> show create table mysql.slow_log\G
*************************** 1. row ***************************
       Table: slow_log
Create Table: CREATE TABLE `slow_log` (
  `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  `user_host` mediumtext NOT NULL,
  `query_time` time NOT NULL,
  `lock_time` time NOT NULL,
  `rows_sent` int(11) NOT NULL,
  `rows_examined` int(11) NOT NULL,
  `db` varchar(512) NOT NULL,
  `last_insert_id` int(11) NOT NULL,
  `insert_id` int(11) NOT NULL,
  `server_id` int(10) unsigned NOT NULL,
  `sql_text` mediumtext NOT NULL,
  `thread_id` bigint(21) unsigned NOT NULL
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log'

参数log_output指定了慢查询的输出格式,默认为FILE,可以将它设为TABLE。参数log_output是动态的,并且是全局的,因此可以在线修改。

mysql> show variables like 'log_output';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | FILE  |
+---------------+-------+

mysql> set global log_output='TABLE';
Query OK, 0 rows affected (0.00 sec)

slow_log表的定义用的是CSV引擎,对大数据量下的查询效率可能不高,可以把slow_log表的引擎转换到MyISAM,并在start_time列上添加索引进一步提高查询的效率。

mysql> set global log_output='TABLE';
Query OK, 0 rows affected (0.00 sec)

mysql> alter table mysql.slow_log ENGINE=MyISAM;
Query OK, 28 rows affected (0.03 sec)
Records: 28  Duplicates: 0  Warnings: 0

4. pt-query-digest分析慢查询

下载地址:http://www.percona.com/software/percona-toolkit/
官方文档:http://www.percona.com/doc/percona-toolkit/pt-query-digest.html

$ tar xvfz percona-toolkit-2.2.10.tar.gz
$ cd percona-toolkit-2.2.10/bin
$ ./pt-query-digest /mysqldata1/mysql_3301_slow.log

----------------------摘要
# 240ms user time, 20ms system time, 20.30M rss, 126.37M vsz
# Current date: Thu Jul 31 22:11:22 2014
# Hostname: rhel5
# Files: /mysqldata1/mysql_3301_slow.log
# Overall: 237 total, 52 unique, 0.00 QPS, 0.00x concurrency _____________
# Time range: 2014-07-26 03:39:47 to 2014-07-31 21:23:43
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            14s   158us     12s    58ms    40ms   774ms   541us
# Lock time          263ms       0   105ms     1ms   467us     8ms   138us
# Rows sent          9.97k       0    1000   43.08  143.84  164.63    3.89
# Rows examine     133.08k       0  58.59k     575  174.84   5.19k    5.75
# Query size        22.51k       6     527   97.27  174.84   71.26   62.76

---------------------显示最慢的SQL
# Profile
# Rank Query ID           Response time Calls R/Call  V/M   Item
# ==== ================== ============= ===== ======= ===== ==============
#    1 0x813031B8BBC3B329 12.2729 88.7%     1 12.2729  0.00 COMMIT
#    2 0xD1CC9400998BBF7E  0.3997  2.9%     4  0.0999  0.20 SELECT test.t?
#    3 0xB7A49D9B500CFA2E  0.1929  1.4%    77  0.0025  0.07 SELECT information_schema.profiling
#    4 0x3F6C721C6C536887  0.1434  1.0%     2  0.0717  0.10 SELECT tpcc?.stock
#    5 0x1B3B30C35BC645CE  0.1067  0.8%     1  0.1067  0.00 SELECT information_schema.TABLES
#    6 0x4ED4D152955F2D44  0.0941  0.7%     1  0.0941  0.00 SELECT information_schema.TABLES
# MISC 0xMISC              0.6202  4.5%   151  0.0041   0.0 <46 ITEMS>

# Query 1: 0 QPS, 0x concurrency, ID 0x813031B8BBC3B329 at byte 60821 ____
# Scores: V/M = 0.00
# Time range: all events occurred at 2014-07-31 19:15:14
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0       1
# Exec time     88     12s     12s     12s     12s     12s       0     12s
# Lock time      0       0       0       0       0       0       0       0
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size     0       6       6       6       6       6       0       6
# String:
# Databases    tpcc100
# Hosts
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+  ################################################################

关于紫砂壶

感悟技术人生
此条目发表在MySQL分类目录,贴了标签。将固定链接加入收藏夹。