Explain

简介

MySQL 提供了一个 EXPLAIN 命令, 它可以对 SELECT 语句进行分析, 并输出 SELECT 执行的详细信息, 以供开发人员针对性优化.

EXPLAIN 命令用法十分简单, 在 SELECT 语句前加上 Explain 就可以了, 例如:

1	EXPLAIN SELECT * from user_info WHERE id < 300;

数据准备

CREATE TABLE `user_info` (
  `id` bigint(20) NOT NULL AUTO_INCREMENT,
  `name` varchar(50) NOT NULL DEFAULT '',
  `age` int(11) DEFAULT NULL,
  PRIMARY KEY (`id`),
  KEY `name_index` (`name`)
) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8;

INSERT INTO user_info (name, age) VALUES ('xys', 20);
INSERT INTO user_info (name, age) VALUES ('a', 21);
INSERT INTO user_info (name, age) VALUES ('b', 23);
INSERT INTO user_info (name, age) VALUES ('c', 50);
INSERT INTO user_info (name, age) VALUES ('d', 15);
INSERT INTO user_info (name, age) VALUES ('e', 20);
INSERT INTO user_info (name, age) VALUES ('f', 21);
INSERT INTO user_info (name, age) VALUES ('g', 23);
INSERT INTO user_info (name, age) VALUES ('h', 50);
INSERT INTO user_info (name, age) VALUES ('i', 15);

CREATE TABLE `order_info` (
  `id` bigint(20) NOT NULL AUTO_INCREMENT,
  `user_id` bigint(20) DEFAULT NULL,
  `product_name` varchar(50) NOT NULL DEFAULT '',
  `productor` varchar(30) DEFAULT NULL,
  PRIMARY KEY (`id`),
  KEY `user_product_detail_index` (`user_id`,`product_name`,`productor`)
) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8;

INSERT INTO order_info (user_id, product_name, productor) VALUES (1, 'p1', 'WHH');
INSERT INTO order_info (user_id, product_name, productor) VALUES (1, 'p2', 'WL');
INSERT INTO order_info (user_id, product_name, productor) VALUES (1, 'p1', 'DX');
INSERT INTO order_info (user_id, product_name, productor) VALUES (2, 'p1', 'WHH');
INSERT INTO order_info (user_id, product_name, productor) VALUES (2, 'p5', 'WL');
INSERT INTO order_info (user_id, product_name, productor) VALUES (3, 'p3', 'MA');
INSERT INTO order_info (user_id, product_name, productor) VALUES (4, 'p1', 'WHH');
INSERT INTO order_info (user_id, product_name, productor) VALUES (6, 'p1', 'WHH');
INSERT INTO order_info (user_id, product_name, productor) VALUES (9, 'p8', 'TE');

EXPLAIN 输出格式

mysql> explain select * from user_info where id = 2;
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
| id | select_type | table     | type  | possible_keys | key     | key_len | ref   | rows | Extra |
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
|  1 | SIMPLE      | user_info | const | PRIMARY       | PRIMARY | 8       | const |    1 |       |
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
1 row in set (0.00 sec)

各列的含义如下:

id: SELECT 查询的标识符. 每个 SELECT 都会自动分配一个唯一的标识符.
select_type: SELECT 查询的类型.
table: 表示查询涉及的表或衍生表
partitions: 匹配的分区
type: join 类型
possible_keys: 表示 MySQL 在查询时, 能够使用到的索引. 注意, 即使有些索引在 possible_keys 中出现, 但是并不表示此索引会真正地被 MySQL 使用到. MySQL 在查询时具体使用了哪些索引, 由 key 字段决定.
key: 此次查询中真正使用到的索引.
ref: 哪个字段或常数与 key 一起被使用
rows: MySQL查询优化器根据统计信息, 估算SQL要查找到结果集需要扫描读取的数据行数.
这个值非常直观显示 SQL 的效率好坏, 原则上 rows 越少越好.
filtered: 表示此查询条件所过滤的数据的百分比
extra: 额外的信息

参数说明

select_type

select_type 表示了查询的类型, 它的常用取值有:

SIMPLE, 表示此查询不包含 UNION 查询或子查询
PRIMARY, 表示此查询是最外层的查询
UNION, 表示此查询是 UNION 的第二个或随后的查询
DEPENDENT UNION, UNION 中的第二个或后面的查询语句, 取决于外面的查询
UNION RESULT, UNION 的结果
SUBQUERY, 子查询中的第一个 SELECT
DEPENDENT SUBQUERY: 子查询中的第一个 SELECT, 取决于外面的查询. 即子查询依赖于外层查询的结果.

最常见的查询类别应该是 SIMPLE 了, 比如当我们的查询没有子查询, 也没有 UNION 查询时, 那么通常就是 SIMPLE 类型, 例如:

mysql> explain select * from user_info where id = 2;
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
| id | select_type | table     | type  | possible_keys | key     | key_len | ref   | rows | Extra |
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
|  1 | SIMPLE      | user_info | const | PRIMARY       | PRIMARY | 8       | const |    1 |       |
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
1 row in set (0.00 sec)

如果我们使用了 UNION 查询, 那么 EXPLAIN 输出的结果类似如下:

mysql> EXPLAIN (SELECT * FROM user_info  WHERE id IN (1, 2, 3)) UNION (SELECT * FROM user_info WHERE id IN (3, 4, 5));
+----+--------------+------------+-------+---------------+---------+---------+------+------+-------------+
| id | select_type  | table      | type  | possible_keys | key     | key_len | ref  | rows | Extra       |
+----+--------------+------------+-------+---------------+---------+---------+------+------+-------------+
|  1 | PRIMARY      | user_info  | range | PRIMARY       | PRIMARY | 8       | NULL |    3 | Using where |
|  2 | UNION        | user_info  | range | PRIMARY       | PRIMARY | 8       | NULL |    3 | Using where |
| NULL | UNION RESULT | <union1,2> | ALL   | NULL   | NULL    | NULL    | NULL | NULL   |             |
+----+--------------+------------+-------+---------------+---------+---------+------+------+-------------+
3 rows in set (0.00 sec)

type

type 字段比较重要, 它提供了判断查询是否高效的重要依据依据. 通过 type 字段, 我们判断此次查询是 全表扫描 还是 索引扫描 等.

type 常用类型取值有:

system: 表中只有一条数据. 这个类型是特殊的 const 类型.

const: 针对主键或唯一索引的等值查询扫描, 最多只返回一行数据. const 查询速度非常快, 因为它仅仅读取一次即可.
例如下面的这个查询, 它使用了主键索引, 因此 type 就是 const 类型的.

mysql> explain select * from user_info where id = 2;
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
| id | select_type | table     | type  | possible_keys | key     | key_len | ref   | rows | Extra |
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
|  1 | SIMPLE      | user_info | const | PRIMARY       | PRIMARY | 8       | const |    1 |       |
+----+-------------+-----------+-------+---------------+---------+---------+-------+------+-------+
1 row in set (0.00 sec)

eq_ref: 此类型通常出现在多表的 join 查询, 表示对于前表的每一个结果, 都只能匹配到后表的一行结果. 并且查询的比较操作通常是 =, 查询效率较高. 例如:

mysql> EXPLAIN SELECT * FROM user_info, order_info WHERE user_info.id = order_info.user_id;
+----+-------------+------------+--------+---------------------------+---------------------------+---------+-------------------------+------+-------------+
| id | select_type | table      | type   | possible_keys             | key                       | key_len | ref                     | rows | Extra       |
+----+-------------+------------+--------+---------------------------+---------------------------+---------+-------------------------+------+-------------+
|  1 | SIMPLE      | order_info | index  | user_product_detail_index | user_product_detail_index | 254     | NULL                    |    9 | Using index |
|  1 | SIMPLE      | user_info  | eq_ref | PRIMARY                   | PRIMARY                   | 8       | test.order_info.user_id |    1 |             |
+----+-------------+------------+--------+---------------------------+---------------------------+---------+-------------------------+------+-------------+
2 rows in set (0.00 sec)

ref: 此类型通常出现在多表的 join 查询, 针对于非唯一或非主键索引, 或者是使用了 最左前缀 规则索引的查询.
例如下面这个例子中, 就使用到了 ref 类型的查询:

mysql> EXPLAIN SELECT * FROM user_info, order_info WHERE user_info.id = order_info.user_id AND order_info.user_id = 5; 
+----+-------------+------------+-------+---------------------------+---------------------------+---------+-------+------+--------------------------+
| id | select_type | table      | type  | possible_keys             | key                       | key_len | ref   | rows | Extra                    |
+----+-------------+------------+-------+---------------------------+---------------------------+---------+-------+------+--------------------------+
|  1 | SIMPLE      | user_info  | const | PRIMARY                   | PRIMARY                   | 8       | const |    1 |                          |
|  1 | SIMPLE      | order_info | ref   | user_product_detail_index | user_product_detail_index | 9       | const |    1 | Using where; Using index |
+----+-------------+------------+-------+---------------------------+---------------------------+---------+-------+------+--------------------------+
2 rows in set (0.01 sec)

range: 表示使用索引范围查询, 通过索引字段范围获取表中部分数据记录. 这个类型通常出现在 =, <>, >, >=, <, <=, IS NULL, <=>, BETWEEN, IN() 操作中.

当 type 是 range 时, 那么 EXPLAIN 输出的 ref 字段为 NULL, 并且 key_len 字段是此次查询中使用到的索引的最长的那个.

    mysql> EXPLAIN SELECT * FROM user_info WHERE id BETWEEN 2 AND 8;
+----+-------------+-----------+-------+---------------+---------+---------+------+------+-------------+
| id | select_type | table     | type  | possible_keys | key     | key_len | ref  | rows | Extra       |
+----+-------------+-----------+-------+---------------+---------+---------+------+------+-------------+
|  1 | SIMPLE      | user_info | range | PRIMARY       | PRIMARY | 8       | NULL |    7 | Using where |
+----+-------------+-----------+-------+---------------+---------+---------+------+------+-------------+

index: 表示全索引扫描(full index scan), 和 ALL 类型类似, 只不过 ALL 类型是全表扫描, 而 index 类型则仅仅扫描所有的索引, 而不扫描数据.

index 类型通常出现在: 所要查询的数据直接在索引树中就可以获取到, 而不需要扫描数据. 当是这种情况时, Extra 字段会显示 Using index.例如:

    mysql> EXPLAIN SELECT name FROM  user_info;
+----+-------------+-----------+-------+---------------+------------+---------+------+------+-------------+
| id | select_type | table     | type  | possible_keys | key        | key_len | ref  | rows | Extra       |
+----+-------------+-----------+-------+---------------+------------+---------+------+------+-------------+
|  1 | SIMPLE      | user_info | index | NULL          | name_index | 152     | NULL |   10 | Using index |
+----+-------------+-----------+-------+---------------+------------+---------+------+------+-------------+

上面的例子中, 我们查询的 name 字段恰好是一个索引, 因此我们直接从索引中获取数据就可以满足查询的需求了, 而不需要查询表中的数据. 因此这样的情况下, type 的值是 index, 并且 Extra 的值是 Using index.

ALL: 表示全表扫描, 这个类型的查询是性能最差的查询之一. 通常来说, 我们的查询不应该出现 ALL 类型的查询, 因为这样的查询在数据量大的情况下, 对数据库的性能是巨大的灾难. 如一个查询是 ALL 类型查询, 那么一般来说可以对相应的字段添加索引来避免.

下面是一个全表扫描的例子, 可以看到, 在全表扫描时, possible_keys 和 key 字段都是 NULL, 表示没有使用到索引, 并且 rows 十分巨大, 因此整个查询效率是十分低下的.

    mysql> EXPLAIN SELECT age FROM  user_info WHERE age = 20;
+----+-------------+-----------+------+---------------+------+---------+------+------+-------------+
| id | select_type | table     | type | possible_keys | key  | key_len | ref  | rows | Extra       |
+----+-------------+-----------+------+---------------+------+---------+------+------+-------------+
|  1 | SIMPLE      | user_info | ALL  | NULL          | NULL | NULL    | NULL |   10 | Using where |
+----+-------------+-----------+------+---------------+------+---------+------+------+-------------+

type 类型的性能比较

通常来说, 不同的 type 类型的性能关系如下:

ALL < index < range ~ index_merge < ref < eq_ref < const < system

ALL 类型因为是全表扫描, 因此在相同的查询条件下, 它是速度最慢的.

而 index 类型的查询虽然不是全表扫描, 但是它扫描了所有的索引, 因此比 ALL 类型的稍快.

后面的几种类型都是利用了索引来查询数据, 因此可以过滤部分或大部分数据, 因此查询效率就比较高了.

key_len

表示查询优化器使用了索引的字节数. 这个字段可以评估组合索引是否完全被使用, 或只有最左部分字段被使用到.
key_len 的计算规则如下:

字符串
- char(n): n字节长度
- varchar(n): 如果是 utf8 编码, 则是 (3n + 2) 字节; 如果是 utf8mb4 编码, 则是 (4n + 2）字节.
数值类型:
- TINYINT: 1字节
- SMALLINT: 2字节
- MEDIUMINT: 3字节
- INT: 4字节
- BIGINT: 8字节
时间类型
- DATE: 3字节
- TIMESTAMP: 4字节
- DATETIME: 8字节
字段属性: NULL 属性占用一个字节. 如果一个字段是 NOT NULL 的, 则没有此属性.

我们来举两个简单的例子:

mysql> EXPLAIN SELECT * FROM order_info WHERE user_id < 3 AND product_name = 'p1' AND productor = 'WHH';
+----+-------------+------------+-------+---------------------------+---------------------------+---------+------+------+--------------------------+
| id | select_type | table      | type  | possible_keys             | key                       | key_len | ref  | rows | Extra                    |
+----+-------------+------------+-------+---------------------------+---------------------------+---------+------+------+--------------------------+
|  1 | SIMPLE      | order_info | range | user_product_detail_index | user_product_detail_index | 9       | NULL |    4 | Using where; Using index |
+----+-------------+------------+-------+---------------------------+---------------------------+---------+------+------+--------------------------+

上面的例子是从表 order_info 中查询指定的内容, 而我们从此表的建表语句中可以知道, 表 order_info 有一个联合索引:

KEY user_product_detail_index (user_id, product_name, productor)

不过此查询语句 WHERE user_id < 3 AND product_name = 'p1' AND productor = 'WHH' 中, 因为先进行 user_id 的范围查询, 而根据最左前缀匹配原则, 当遇到范围查询时, 就停止索引的匹配, 因此实际上我们使用到的索引的字段只有 user_id, 因此在 EXPLAIN 中, 显示的 key_len 为 9.

因为 user_id 字段是 BIGINT, 占用 8 字节, 而 NULL 属性占用一个字节, 因此总共是 9 个字节. 若我们将user_id 字段改为 BIGINT(20) NOT NULL DEFAULT ‘0’, 则 key_length 应该是8.

上面因为最左前缀匹配原则, 我们的查询仅仅使用到了联合索引的 user_id 字段, 因此效率不算高.

接下来我们来看一下下一个例子:

mysql> EXPLAIN SELECT * FROM order_info WHERE user_id = 1 AND product_name = 'p1';
+----+-------------+------------+------+---------------------------+---------------------------+---------+-------------+------+--------------------------+
| id | select_type | table      | type | possible_keys             | key                       | key_len | ref         | rows | Extra                    |
+----+-------------+------------+------+---------------------------+---------------------------+---------+-------------+------+--------------------------+
|  1 | SIMPLE      | order_info | ref  | user_product_detail_index | user_product_detail_index | 161     | const,const |    2 | Using where; Using index |
+----+-------------+------------+------+---------------------------+---------------------------+---------+-------------+------+--------------------------+

这次的查询中, 我们没有使用到范围查询, key_len 的值为 161. 为什么呢?

因为我们的查询条件 WHERE user_id = 1 AND product_name = 'p1' 中, 仅仅使用到了联合索引中的前两个字段, 因此 keyLen(user_id) + keyLen(product_name) = 9 + 50 * 3 + 2 = 161

Extra

EXplain 中的很多额外的信息会在 Extra 字段显示, 常见的有以下几种内容:

Using filesort
当 Extra 中有 Using filesort 时, 表示 MySQL 需额外的排序操作, 不能通过索引顺序达到排序效果. 一般有 Using filesort, 都建议优化去掉, 因为这样的查询 CPU 资源消耗大.

例如下面的例子:

    mysql> EXPLAIN SELECT * FROM order_info ORDER BY product_name;
+----+-------------+------------+-------+---------------+---------------------------+---------+------+------+-----------------------------+
| id | select_type | table      | type  | possible_keys | key                       | key_len | ref  | rows | Extra                       |
+----+-------------+------------+-------+---------------+---------------------------+---------+------+------+-----------------------------+
|  1 | SIMPLE      | order_info | index | NULL          | user_product_detail_index | 254     | NULL |    9 | Using index; Using filesort |
+----+-------------+------------+-------+---------------+---------------------------+---------+------+------+-----------------------------+

我们的索引是

KEY user_product_detail_index (user_id, product_name, productor)

但是上面的查询中根据 product_name 来排序, 因此不能使用索引进行优化, 进而会产生 Using filesort.
如果我们将排序依据改为 ORDER BY user_id, product_name, 那么就不会出现 Using filesort 了. 例如:

mysql> EXPLAIN SELECT * FROM order_info ORDER BY user_id, product_name;
+----+-------------+------------+-------+---------------+---------------------------+---------+------+------+-------------+
| id | select_type | table      | type  | possible_keys | key                       | key_len | ref  | rows | Extra       |
+----+-------------+------------+-------+---------------+---------------------------+---------+------+------+-------------+
|  1 | SIMPLE      | order_info | index | NULL          | user_product_detail_index | 254     | NULL |    9 | Using index |
+----+-------------+------------+-------+---------------+---------------------------+---------+------+------+-------------+

Using index
“覆盖索引扫描”, 表示查询在索引树中就可查找所需数据, 不用扫描表数据文件, 往往说明性能不错
Using temporary
查询有使用临时表, 一般出现于排序, 分组和多表 join 的情况, 查询效率不高, 建议优化.

Profiling

简介

当我们要对某一条sql的性能进行分析时，可以使用它。

Profiling是从 mysql5.0.3版本以后才开放的。
启动profile之后，所有查询包括错误的语句都会记录在内。
关闭会话或者set profiling=0 就关闭了。（如果将profiling_history_size参数设置为0，同样具有关闭MySQL的profiling效果。）

此工具可用来查询SQL执行状态，System lock和Table lock 花多少时间等等，

对定位一条语句的I/O、CPU、IPC，Memory消耗非常重要。(SQL 语句执行所消耗的最大两部分资源就是IO和CPU)

在mysql5.7之后，profile信息将逐渐被废弃，mysql推荐使用performance schema

用法

简易流程大概如下：

set profiling=1;  	//打开分析，默认值为0（off），可以通过设置profiling为1或ON开启
 
run your sql1;
 
run your sql2;
 
show profiles;			//查看sql1, sql2的语句分析
 
show profile for query 1;	//查看sql1的具体分析
 
show profile ALL for query 1;	//查看sql1相关的所有分析【主要看i/o与cpu,下边分析中有各项意义介绍】

set profiling=0;  		//关闭分析

语法：

1
2
3

SHOW PROFILE [type [, type] ... ]
   [FOR QUERY n]
   [LIMIT row_count [OFFSET offset]]

type:

ALL | BLOCK IO | CONTEXT SWITCHES | CPU | IPC | MEMORY | PAGE FAULTS | SOURCE | SWAPS

SOURCE：显示和Source_function,Source_file,Source_line相关的开销信息

注意：profiling被应用在每一个会话中，当前会话关闭后，profiling统计的信息将丢失。

实例：

mysql> show variables like '%profil%';   ## 查看mysql profiling相关配置
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| have_profiling         | YES   |
| profiling              | OFF   | ## 是否开启
| profiling_history_size | 15    | ## 记录历史条数
+------------------------+-------+
3 rows in set (0.00 sec)

mysql> set profiling = ON;  ## 开启分析
Query OK, 0 rows affected (0.01 sec)

mysql> show variables like '%profil%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| have_profiling         | YES   |
| profiling              | ON    |
| profiling_history_size | 15    |
+------------------------+-------+
3 rows in set (0.00 sec)

mysql> show tables;                   
+-------------------------------------+
| Tables_in_bigdata_new               |
+-------------------------------------+
| TblDataShoppingRecord               |
| TblDataViewRecord                   |
| TblEmailNotifyRecord                |
+-------------------------------------+
3 rows in set (0.00 sec)

mysql> select * from TblDataShoppingRecord order by id desc limit 1\G;
*************************** 1. row ***************************
                id: 1263
            status: off
              name: mapdata_meta_27
           creator: zhangsan
        createTime: 2019-10-08 15:20:20
1 row in set (0.00 sec)

ERROR: 
No query specified

mysql> select * from TblDataShoppingRecord where creator = 'austin' order by id desc limit 1\G;
*************************** 1. row ***************************
                id: 1285
            status: off
              name: metadata_30
           creator: austin
        createTime: 2019-10-08 15:20:20
1 row in set (0.01 sec)

ERROR: 
No query specified

mysql> show profiles;
+----------+------------+---------------------------------------------------------------------------------------------+
| Query_ID | Duration   | Query                                                                                       |
+----------+------------+---------------------------------------------------------------------------------------------+
|        1 | 0.00045400 | show variables like '%profil%'                                                              |
|        2 | 0.00086200 | show tables                                                                                 |
|        3 | 0.00034900 | select * from TblDataShoppingRecord order by id desc limit 1                                |
|        4 | 0.00040000 | select * from TblDataShoppingRecord where creator = 'austin' order by id desc limit 1       |
+----------+------------+---------------------------------------------------------------------------------------------+
4 rows in set (0.00 sec)

mysql> show profile for query 4;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.000039 |
| checking query cache for query | 0.000052 |
| Opening tables                 | 0.000015 |
| System lock                    | 0.000005 |
| Table lock                     | 0.000037 |
| init                           | 0.000031 |
| optimizing                     | 0.000009 |
| statistics                     | 0.000073 |
| preparing                      | 0.000016 |
| executing                      | 0.000005 |
| Sorting result                 | 0.000006 |
| Sending data                   | 0.000050 |
| end                            | 0.000007 |
| query end                      | 0.000004 |
| freeing items                  | 0.000027 |
| storing result in query cache  | 0.000015 |
| logging slow query             | 0.000004 |
| cleaning up                    | 0.000005 |
+--------------------------------+----------+
18 rows in set (0.00 sec)

mysql> show profile cpu for query 4;
+--------------------------------+----------+----------+------------+
| Status                         | Duration | CPU_user | CPU_system |
+--------------------------------+----------+----------+------------+
| starting                       | 0.000039 | 0.000000 |   0.000000 |
| checking query cache for query | 0.000052 | 0.000000 |   0.000000 |
| Opening tables                 | 0.000015 | 0.000000 |   0.000000 |
| System lock                    | 0.000005 | 0.000000 |   0.000000 |
| Table lock                     | 0.000037 | 0.000000 |   0.000000 |
| init                           | 0.000031 | 0.000000 |   0.000000 |
| optimizing                     | 0.000009 | 0.000000 |   0.000000 |
| statistics                     | 0.000073 | 0.000000 |   0.000000 |
| preparing                      | 0.000016 | 0.000000 |   0.000000 |
| executing                      | 0.000005 | 0.000000 |   0.000000 |
| Sorting result                 | 0.000006 | 0.000000 |   0.000000 |
| Sending data                   | 0.000050 | 0.000000 |   0.000000 |
| end                            | 0.000007 | 0.000000 |   0.000000 |
| query end                      | 0.000004 | 0.000000 |   0.000000 |
| freeing items                  | 0.000027 | 0.000000 |   0.000000 |
| storing result in query cache  | 0.000015 | 0.000000 |   0.000000 |
| logging slow query             | 0.000004 | 0.000000 |   0.000000 |
| cleaning up                    | 0.000005 | 0.000000 |   0.000000 |
+--------------------------------+----------+----------+------------+
18 rows in set (0.00 sec)

mysql> show profile BLOCK IO, CPU, IPC, MEMORY, SOURCE, SWAPS  for query 4;   
+--------------------------------+----------+----------+------------+--------------+---------------+---------------+-------------------+-------+------------------+---------------+-------------+
| Status                         | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | Messages_sent | Messages_received | Swaps | Source_function  | Source_file   | Source_line |
+--------------------------------+----------+----------+------------+--------------+---------------+---------------+-------------------+-------+------------------+---------------+-------------+
| starting                       | 0.000039 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | NULL             | NULL          |        NULL |
| checking query cache for query | 0.000052 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_cache.cc  |        1523 |
| Opening tables                 | 0.000015 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_base.cc   |        4618 |
| System lock                    | 0.000005 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | lock.cc       |         260 |
| Table lock                     | 0.000037 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | lock.cc       |         271 |
| init                           | 0.000031 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_select.cc |        2528 |
| optimizing                     | 0.000009 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_select.cc |         833 |
| statistics                     | 0.000073 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_select.cc |        1024 |
| preparing                      | 0.000016 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_select.cc |        1046 |
| executing                      | 0.000005 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_select.cc |        1780 |
| Sorting result                 | 0.000006 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_select.cc |        2205 |
| Sending data                   | 0.000050 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_select.cc |        2338 |
| end                            | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_select.cc |        2574 |
| query end                      | 0.000004 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_parse.cc  |        5118 |
| freeing items                  | 0.000027 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_parse.cc  |        6142 |
| storing result in query cache  | 0.000015 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_cache.cc  |         985 |
| logging slow query             | 0.000004 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_parse.cc  |        1735 |
| cleaning up                    | 0.000005 | 0.000000 |   0.000000 |            0 |             0 |             0 |                 0 |     0 | unknown function | sql_parse.cc  |        1703 |
+--------------------------------+----------+----------+------------+--------------+---------------+---------------+-------------------+-------+------------------+---------------+-------------+
18 rows in set (0.00 sec)

mysql> set profiling=0;
Query OK, 0 rows affected (0.00 sec)

mysql> show variables like '%profil%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| have_profiling         | YES   |
| profiling              | OFF   |
| profiling_history_size | 15    |
+------------------------+-------+
3 rows in set (0.00 sec)

结果参数说明

其中标题含义：

"Status": "query end",  状态
"Duration": "1.751142", 持续时间
"CPU_user": "0.008999", cpu用户
"CPU_system": "0.003999", cpu系统
"Context_voluntary": "98", 上下文主动切换
"Context_involuntary": "0", 上下文被动切换
"Block_ops_in": "8", 阻塞的输入操作
"Block_ops_out": "32", 阻塞的输出操作
"Messages_sent": "0", 消息发出
"Messages_received": "0", 消息接受
"Page_faults_major": "0", 主分页错误
"Page_faults_minor": "0", 次分页错误
"Swaps": "0", 交换次数
"Source_function": "mysql_execute_command", 源功能
"Source_file": "sql_parse.cc", 源文件
"Source_line": "4465" 源代码行

不同阶段：

starting：开始
checking permissions：检查权限
Opening tables：打开表
init ： 初始化
System lock ：系统锁
optimizing ： 优化
statistics ： 统计
preparing ：准备
executing ：执行
Sending data ：发送数据
Sorting result ：排序
end ：结束
query end ：查询 结束
closing tables ： 关闭表 ／去除TMP 表
freeing items ： 释放物品
cleaning up ：清理

配置

显示的记录数由变量“profiling_history_size”控制,默认15条，最大值为100，可以手动设置该参数值。


mysql> set profiling_history_size = 30;  
Query OK, 0 rows affected (0.01 sec)

mysql> show variables like '%profil%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| have_profiling         | YES   |
| profiling              | OFF   |
| profiling_history_size | 30    |
+------------------------+-------+
3 rows in set (0.00 sec)

参考博客

[1] MySQL 性能优化神器 Explain 使用分析
[2] Mysql分析-profile详解
[3] MySQL性能分析工具profiling