MySQL之profiling性能分析(在5.6.14版本被丢弃)

官方建议使用information_schema.profiling

原因是show profile 输出了查询执行的每个步骤及其花费的时间,但是结果很难快速确定哪个步骤花费的时间最多,因为输出是按照执行顺序排序的,而不是按花费的时间排序—-而时间上我们更关心的是花费了多少时间。

 

 

通过 Query Profiler 来定位一条 Query 的性能瓶颈,这里我们再详细介绍一下 Profiling 的用途及使用方法。

 

要想优化一条 Query,我们就需要清楚的知道这条 Query 的性能瓶颈到底在哪里,

是消耗的 CPU计算太多?

还是需要的的 IO 操作太多?

要想能够清楚的了解这些信息,在 MySQL 5.0 和 MySQL 5.1正式版中已经可以非常容易做到了,那就是通过 Query Profiler 功能。

 

MySQL 的 Query Profiler 是一个使用非常方便的 Query 诊断分析工具。

通过该工具可以获取一条Query 在整个执行过程中多种资源的消耗情况,如 CPU,IO,IPC,SWAP 等,以及发生的 PAGE FAULTS,CONTEXT SWITCHE 等等,同时还能得到该 Query 执行过程中 MySQL 所调用的各个函数在源文件中的位置。

 

下面我们看看 Query Profiler 的具体用法。

 

1、 开启 profiling 参数

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

通过执行 “set profiling”命令,可以开启关闭 Query Profiler 功能。

 

2、 执行 Query

mysql> select * from users;
+----+--------+-----+-----+---------------------+---------------------+
| id | name   | sex | age | created_at          | updated_at          |
+----+--------+-----+-----+---------------------+---------------------+
|  1 | 李四       | 男    |  20 | 2019-04-25 12:59:01 | 2019-04-25 12:59:01 |
|  2 | 李老四       | 女   |  60 | 2019-04-25 12:59:15 | 2019-04-25 12:59:15 |
|  3 | 李老五       | 女   |  70 | 2019-04-25 12:59:26 | 2019-04-25 12:59:26 |
|  4 | 王老四       | 女   |  70 | 2019-04-25 12:59:40 | 2019-04-25 12:59:40 |
|  5 | 王老五       | 男    |  90 | 2019-04-25 12:59:52 | 2019-04-25 12:59:52 |
|  6 | 刘老七       | 男    |  20 | 2019-04-25 13:00:07 | 2019-04-25 13:00:07 |
+----+--------+-----+-----+---------------------+---------------------+
6 rows in set (0.01 sec)

在开启 Query Profiler 功能之后,MySQL 就会自动记录所有执行的 Query 的 profile 信息了。

 

3、获取系统中保存的所有 Query 的 profile 概要信息

mysql> show profiles;
+----------+------------+---------------------+
| Query_ID | Duration   | Query               |
+----------+------------+---------------------+
|        1 | 0.00103400 | SELECT DATABASE()   |
|        2 | 0.00019200 | select * from users |
|        3 | 0.00011100 | set names gbk       |
|        4 | 0.00668550 | select * from users |
+----------+------------+---------------------+
4 rows in set (0.00 sec)

通过执行 “SHOW PROFILE” 命令获取当前系统中保存的多个 Query 的 profile 的概要信息。

可以看到MySQL为每一个操作生成了一个Query_ID,我们可以使用show profile for query 1这样的形式来查看第一条语句具体的执行过程分析。

 

4、针对单个 Query 获取详细的 profile 信息。


在获取到概要信息之后,我们就可以根据概要信息中的 Query_ID 来获取某个 Query 在执行过程中

详细的 profile 信息了,具体操作如下:

mysql> show profile for query 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000481 |
| checking permissions | 0.000005 |
| Opening tables       | 0.000004 |
| init                 | 0.000184 |
| optimizing           | 0.000006 |
| executing            | 0.000226 |
| end                  | 0.000004 |
| query end            | 0.000001 |
| closing tables       | 0.000002 |
| freeing items        | 0.000080 |
| logging slow query   | 0.000002 |
| cleaning up          | 0.000040 |
+----------------------+----------+
12 rows in set (0.00 sec)

如果没有指定FOR QUERY,那么输出最近一条语句的信息。

可以看到MySQL为我们生成了操作在执行过程中每一个步骤所耗费的时间,通过profiling我们就可以查找出sql语句中耗时的地方,并加以优化。 

 

5、

SHOW PROFILE TYPE FOR QUERY n

 

TYPE是可选的,取值范围可以如下:

  • ALL 显示所有性能信息
  • BLOCK IO 显示块IO操作的次数
  • CONTEXT SWITCHES 显示上下文切换次数,不管是主动还是被动
  • CPU 显示用户CPU时间、系统CPU时间
  • IPC 显示发送和接收的消息数量
  • MEMORY [暂未实现]
  • PAGE FAULTS 显示页错误数量
  • SOURCE 显示源码中的函数名称与位置
  • SWAPS 显示SWAP的次数

例:

mysql> show profile cpu,block io for query 1;
+----------------------+----------+----------+------------+--------------+---------------+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting             | 0.000481 | 0.000000 |   0.000000 |         NULL |          NULL |
| checking permissions | 0.000005 | 0.000000 |   0.000000 |         NULL |          NULL |
| Opening tables       | 0.000004 | 0.000000 |   0.000000 |         NULL |          NULL |
| init                 | 0.000184 | 0.000000 |   0.000000 |         NULL |          NULL |
| optimizing           | 0.000006 | 0.000000 |   0.000000 |         NULL |          NULL |
| executing            | 0.000226 | 0.000000 |   0.000000 |         NULL |          NULL |
| end                  | 0.000004 | 0.000000 |   0.000000 |         NULL |          NULL |
| query end            | 0.000001 | 0.000000 |   0.000000 |         NULL |          NULL |
| closing tables       | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| freeing items        | 0.000080 | 0.000000 |   0.000000 |         NULL |          NULL |
| logging slow query   | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| cleaning up          | 0.000040 | 0.000000 |   0.000000 |         NULL |          NULL |
+----------------------+----------+----------+------------+--------------+---------------+
12 rows in set (0.00 sec)

上面的例子中是获取 CPU 和 Block IO 的消耗,非常清晰,对于定位性能瓶颈非常适用。

 

以下状态解释来自网络博客:

 

 

 

6、获取所有信息

mysql> SHOW PROFILE ALL FOR QUERY 1;

等价于

mysql> SELECT * FROM information_schema.profiling WHERE query_id = 1 ORDER BY seq;

 

 

 

 

 

 

 

 

大概只有在孩提时代的我们才会有远大的目标吧。

posted @ 2019-12-20 11:40  杨宇飞  阅读(610)  评论(0编辑  收藏  举报