发现瓶颈 - Profiling(程序剖析) - SHOW PROFILE

SHOW PROFILE

show profile是由Jeremy Cole捐献给MySQL社区版本的。默认的是关闭的，但是会话级别可以开启这个功能。开启它可以让MySQL收集在执行语句的时候所使用的资源。为了统计报表,把profiling设为1

 

mysql> SET profiling = 1;

 

之后在运行一个查询

mysql> SELECT COUNT(DISTINCT actor.first_name) AS cnt_name, COUNT(*) AS cnt

-> FROM sakila.film_actor

-> INNER JOIN sakila.actor USING(actor_id)

-> GROUP BY sakila.film_actor.film_id

-> ORDER BY cnt_name DESC;

...

997 rows in set (0.03 sec)

 

这个执行语句的剖析信息存储在这个会话中。使用SHOW PROFILES进行查看。

mysql> SHOW PROFILES\G

*************************** 1. row ***************************

Query_ID: 1

Duration: 0.02596900

Query: SELECT COUNT(DISTINCT actor.first_name) AS cnt_name,...

 

你可以使用SHOW PROFILE语句来获取已经存储的剖析数据。如果不加参数，会显示状态以及它们持续的时间。

mysql> SHOW PROFILE;

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

| Status | Duration |

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

| (initialization) | 0.000005 |

| Opening tables | 0.000033 |

| System lock | 0.000037 |

| Table lock | 0.000024 |

| init | 0.000079 |

| optimizing | 0.000024 |

| statistics | 0.000079 |

| preparing | 0.00003 |

| Creating tmp table | 0.000124 |

| executing | 0.000008 |

| Copying to tmp table | 0.010048 |

| Creating sort index | 0.004769 |

| Copying to group table | 0.0084880 |

| Sorting result | 0.001136 |

| Sending data | 0.000925 |

| end | 0.00001 |

| removing tmp table | 0.00004 |

| end | 0.000005 |

| removing tmp table | 0.00001 |

| end | 0.000011 |

| query end | 0.00001 |

| freeing items | 0.000025 |

| removing tmp table | 0.00001 |

| freeing items | 0.000016 |

| closing tables | 0.000017 |

| logging slow query | 0.000006 |

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

 

每行都是状态变化的过程以及它们持续的时间。Status那一列和SHOW FULL PROCESSLIST的State应该是一致的。

这个值是来自于thd->proc_info变量。因此你所查看的这个值是直接来自MySQL内部的。尽管这些数值是比较直接易懂的，你也可以查看MySQL手册。

 

你可以给SHOW PROFILES指定一个Query_ID来查看指定的语句，还可以给输出添加新的列。如，查看用户和CPU使用。可以用如下命令。

 

mysql> SHOW PROFILE CPU FOR QUERY 1;

 

SHOW PROFILE可以深入的查看服务器执行语句的工作情况。以及也能帮助你理解执行语句消耗时间的情况。一些限制是它没有实现的功能，不能查看和剖析其他连接的语句，以及剖析时所引起的消耗。