MySQL 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 的具體用法。

一、 開啓 profiling 參數

root@localhost : (none) 10:53:11> set profiling=1;
Query OK, 0 rows affected (0.00 sec)

經過執行 「set profiling」命令，能夠開啓關閉 Query Profiler 功能。

二、 執行 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 信息了。

三、獲取系統中保存的全部 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 的概要信息。

四、針對單個 Query 獲取詳細的 profile 信息。

在獲取到概要信息以後，咱們就能夠根據概要信息中的 Query_ID 來獲取某個 Query 在執行過程當中

詳細的 profile 信息了，具體操做以下：

上面的例子中是獲取 CPU 和 Block IO 的消耗，很是清晰，對於定位性能瓶頸很是適用。但願獲得取其餘的信息，均可以經過執行 「SHOW PROFILE *** FOR QUERY n」 來獲取，各位讀者朋友能夠自行測試熟悉。

 

對同一條語句的兩次查詢作性能分析

• 經過 sql 性能分析器，咱們來對比一下 下列語句先後 2 次執行過程的差別，對咱們瞭解 sql 的詳細執行過程是很是有幫助的。

mysql> create table t_engines select * from t_engines1; Query OK, 57344 rows affected (0.10 sec) Records: 57344 Duplicates: 0 Warnings: 0 mysql> select count(*) from t_engines; +----------+ | count(*) | +----------+ | 57344 | +----------+ 1 row in set (0.00 sec) mysql> select count(*) from t_engines; +----------+ | count(*) | +----------+ | 57344 | +----------+ 1 row in set (0.00 sec) mysql> SHOW PROFILES; +----------+------------+-------------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+-------------------------------------------------+ | 26 | 0.10213775 | create table t_engines select * from t_engines1 | | 27 | 0.00032775 | select count(*) from t_engines | | 28 | 0.00003850 | select count(*) from t_engines | +----------+------------+-------------------------------------------------+ 15 rows in set (0.01 sec)mysql> SHOW PROFILE FOR QUERY 27; +--------------------------------+------------+ | Status | Duration | +--------------------------------+------------+ | (initialization) | 0.00000425 | | checking query cache for query | 0.00004050 | | checking permissions | 0.00001050 | | Opening tables | 0.00018250 | | System lock | 0.00000450 | | Table lock | 0.00001775 | | init | 0.00001075 | | optimizing | 0.00000550 | | executing | 0.00002775 | | end | 0.00000450 | | query end | 0.00000325 | | storing result in query cache | 0.00000400 | | freeing items | 0.00000400 | | closing tables | 0.00000500 | | logging slow query | 0.00000300 | +--------------------------------+------------+ 15 rows in set (0.00 sec) mysql> SHOW PROFILE FOR QUERY 28; +-------------------------------------+------------+ | Status | Duration | +-------------------------------------+------------+ | (initialization) | 0.00000350 | | checking query cache for query | 0.00000750 | | checking privileges on cached query | 0.00000500 | | checking permissions | 0.00000525 | | sending cached result to client | 0.00001275 | | logging slow query | 0.00000450 | +-------------------------------------+------------+ 6 rows in set (0.00 sec)mysql> SELECT sum( FORMAT(DURATION, 6)) AS DURATION FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID =27 ORDER BY SEQ; +----------+ | DURATION | +----------+ | 0.000326 | +----------+ 1 row in set (0.00 sec) mysql> SELECT sum( FORMAT(DURATION, 6)) AS DURATION FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID =28 ORDER BY SEQ; +----------+ | DURATION | +----------+ | 0.000039 | +----------+ 1 row in set (0.00 sec) mysql> 從上面的例子中咱們能夠清晰的看出 2 次執行 count 語句的差異， SHOW PROFILE FOR QUERY 27 展示的是第一次 count 統計的執行過程，包含了 Opening tables 、 Table lock 等操做 。而 SHOW PROFILE FOR QUERY 28 展現了第二次 count 統計的執行過程 , 第二次 count 直接從查詢緩存中返回 count 統計結果，經過對比 2 次統計的總執行時間發現，緩存讀的速度接近物理讀的 10 倍。經過使用 SQL 性能分析器能夠幫助咱們對一些比較難以肯定性能問題的 SQL 進行診斷，找出問題根源。