快捷導(dǎo)航

解析Mysql Profiling的使用

更新時(shí)間：2013年06月14日 10:19:41 作者：

本篇文章是對Mysql Profiling的使用進(jìn)行了詳細(xì)的分析介紹，需要的朋友參考下

profiling是個很好用的mysql性能分析工具，今兒就來試驗(yàn)下profiling的功能。感謝有愛玫瑰的博文：
mysql 的 sql 性能分析器主要用途是顯示 sql 執(zhí)行的整個過程中各項(xiàng)資源的使用情況。分析器可以更好的展示出不良 SQL 的性能問題所在。
下面我們舉例介紹一下MySQL SQL Profiler的使用方法：
首先，開啟 MySQL SQL Profiler

復(fù)制代碼代碼如下:

mysql> SELECT @@profiling;
    +-------------+
    | @@profiling |
    +-------------+
    | 0 |
    +-------------+
    1 row in set (0.00 sec)
    mysql> SET profiling = 1;
    Query OK, 0 rows affected (0.00 sec)
    mysql> SELECT @@profiling;
    +-------------+
    | @@profiling |
    +-------------+
    | 1 |
    +-------------+

1 row in set (0.00 sec)默認(rèn)情況下 profiling 的值為 0 表示 MySQL SQL Profiler 處于 OFF 狀態(tài)，開啟 SQL 性能分析器后 profiling 的值為 1.
通過 sql 性能分析器，我們來對比一下下列語句前后 2 次執(zhí)行過程的差異，對我們了解 sql 的詳細(xì)執(zhí)行過程是非常有幫助的。

復(fù)制代碼代碼如下:

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)

從上面的例子中我們可以清晰的看出 2 次執(zhí)行 count 語句的差別， SHOW PROFILE FOR QUERY 27 展現(xiàn)的是第一次 count 統(tǒng)計(jì)的執(zhí)行過程，包含了 Opening tables 、 Table lock 等操作。而 SHOW PROFILE FOR QUERY 28 展示了第二次 count 統(tǒng)計(jì)的執(zhí)行過程 , 第二次 count 直接從查詢緩存中返回 count 統(tǒng)計(jì)結(jié)果，通過對比 2 次統(tǒng)計(jì)的總執(zhí)行時(shí)間發(fā)現(xiàn)，緩存讀的速度接近物理讀的 10 倍。通過使用 SQL 性能分析器可以幫助我們對一些比較難以確定性能問題的 SQL 進(jìn)行診斷，找出問題根源。

您可能感興趣的文章: