使用show profile分析单条查询

show profile命令是Mysql5.1版本中引入的，默认是禁用的，但可以通过服务器变量在会话级别动态地修改，下面是打开profile:

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

执行下show profile查看最近执行的查询情况:

mysql> show profiles;+----------+------------+--------------------------+| Query_ID | Duration   | Query                    |+----------+------------+--------------------------+|        1 | 0.00134600 | show tables              ||        2 | 0.01328775 | select * from AASC       ||        3 | 0.00020075 | select * from AAASTUDENT ||        4 | 0.00029550 | select * from AASTUDENT  ||        5 | 0.00019100 | select * from AATECHER   ||        6 | 0.00022300 | select * from AATEACHER  |+----------+------------+--------------------------+6 rows in set (0.00 sec)

从上面的结果可以看出，以很高的精度显示了查询时间
细信息查看，按下面的方式执行即可：

mysql> show profile for query 1;+----------------------+----------+| Status               | Duration |+----------------------+----------+| starting             | 0.000034 || checking permissions | 0.000006 || Opening tables       | 0.000012 || System lock          | 0.000005 || init                 | 0.000014 || optimizing           | 0.000003 || statistics           | 0.000008 || preparing            | 0.000005 || executing            | 0.000001 || Sending data         | 0.000077 || end                  | 0.000004 || query end            | 0.000003 || closing tables       | 0.000005 || freeing items        | 0.000043 || logging slow query   | 0.000003 || cleaning up          | 0.000002 |+----------------------+----------+16 rows in set (0.00 sec)

虽然详细，但是很难直接看出性能问题，加入不使用show profile命令，而是直接查询information_schema中对应的表，则可以按需格式化输出：

mysql> set @query_id = 1;Query OK, 0 rows affected (0.00 sec)

SELECT STATE    ,sum(duration) AS total_r    ,round(100 * sum(duration) / (            SELECT sum(duration)            FROM information_schemling            WHERE query_id = @query_id            ), 2) AS pct_r    ,count(*) AS calls    ,sum(duration) / count(*) AS "R/Call"FROM information_schema.profilingWHERE query_id = @query_idGROUP BY STATEORDER BY total_r DESC;

+----------------------+----------+-------+-------+--------------+| state                | total_r  | pct_r | calls | R/Call       |+----------------------+----------+-------+-------+--------------+| Sending data         | 0.000077 | 34.22 |     1 | 0.0000770000 || freeing items        | 0.000043 | 19.11 |     1 | 0.0000430000 || starting             | 0.000034 | 15.11 |     1 | 0.0000340000 || init                 | 0.000014 |  6.22 |     1 | 0.0000140000 || Opening tables       | 0.000012 |  5.33 |     1 | 0.0000120000 || statistics           | 0.000008 |  3.56 |     1 | 0.0000080000 || checking permissions | 0.000006 |  2.67 |     1 | 0.0000060000 || System lock          | 0.000005 |  2.22 |     1 | 0.0000050000 || preparing            | 0.000005 |  2.22 |     1 | 0.0000050000 || closing tables       | 0.000005 |  2.22 |     1 | 0.0000050000 || end                  | 0.000004 |  1.78 |     1 | 0.0000040000 || logging slow query   | 0.000003 |  1.33 |     1 | 0.0000030000 || query end            | 0.000003 |  1.33 |     1 | 0.0000030000 || optimizing           | 0.000003 |  1.33 |     1 | 0.0000030000 || cleaning up          | 0.000002 |  0.89 |     1 | 0.0000020000 || executing            | 0.000001 |  0.44 |     1 | 0.0000010000 |+----------------------+----------+-------+-------+--------------+16 rows in set (0.07 sec)

从上面的查询结果可以看出来，发送数据和释放索引消耗的时间较多，但这属于正常开销，如果以后执行复杂的SQL时，就会很具有分析价值了。