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