MySQL PROFILE跟踪语句各阶段性能开销

PROFILE可以跟踪查询语句各个阶段Time，IO，CPU，MEMORY等资源使用情况，比较详细。所以系统一般不会记录太多。启用是全局的，所以每个连接都保持语句的资源使用情况。

查看 PROFILE 是否启用：
mysql> select @@profiling;
+-------------+
| @@profiling |
+-------------+
| 0 |
+-------------+

mysql> show variables like '%profiling%';
+------------------------+-------+
| variable_name | value |
+------------------------+-------+
| have_profiling | yes |
| profiling | off |
| profiling_history_size | 15 |
+------------------------+-------+
have_profiling ： 是否可使用 profiling
profiling ： 是否启用
profiling_history_size ： 保留最近执行的记录数量。默认15，最大100，0相当于禁用。

启用(为全局变量)：
mysql> set profiling = 1;
mysql> set profiling_history_size = 10;

查看当前连接最近执行语句情况，编号越大为当前最近执行的。
mysql> show profiles;
+----------+------------+-----------------------------------------+
| query_id | duration | query |
+----------+------------+-----------------------------------------+
| 2 | 0.00705950 | show variables like '%profiling%' |
| 3 | 0.00127400 | select * from mysql.user |
| 4 | 0.00029100 | select * from mysql.user |
| 5 | 0.00040850 | select * from mysql.user limit 10 |
| 6 | 5.00128000 | select sleep(5) |
| 7 | 0.00044425 | select * from mysql.user limit 1 |
| 8 | 0.00436100 | show variables like '%profiling%' |
| 9 | 0.00047725 | select * from mysql.slow_log |
| 10 | 0.00052150 | select * from mysql.slow_log order by 1 |
| 11 | 0.00049775 | select * from mysql.slow_log order by 2 |
+----------+------------+-----------------------------------------+

查看以上查询开销：SHOW PROFILE Syntax
SHOW PROFILE [type [, type] ... ]
[FOR QUERY n]
[LIMIT row_count [OFFSET offset]]

type:
ALL
| BLOCK IO
| CONTEXT SWITCHES
| CPU
| IPC
| MEMORY
| PAGE FAULTS
| SOURCE
| SWAPS

默认显示时间信息，显示了该查询从开始到被清除各个阶段的执行时间。
mysql> show profile;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000090 |
| checking permissions | 0.000007 |
| Opening tables | 0.000048 |
| init | 0.000033 |
| System lock | 0.000006 |
| optimizing | 0.000018 |
| statistics | 0.000018 |
| preparing | 0.000015 |
| Sorting result | 0.000006 |
| executing | 0.000328 |
| Sending data | 0.000016 |
| Creating sort index | 0.000081 |
| end | 0.000004 |
| query end | 0.000006 |
| closing tables | 0.000003 |
| removing tmp table | 0.000005 |
| closing tables | 0.000004 |
| freeing items | 0.000068 |
| cleaning up | 0.000017 |
+----------------------+----------+

其它查看方法：
mysql> show profile;
mysql> select * from information_schema.profiling;
mysql> select * from information_schema.profiling where query_id=6 or

mysql> show profile; #默认显示时间信息
mysql> show profile CPU,BLOCK IO; #(时间)加上 CPU,BLOCK IO使用情况
mysql> show profile for query 6; #query_id=6的(时间)信息
mysql> show profile CPU for query 6; #query_id=6的cpu信息
mysql> show profile CPU limit 6; #前6个状态信息(前6行)
mysql> show profile CPU limit 6 offset 2; #第2行起前6个状态信息(前2~7行)

关闭跟踪：
set profiling = 0;
set profiling_history_size = 0;

参考：
SHOW PROFILE Syntax
The INFORMATION_SCHEMA PROFILING Table