MySQL 性能分析工具系列：PROFILING

由于个人能力有限，文中可能存在错误，欢迎批评指正。

1.说明

profiling 是 mysql 提供用来查看并分析 sql 具体执行代价的功能，目前可提供除了内存以外的其他资源消耗统计，例如 CPU、I/O、CONTEXT、SWAP 等。

2.如何使用

1）查看参数是否开启，默认是关闭状态

mysql> select @@profiling;
+-------------+
| @@profiling |
+-------------+
|           0 |
+-------------+
1 row in set, 1 warning (0.00 sec)

2）开启 profiling

# 设置成 1 即开启，另外注意 profiling 是会话变量，退出会话后，设置会再还原为 0 
mysql> set profiling=1;
Query OK, 0 rows affected, 1 warning (0.00 sec)

# 查看 profiling 状态，当前已开启
mysql> select @@profiling;
+-------------+
| @@profiling |
+-------------+
|           1 |
+-------------+
1 row in set, 1 warning (0.00 sec)

3）查看 sql 执行情况

# 示例：
mysql> select * from t2 limit 5;
+----+-----+-----+-----+
| id | xxx | yyy | zzz |
+----+-----+-----+-----+
|  1 | 11  | 22  | 33  |
|  2 | 12  | 23  | 34  |
|  3 | 13  | 24  | 35  |
|  4 | 11  | 22  | 33  |
|  5 | 12  | 23  | 34  |
+----+-----+-----+-----+
5 rows in set (0.00 sec)

# 查看 sql 执行情况，如下命令展示最近执行的 sql 语句（默认是最近15条 sql ），Query_ID 会一直递增，后期我们会使用这个id，来具体查询某一条SQL的执行耗时清单
mysql> show profiles;
+----------+------------+---------------------------+
| Query_ID | Duration   | Query                     |
+----------+------------+---------------------------+
|        1 | 0.00013300 | select @@profiling        |
|        2 | 0.00022900 | select * from t2 limit 5  |
+----------+------------+---------------------------+
2 rows in set, 1 warning (0.00 sec)

4）具体查看某一条 SQL 的执行细节

mysql> show profile for query 2;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000050 |
| checking permissions | 0.000005 |
| Opening tables       | 0.000016 |
| init                 | 0.000015 |
| System lock          | 0.000008 |
| optimizing           | 0.000002 |
| statistics           | 0.000011 |
| preparing            | 0.000016 |
| executing            | 0.000002 |
| Sending data         | 0.000048 |
| end                  | 0.000002 |
| query end            | 0.000012 |
| closing tables       | 0.000006 |
| freeing items        | 0.000026 |
| cleaning up          | 0.000011 |
+----------------------+----------+
15 rows in set, 1 warning (0.04 sec)

另外，也可以结合如下选项一起执行：

# 语法格式
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
 }
	
-- 选项
ALL；显示所有的开销信息
BLOCK IO：显示块IO相关开销
CONTEXT SWITCHES：上下文切换相关开销
CPU：显示CPU相关开销
IPC：显示发送和接受相关开销
MEMORY：显示内存相关开销
PAGE FAULTS：显示页面错误相关开销
SOURCE：显示和Source_function, Source_file,Source_line相关的相关开销
SWAPS：显示交换次数相关开销

# 示例：
mysql> show profile cpu,block io for query 2;
+----------------------+----------+----------+------------+--------------+---------------+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | 	Block_ops_out|
+----------------------+----------+----------+------------+--------------+---------------+
| starting             | 0.000048 |     NULL |       NULL |         NULL |          NULL |
| checking permissions | 0.000005 |     NULL |       NULL |         NULL |          NULL |
| Opening tables       | 0.000126 |     NULL |       NULL |         NULL |          NULL |
| init                 | 0.000020 |     NULL |       NULL |         NULL |          NULL |
| System lock          | 0.000008 |     NULL |       NULL |         NULL |          NULL |
| optimizing           | 0.000003 |     NULL |       NULL |         NULL |          NULL |
| statistics           | 0.000011 |     NULL |       NULL |         NULL |          NULL |
| preparing            | 0.000009 |     NULL |       NULL |         NULL |          NULL |
| executing            | 0.000002 |     NULL |       NULL |         NULL |          NULL |
| Sending data         | 0.000087 |     NULL |       NULL |         NULL |          NULL |
| end                  | 0.000003 |     NULL |       NULL |         NULL |          NULL |
| query end            | 0.000006 |     NULL |       NULL |         NULL |          NULL |
| closing tables       | 0.000006 |     NULL |       NULL |         NULL |          NULL |
| freeing items        | 0.000027 |     NULL |       NULL |         NULL |          NULL |
| cleaning up          | 0.000013 |     NULL |       NULL |         NULL |          NULL |
+----------------------+----------+----------+------------+--------------+---------------+
15 rows in set, 1 warning (0.01 sec)

大部分情况下，PROFILE 的结果我们主要关注两列：Status、Duration，前者表示的是 PROFILE 里的状态，它和 PROCESSLIST 的状态基本是一致的，后者是该状态的耗时。因此，我们最主要的是关注处于哪个状态耗时最久，这些状态中，哪些可以进一步优化。

下面几种状态是要尤其关注的，而且大多数通过创建合适的索引就可以完成优化。

Status 建议

• System lock，确认是由于哪个锁引起的，通常是因为 MySQL 或 InnoDB 内核级的锁引起的。
  建议：如果耗时较大再关注即可，一般情况下都还好。

• Sending data，从 server 端发送数据到客户端，也有可能是接收存储引擎层返回的数据，再发送给客户端，数据量很大时尤其经常能看见。

  备注：Sending Data 不是网络发送，是从硬盘读取，发送到网络是 Writing to net 。

  建议通过索引或加上 LIMIT ，减少需要扫描并且发送给客户端的数据量。

• Sorting result，正在对结果进行排序，类似 Creating sort index ，不过是正常表，而不是在内存表中进行排序。
  建议：创建适当的索引。

• Table lock，表级锁，要么是因为 MyISAM 引擎表级锁，要么是其他情况显式锁表。

• create sort index，当前的 SELECT 中需要用到临时表在进行 ORDER BY 排序。
  建议：创建适当的索引。

参考资料

【1】 SHOW PROFILE Statement