mysql show profiles使用分析sql性能

 

Show profiles是5.0.37之后添加的，要想使用此功能，要确保版本在5.0.37之后。

 

查看一下我的数据库版本

mysql> Select  version();

+---------------------+

| version()           |

+---------------------+

| 5.0.82-community-nt |

+---------------------+

  www.2cto.com  

1 row in set (0.00 sec)

 

版本是支持show profiles功能的。接下来进入mysql性能跟踪诊断的世界

 

查看是否打开了profiles功能,默认是关闭的

 

mysql> use test;

 

Database changed

 

mysql> show profiles;

 

Empty set (0.00 sec)

 

显示为空，说明profiles功能是关闭的。下面开启

 

mysql> set profiling=1;

 

Query OK, 0 rows affected (0.00 sec)

 

执行下面的查询

  www.2cto.com  

mysql> explain select distinct player_idfrom task limit 20;

 

mysql> select distinct player_id from task ;

 

然后执行 show profiles

 

mysql> show profiles;

 

+----------+------------+------------------------------------------------------+

 

| Query_ID | Duration   | Query                                               |

 

+----------+------------+------------------------------------------------------+

 

|       1 | 0.00035225 | explain select distinct player_id from task limit 20 |

 

|       2 | 1.91772775 | select distinct player_id from task                  |

 

+----------+------------+------------------------------------------------------+

 

此时可以看到执行select distinct player_id from task 用了1.91772775秒的时间

 

根据query_id 查看某个查询的详细时间耗费

 

mysql> show profile for query 2;

  www.2cto.com  

+----------------------+----------+

 

| Status               | Duration |

 

+----------------------+----------+

 

| starting             | 0.000052 |

 

| Opening tables       | 0.000009 |

 

| System lock          | 0.000003 |

 

| Table lock           | 0.000007 |

 

| init                 | 0.000013 |

 

| optimizing           | 0.000003 |

 

| statistics           | 0.000009 |

 

| preparing            | 0.000008 |

 

| Creating tmp table   | 0.000074 |

 

| executing            | 0.000002 |

 

| Copying to tmp table |1.916551 |

  www.2cto.com  

| Sending data         | 0.000667 |

 

| end                  | 0.000004 |

 

| removing tmp table   | 0.000065 |

 

| end                  | 0.000002 |

 

| end                  | 0.000002 |

 

| query end            | 0.000003 |

 

| freeing items        | 0.000245 |

 

| closing tables       | 0.000006 |

 

| logging slow query   | 0.000002 |

 

| cleaning up          | 0.000003 |

 

+----------------------+----------+

 

可以看到红色字体部分耗费了大量时间，这是因为distinct查看会用到临时表

 

那么可不可以查看占用cpu、 io等信息呢

 

 mysql> show profile block io,cpu for query2;

 

+----------------------+----------+----------+------------+--------------+------

 

---------+

 

| Status               | Duration | CPU_user |CPU_system | Block_ops_in | Block

 

_ops_out |

 

+----------------------+----------+----------+------------+--------------+------

  www.2cto.com  

---------+

 

| starting             | 0.000052 |     NULL |       NULL |         NULL |

 

   NULL |

 

| Opening tables       | 0.000009 |     NULL |       NULL |         NULL |

 

   NULL |

 

| System lock          | 0.000003 |     NULL |       NULL |         NULL |

 

   NULL |

 

| Table lock           | 0.000007 |     NULL |       NULL |         NULL |

 

   NULL |

 

| init                 | 0.000013 |     NULL |       NULL |         NULL |

 

   NULL |

 

| optimizing           | 0.000003 |     NULL |       NULL |         NULL |

 

   NULL |

 

| statistics           | 0.000009 |     NULL |       NULL |         NULL |

 

   NULL |  www.2cto.com  

 

| preparing            | 0.000008 |     NULL |       NULL |        NULL |

 

   NULL |

 

| Creating tmp table   | 0.000074 |     NULL |       NULL |         NULL |

 

   NULL |

 

| executing            | 0.000002 |     NULL |       NULL |         NULL |

 

   NULL |

 

| Copying to tmp table | 1.916551 |     NULL |       NULL |        NULL |

 

   NULL |

 

| Sending data         | 0.000667 |     NULL |       NULL |         NULL |

 

   NULL |

 

| end                  | 0.000004 |     NULL |       NULL |         NULL |

 

   NULL |

 

| removing tmp table   | 0.000065 |     NULL |       NULL |         NULL |

 

   NULL |

 

| end                  | 0.000002 |     NULL |       NULL |         NULL |

 

   NULL |

 

| end                  | 0.000002 |     NULL |       NULL |         NULL |

 

   NULL |

 

| query end            | 0.000003 |     NULL |       NULL |         NULL |

 

   NULL |

 

| freeing items        | 0.000245 |     NULL |       NULL |         NULL |

 

   NULL |

 

| closing tables       | 0.000006 |     NULL |       NULL |         NULL |

 

   NULL |

  www.2cto.com  

| logging slow query   | 0.000002 |     NULL |       NULL |         NULL |

 

   NULL |

 

| cleaning up          | 0.000003 |     NULL |       NULL |         NULL |

 

   NULL |

 

+----------------------+----------+----------+------------+--------------+------

另外还可以看到memory,swaps,context switches,source 等信息