Profiling 的使用

Normal 0 7.8 磅 0 2 false false false EN-US ZH-CN X-NONE /* Style Definitions */ table.MsoNormalTable {mso-style-name:普通表格; mso-tstyle-rowband-size:0; mso-tstyle-colband-size:0; mso-style-noshow:yes; mso-style-priority:99; mso-style-qformat:yes; mso-style-parent:""; mso-padding-alt:0cm 5.4pt 0cm 5.4pt; mso-para-margin:0cm; mso-para-margin-bottom:.0001pt; mso-pagination:widow-orphan; font-size:10.0pt; font-family:"Lucida Sans","sans-serif";}

8.3.2 Profiling 的使用

 

    在本章第一节中我们还提到过通过 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 参数

 

root@localhost : (none) 10:53:11> set profiling=1;

Query OK, 0 rows affected (0.00 sec)

 

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

 

2、 执行 Query

    ... ...

root@localhost : test 07:43:18> select status,count(*)

    -> from test_profiling group by status;

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

| status         | count(*) |

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

| st_xxx1        |       27 |

| st_xxx2        |     6666 |

| st_xxx3        |   292887 |

| st_xxx4        |       15 |

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

5 rows in set (1.11 sec)

... ...

 

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

 

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

root@localhost : test 07:47:35> show profiles;

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

| Query_ID | Duration   | Query                                                      |

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

|        1 | 0.00183100 | show databases                                             |

|        2 | 0.00007000 | SELECT DATABASE()                                          |

|        3 | 0.00099300 | desc test                                                  |

|        4 | 0.00048800 | show tables                                                |

|        5 | 0.00430400 | desc test_profiling                                        |

|        6 | 1.90115800 | select status,count(*) from test_profiling group by status |

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

3 rows in set (0.00 sec)

 

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

 

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

在获取到概要信息之后，我们就可以根据概要信息中的 Query_ID 来获取某个 Query 在执行过程中详细的 profile 信息了，具体操作如下：

root@localhost : test 07:49:24> show profile cpu, block io for query 6;

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

| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |

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

| starting             | 0.000349 | 0.000000 |   0.000000 |            0 |             0 |

| Opening tables       | 0.000012 | 0.000000 |   0.000000 |            0 |             0 |

| System lock          | 0.000004 | 0.000000 |   0.000000 |            0 |             0 |

| Table lock           | 0.000006 | 0.000000 |   0.000000 |            0 |             0 |

| init                 | 0.000023 | 0.000000 |   0.000000 |            0 |             0 |

| optimizing           | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |

| statistics           | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |

| preparing            | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |

| Creating tmp table   | 0.000035 | 0.000999 |   0.000000 |            0 |             0 |

| executing            | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |

| Copying to tmp table | 1.900619 | 1.030844 |   0.197970 |          347 |           347 |

| Sorting result       | 0.000027 | 0.000000 |   0.000000 |            0 |             0 |

| Sending data         | 0.000017 | 0.000000 |   0.000000 |            0 |             0 |

| end                  | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |

| removing tmp table   | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |

| end                  | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |

| query end            | 0.000003 | 0.000000 |   0.000000 |            0 |             0 |

| freeing items        | 0.000029 | 0.000000 |   0.000000 |            0 |             0 |

| logging slow query   | 0.000001 | 0.000000 |   0.000000 |            0 |             0 |

| logging slow query   | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |

| cleaning up          | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |

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

 

    上面的例子中是获取 CPU 和 Block IO 的消耗，非常清晰，对于定位性能瓶颈非常适用。希望得到取其他的信息，都可以通过执行 “SHOW PROFILE *** FOR QUERY n” 来获取，各位读者朋友可以自行测试熟悉。