MYSQL查詢最佳化：show profile

標籤：

Query Profiler是MYSQL內建的一種query診斷分析工具，通過它可以分析出一條SQL語句的效能瓶頸在什麼地方。通常我們是使用的explain,以及slow query log都無法做到精確分析，但是Query Profiler卻可以定位出一條SQL語句執行的各種資源消耗情況，比如CPU，IO等，以及該SQL執行所耗費的時間等。不過該工具只有在MYSQL 5.0.37以及以上版本中才有實現。
預設的情況下，MYSQL的該功能沒有開啟，需要自己手動啟動。可以通過如下方法查看當前mysql伺服器是否開啟了該功能。

 

MySQL尋找SQL耗時瓶頸 SHOW profiles

 

1、不過版本要在5.0.37之後。(SHOW PROFILES and SHOW PROFILE were added in MySQL 5.0.37.)

SELECT @@profiling;

來查看是否已經啟用profile，如果profilng值為0，可以通過

SET profiling = 1;

來啟用。啟用profiling之後，我們執行一條查詢語句，比如：

select count(*) from roi_summary;

然後show profiles查看如下：

+----------------+------------+----------------------------------+| Query_ID       | Duration   | Query                            |+----------------+------------+----------------------------------+|        1       | 0.00021500 | select @@profiling               ||        2       | 0.05522700 | select count(*) from roi_summary |+----------------+------------+----------------------------------+

2 rows in set (0.00 sec)

其中ID為5的語句是剛執行的查詢語句

2、變數profiling是使用者變數，每次都得重新啟用。
以下是我做的一些實驗。資料很明顯，就不多解釋了。

mysql> use testDatabase changedmysql> set profiling=1;Query OK, 0 rows affected (0.00 sec)mysql> show tables;+----------------+| Tables_in_test |+----------------+| bag_item | | bag_user | | score | | t | +----------------+4 rows in set (0.03 sec)mysql> select count(*) from t;+----------+| count(*) |+----------+| 2097152 | +----------+1 row in set (0.74 sec)mysql> show profiles;+----------+------------+------------------------+| Query_ID | Duration   | Query                  |+----------+------------+------------------------+|        1 | 0.02717000 | show tables            | |        2 | 0.74770100 | select count(*) from t | +----------+------------+------------------------+2 rows in set (0.00 sec)mysql> show profile for query 2;+--------------------------------+----------+| Status                         | Duration |+--------------------------------+----------+| (initialization)               | 0.000004 | | checking query cache for query | 0.000044 | | Opening tables                 | 0.000012 | | System lock                    | 0.000017 | | Table lock                     | 0.00003  | | init                           | 0.000013 | | optimizing                     | 0.000008 | | statistics                     | 0.000013 | | preparing                      | 0.000011 | | executing                      | 0.000006 | | Sending data                   | 0.747313 | | end                            | 0.000014 | | query end                      | 0.000006 | | storing result in query cache  | 0.000006 | | freeing items                  | 0.000012 | | closing tables                 | 0.000009 | | logging slow query             | 0.000183 | +--------------------------------+----------+17 rows in set (0.00 sec)mysql> show profile block io,cpu for query 2;+--------------------------------+----------+----------+------------+--------------+---------------+| Status                         | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |+--------------------------------+----------+----------+------------+--------------+---------------+| (initialization)               | 0.000004 | 0        | 0          |            0 |             0 | | checking query cache for query | 0.000044 | 0        | 0          |            0 |             0 | | Opening tables                 | 0.000012 | 0        | 0          |            0 |             0 | | System lock                    | 0.000017 | 0        | 0          |            0 |             0 | | Table lock                     | 0.00003  | 0        | 0          |            0 |             0 | | init                           | 0.000013 | 0        | 0          |            0 |             0 | | optimizing                     | 0.000008 | 0        | 0          |            0 |             0 | | statistics                     | 0.000013 | 0        | 0          |            0 |             0 | | preparing                      | 0.000011 | 0        | 0          |            0 |             0 | | executing                      | 0.000006 | 0        | 0          |            0 |             0 | | Sending data                   | 0.747313 | 0.746887 | 0          |            0 |             0 | | end                            | 0.000014 | 0        | 0          |            0 |             0 | | query end                      | 0.000006 | 0        | 0          |            0 |             0 | | storing result in query cache  | 0.000006 | 0        | 0          |            0 |             0 | | freeing items                  | 0.000012 | 0        | 0          |            0 |             0 | | closing tables                 | 0.000009 | 0        | 0          |            0 |             0 | | logging slow query             | 0.000183 | 0        | 0          |            0 |             0 | +--------------------------------+----------+----------+------------+--------------+---------------+17 rows in set (0.00 sec)mysql> insert into t(username) select username from t;Query OK, 2097152 rows affected (34.17 sec)Records: 2097152  Duplicates: 0  Warnings: 0mysql> show profiles;+----------+-------------+------------------------------------------------+| Query_ID | Duration    | Query                                          |+----------+-------------+------------------------------------------------+|        1 |  0.02717000 | show tables                                    | |        2 |  0.74770100 | select count(*) from t                         | |        3 |  0.00004200 | show prifile for query 2                       | |        4 | 34.30410100 | insert into t(username) select username from t | +----------+-------------+------------------------------------------------+4 rows in set (0.00 sec)mysql> show profile cpu,block io,memory,swaps for query 4;mysql> select count(*) from t;+----------+| count(*) |+----------+|  4194304 | +----------+1 row in set (1.51 sec)mysql> show profiles;+----------+-------------+------------------------------------------------+| Query_ID | Duration    | Query                                          |+----------+-------------+------------------------------------------------+|        1 |  0.02717000 | show tables                                    | |        2 |  0.74770100 | select count(*) from t                         | |        3 |  0.00004200 | show prifile for query 2                       | |        4 | 34.30410100 | insert into t(username) select username from t | |        5 |  1.50563800 | select count(*) from t                         | +----------+-------------+------------------------------------------------+5 rows in set (0.00 sec)mysql> show profile cpu,block io,memory,swaps,context switches,source for query 5;……mysql> update t set username = ‘waill‘;Query OK, 4194304 rows affected (44.82 sec)Rows matched: 4194304  Changed: 4194304  Warnings: 0mysql> show profiles;+----------+-------------+------------------------------------------------+| Query_ID | Duration    | Query                                          |+----------+-------------+------------------------------------------------+|        1 |  0.02717000 | show tables                                    | |        2 |  0.74770100 | select count(*) from t                         | |        3 |  0.00004200 | show prifile for query 2                       | |        4 | 34.30410100 | insert into t(username) select username from t | |        5 |  1.50563800 | select count(*) from t                         | |        6 | 44.82054700 | update t set username = ‘waill‘                | +----------+-------------+------------------------------------------------+6 rows in set (0.00 sec)mysql> show profile cpu,block io,memory,swaps,context switches,source for query 6;
mysql> show profile all for query 6;

MYSQL查詢最佳化：show profile