分析SQL執行帶來的開銷是最佳化SQL的常用手段，在MySQL資料庫中，可以透過配置profiling引數來啟用SQL剖析。
它只能在session級別來設定，設定後影響當前session；當它開啟後，後續執行的SQL語句都將記錄其資源開銷，諸如IO，上下文，CPU，MEMORY等。

實驗環境：

mysql> select version();
+------------+
| version() |
+------------+
| 5.7.17-log |
+------------+
1 row in set (0.00 sec)

與profile相關的三個引數：

mysql> show variables like '%profil%';
+------------------------+-------+
| Variable_name | Value |
+------------------------+-------+
| have_profiling | YES | ---用於控制是否由系統變數開啟或禁用profiling
| profiling | OFF | ---開啟SQL語句剖析功能
| profiling_history_size | 15 | ---設定保留profiling的數目，預設為15，範圍為0至100，為0時將禁用profiling
+------------------------+-------+
3 rows in set (0.01 sec)

開啟profiling,有個警告，這個引數在以後會被刪除，用information_scheam.PROFILING替代。

mysql> set profiling=1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> show warnings;
+---------+------+----------------------------------------------------------------------+
| Level | Code | Message |
+---------+------+----------------------------------------------------------------------+
| Warning | 1287 | '@@profiling' is deprecated and will be removed in a future release. |
+---------+------+----------------------------------------------------------------------+

執行一條sql測試一下:

select * from oms3.customers where `type` = 1 AND `status` < 7 AND `isarea` = 6 AND `into_time`>='2016-12-01'AND `into_time`<='2017-01-02 23:59:59' order by score desc limit 40,20

sql執行很慢，執行完成之後檢視:

mysql> show profiles;
+----------+--------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+--------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 7 | 0.00022275 | SELECT * FROM setup_actors |
| 8 | 0.00016050 | SELECT DATABASE() |
| 9 | 0.00032350 | show databases |
| 10 | 0.00024050 | show tables |
| 11 | 0.00019250 | SELECT * FROM setup_actors |
| 12 | 0.00183950 | show variables like "profiling_hist%" |
| 13 | 0.00192500 | show variables like '%profil%' |
| 14 | 0.00011550 | show warnings |
| 15 | 0.00044725 | help 'show profile' |
| 16 | 0.00013875 | set profiling=1 |
| 17 | 0.00011550 | show warnings |
| 18 | 0.00025075 | select * from customers where `type` = 1 AND `status` < 7 AND `isarea` = 6 AND `into_time`>='2016-12-01'AND `into_time`<='2017-01-02 23:59:59' order by score desc limit 40,20 |
| 19 | 333.19133875 | select * from oms3.customers where `type` = 1 AND `status` < 7 AND `isarea` = 6 AND `into_time`>='2016-12-01'AND `into_time`<='2017-01-02 23:59:59' order by score desc limit 40,20 |
| 20 | 0.00011250 | show profilings |
| 21 | 0.00010975 | show profilings |
+----------+--------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
15 rows in set, 1 warning (0.00 sec)
mysql> set @query_id=19; ---上面顯示是query_id為19
Query OK, 0 rows affected (0.00 sec)
mysql> select STATE,sum(duration) as Total_R, ---用這條sql查詢具體是哪裡出問題，這條sql引用於《High Performance MySQL,Third Edition》
-> ROUND(
-> 100*SUM(DURATION)/
-> (SELECT SUM(DURATION) FROM INFORMATiON_SCHEMA.PROFILING WHERE QUERY_ID=@query_id),2) as Pct_R,
-> count(*) as calls,
-> sum(duration)/count(*) as "R/Call"
-> from information_schema.profiling
-> where query_id=@query_id
-> group by state
-> order by Total_R desc;
+----------------------+------------+-------+-------+----------------+
| STATE | Total_R | Pct_R | calls | R/Call |
+----------------------+------------+-------+-------+----------------+
| Sending data | 332.162424 | 99.69 | 1 | 332.1624240000 | ---這個state基本佔用了全部的資源，那麼對這條sql的最佳化就著重於減少io上。
| statistics | 1.027729 | 0.31 | 1 | 1.0277290000 |
| Opening tables | 0.000519 | 0.00 | 1 | 0.0005190000 |
| freeing items | 0.000157 | 0.00 | 1 | 0.0001570000 |
| starting | 0.000147 | 0.00 | 1 | 0.0001470000 |
| init | 0.000123 | 0.00 | 1 | 0.0001230000 |
| logging slow query | 0.000096 | 0.00 | 1 | 0.0000960000 |
| preparing | 0.000035 | 0.00 | 1 | 0.0000350000 |
| cleaning up | 0.000019 | 0.00 | 1 | 0.0000190000 |
| optimizing | 0.000016 | 0.00 | 1 | 0.0000160000 |
| end | 0.000014 | 0.00 | 1 | 0.0000140000 |
| System lock | 0.000014 | 0.00 | 1 | 0.0000140000 |
| closing tables | 0.000013 | 0.00 | 1 | 0.0000130000 |
| query end | 0.000013 | 0.00 | 1 | 0.0000130000 |
| Sorting result | 0.000010 | 0.00 | 1 | 0.0000100000 |
| checking permissions | 0.000009 | 0.00 | 1 | 0.0000090000 |
| executing | 0.000003 | 0.00 | 1 | 0.0000030000 |
+----------------------+------------+-------+-------+----------------+
17 rows in set, 18 warnings (0.00 sec)

其他用法：

mysql> SHOW PROFILE CPU FOR QUERY 2;
+----------------------+----------+----------+------------+
| Status | Duration | CPU_user | CPU_system |
+----------------------+----------+----------+------------+
| checking permissions | 0.000040 | 0.000038 | 0.000002 |
| creating table | 0.000056 | 0.000028 | 0.000028 |
| After create | 0.011363 | 0.000217 | 0.001571 |
| query end | 0.000375 | 0.000013 | 0.000028 |
| freeing items | 0.000089 | 0.000010 | 0.000014 |
| logging slow query | 0.000019 | 0.000009 | 0.000010 |
| cleaning up | 0.000005 | 0.000003 | 0.000002 |
+----------------------+----------+----------+------------+

更多用法詳見：

help show profiles;

總結：

上面說到這個引數以後會被廢棄，但是我覺得任重而道遠，因為現在information_scheam.PROFILING表裡連具體執行的sql都沒記錄......

PS:關於上面那條慢SQL的最佳化，請看我另一篇部落格：http://blog.itpub.net/20893244/viewspace-2134636/

MySQL效能分析工具之PROFILE

相關文章