MySQL中profile的使用

mysql官网定义

The SHOW PROFILE and SHOW PROFILES statements display profiling information that indicates resource usage for statements executed during the course of the current session.

简单的说，当前会话资源的消耗情况。

注意：show profile和show Profiles都是不建议使用的，在mysql后期的版本中可能会被删除；官网建议使用Performance Schema

怎么使用

profile默认关闭，生产环境中也建议关闭。

查看当前环境的profile设置

mysql> show variables like '%profiling%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| have_profiling         | YES   |
| profiling              | OFF   |
| profiling_history_size | 15    |
+------------------------+-------+

profiling off表示profile关闭，profiling_history_size 15表示保存最近15条SQL的资源消耗情况。

开启profile功能，可以使用命令

set global profiling = 1;

然后就可以使用下面命令

show profiles;

查看最近15条SQL的情况；
如果要查看某一条的具体情况，SQL格式为：

SHOW PROFILE [type [, type] ... ]
    [FOR QUERY n]
    [LIMIT row_count [OFFSET offset]]

type: {
  | ALL------显示所有性能信息
  | BLOCK IO -------显示块IO操作的次数
  | CONTEXT SWITCHES-----显示上下文切换次数，不管是主动还是被动
  | CPU-----显示用户CPU时间、系统CPU时间
  | IPC-----显示发送和接收的消息数量
  | MEMORY-----[暂未实现]
  | PAGE FAULTS-----显示页错误数量
  | SOURCE-----显示源码中的函数名称与位置
  | SWAPS-----显示SWAP的次数
}

profiling 对每个会话有效，当会话结束后，当前的profiling信息就会丢失。

使用案例

mysql> show profiles;
+----------+------------+----------------------------+
| Query_ID | Duration   | Query                      |
+----------+------------+----------------------------+
|        1 | 0.00060275 | select * from customers    |
|        2 | 0.00222450 | show tables                |
|        3 | 0.00567425 | select * from offices      |
|        4 | 0.00052050 | show tables                |
|        5 | 0.01123300 | select * from payments     |
|        6 | 0.00111675 | show tables                |
|        7 | 0.02049625 | select * from productlines |
+----------+------------+----------------------------+

在排查SQL执行情况，或者是哪条SQL执行非常慢，慢在哪里；profile都是非常的辅助工具。

显示一条SQL的具体花销在哪里

mysql> show profile for query 7;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000043 |
| checking permissions | 0.000005 |
| Opening tables       | 0.014552 |
| init                 | 0.000025 |
| System lock          | 0.000009 |
| optimizing           | 0.000004 |
| statistics           | 0.000011 |
| preparing            | 0.000010 |
| executing            | 0.000003 |
| Sending data         | 0.005653 |
| end                  | 0.000010 |
| query end            | 0.000009 |
| closing tables       | 0.000020 |
| freeing items        | 0.000121 |
| cleaning up          | 0.000023 |
+----------------------+----------+

mysql> show profile cpu for query 7;
+----------------------+----------+ ----------+ ----------+ 
| Status               | Duration | CPU_user  | CPU_system|
+----------------------+----------+ ----------+ ----------+    
| starting             | 0.000043 |  0.000000 |  0.000060 |
| checking permissions | 0.000005 |  0.000000 |  0.000004 |
| Opening tables       | 0.014552 |  0.000039 |  0.000008 |
| init                 | 0.000025 |  0.000006 |  0.000060 |
| System lock          | 0.000009 |  0.000011 |  0.000005 |
| optimizing           | 0.000004 |  0.000006 |  0.000060 |
| statistics           | 0.000011 |  0.000000 |  0.000060 |
| preparing            | 0.000010 |  0.000000 |  0.000060 |
| executing            | 0.000003 |  0.000000 |  0.002350 |
| Sending data         | 0.005653 |  0.000000 |  0.000060 |
| end                  | 0.000010 |  0.000000 |  0.000060 |
| query end            | 0.000009 |  0.000000 |  0.000060 |
| closing tables       | 0.000020 |  0.000007 |  0.000060 |
| freeing items        | 0.000121 |  0.000016 |  0.000060 |
| cleaning up          | 0.000023 |  0.000015 |  0.000013 |
+----------------------+----------+  

信息一目了然，这样我就能对SQL执行情况有个大概的了解。