将 MySQL’s SHOW PROFILES 命令的结果转成适合阅读的格式

红薯 发布于 2012/02/21 15:11
阅读 599
收藏 3

SHOW PROFILES 命令用来显示 MySQL 执行一个 SQL 查询的各个阶段所耗费的时间,但其显示的格式不太友好,难以阅读和理解。

下面是一个普通的 SHOW PROFILES 的执行方法和执行结果:

mysql> SET profiling=1;
mysql> pager cat > /dev/null
mysql> SELECT * FROM nicer_but_slower_film_list;
997 rows in set (0.18 sec)

查询耗费 0.18 秒,但时间主要花在哪呢?不知道!

mysql> SHOW PROFILE FOR QUERY 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000032 |
| checking permissions | 0.000005 |
... snip ...
| init                 | 0.000021 |
| optimizing           | 0.000003 |
| statistics           | 0.000006 |
| cleaning up          | 0.000003 |
+----------------------+----------+
35 rows in set (0.00 sec)

上述结果是按照执行的顺序显示的,而不是按照所耗费的时间排序,为此我们编写一个 SQL 用来显示更友好的 PROFILE 结果:

SET @query_id := 1;
SELECT STATE, SUM(DURATION) AS Total_R,
       ROUND(
          100 * SUM(DURATION) /
             (SELECT SUM(DURATION)
              FROM INFORMATION_SCHEMA.PROFILING
              WHERE QUERY_ID = @query_id
          ), 2) AS Pct_R,
       COUNT(*) AS Calls,
       SUM(DURATION) / COUNT(*) AS "R/Call"
    FROM INFORMATION_SCHEMA.PROFILING
    WHERE QUERY_ID = @query_id
    GROUP BY STATE
    ORDER BY Total_R DESC; 

运行结果:

+----------------------+----------+-------+-------+--------------+
| STATE                | Total_R  | Pct_R | Calls | R/Call       |
+----------------------+----------+-------+-------+--------------+
| removing tmp table   | 0.095135 | 55.10 |     3 | 0.0317116667 |
| Copying to tmp table | 0.046175 | 26.74 |     1 | 0.0461750000 |
| Sending data         | 0.018478 | 10.70 |     3 | 0.0061593333 |
| Sorting result       | 0.011090 |  6.42 |     1 | 0.0110900000 |
| checking permissions | 0.000802 |  0.46 |     6 | 0.0001336667 |
| Creating tmp table   | 0.000548 |  0.32 |     1 | 0.0005480000 |
| Opening tables       | 0.000196 |  0.11 |     1 | 0.0001960000 |
| statistics           | 0.000071 |  0.04 |     2 | 0.0000355000 |
| starting             | 0.000032 |  0.02 |     1 | 0.0000320000 |
| freeing items        | 0.000027 |  0.02 |     2 | 0.0000135000 |
| preparing            | 0.000025 |  0.01 |     2 | 0.0000125000 |
| init                 | 0.000021 |  0.01 |     1 | 0.0000210000 |
| optimizing           | 0.000020 |  0.01 |     2 | 0.0000100000 |
| closing tables       | 0.000014 |  0.01 |     2 | 0.0000070000 |
| System lock          | 0.000010 |  0.01 |     1 | 0.0000100000 |
| query end            | 0.000003 |  0.00 |     1 | 0.0000030000 |
| cleaning up          | 0.000003 |  0.00 |     1 | 0.0000030000 |
| executing            | 0.000002 |  0.00 |     2 | 0.0000010000 |
| end                  | 0.000002 |  0.00 |     1 | 0.0000020000 |
| logging slow query   | 0.000001 |  0.00 |     1 | 0.0000010000 |
+----------------------+----------+-------+-------+--------------+

是不是直观很多呢?从这个结果中你可以清楚的了解到临时表的处理占用了最多时间。

via mysqlperformanceblog

加载中
0
aeoluspu
aeoluspu

其中 一步 

返回到原来状态

mysql> pager

返回顶部
顶部