全部博文（535）
分类： Mysql/postgreSQL
2011-12-09 16:33:50
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” 来获取，各位读者朋友可以自行测试熟悉。
