分析SQL执行带来的开销是优化SQL的重要手段。在MySQL数据库中，可以通过配置profiling参数来启用SQL剖析。该参数可以在全局和session级别来设置。对于全局级别则作用于整个MySQL实例，而session级别紧影响当前session。该参数开启后，后续执行的SQL语句都将记录其资源开销，诸如IO，上下文切换，CPU，Memory等等。根据这些开销进一步分析当前SQL瓶颈从而进行优化与调整。本文描述了如何使用MySQL profile，不涉及具体的样例分析。
1、有关profile的描述
查看profiling系统变量
|
1 2 3 4 5 6 7 8 9 |
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.00 sec) |
获取profile的帮助
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 |
mysql> help profile; Name: 'SHOW PROFILE' Description: Syntax: SHOW PROFILE [type [, type] ... ] [FOR QUERY n] [LIMIT row_count [OFFSET offset]] type: ALL #显示所有的开销信息; | BLOCK IO #显示块IO相关开销; | CONTEXT SWITCHES #上下文切换相关开销; | CPU #显示CPU相关开销信息; | IPC #显示发送和接收相关开销信息; | MEMORY #显示内存相关开销信息; | PAGE FAULTS #显示页面错误相关开销信息; | SOURCE #显示和Source_function,Source_file,Source_line相关的开销信息; | SWAPS #显示交换次数相关开销的信息; |
2、开启porfiling
启用session级别的profiling
|
1 2 |
mysql> set profiling=1; Query OK, 0 rows affected, 1 warning (0.00 sec) |
验证修改后的结果
|
1 2 3 4 5 6 7 8 9 |
mysql> show variables like '%profil%'; +------------------------+-------+ | Variable_name | Value | +------------------------+-------+ | have_profiling | YES | | profiling | ON | | profiling_history_size | 15 | +------------------------+-------+ 3 rows in set (0.00 sec) |
发布SQL查询
|
1 |
mysql> select * from zabbix.history_uint where clock<1488466329 limit 1; |
查看当前session所有已产生的profile
|
1 2 3 4 5 6 7 8 |
mysql> show profiles; +----------+------------+------------------------------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+------------------------------------------------------------------+ | 1 | 0.00044625 | show variables like '%profil%' | | 2 | 6.43230200 | select * from zabbix.history_uint where clock<1488466329 limit 1 | +----------+------------+------------------------------------------------------------------+ 2 rows in set, 1 warning (0.00 sec) |
我们看到有2个warning，之前一个，现在一个
|
1 2 3 4 5 6 7 |
mysql> show warnings; +---------+------+--------------------------------------------------------------------------------------------------------------+ | Level | Code | Message | +---------+------+--------------------------------------------------------------------------------------------------------------+ | Warning | 1287 | 'SHOW PROFILES' is deprecated and will be removed in a future release. Please use Performance Schema instead | +---------+------+--------------------------------------------------------------------------------------------------------------+ 1 row in set (0.00 sec) |
告警是说SHOW PROFILES命令将来会被Performance Schema替换掉。
3、获取SQL语句的开销信息
开启profiling后，我们可以通过show profile等方式查看，其实这些开销信息被记录到information_schema.profiling表中。注show profile之类的语句不会被profiling，即自身不会产生Profiling。
我们下面的这个show profile查看的是show warnings产生的相应开销。
|
1 2 3 4 5 6 7 8 9 10 |
mysq> show profile; +----------------+----------+ | Status | Duration | +----------------+----------+ | starting | 0.000141 | | query end | 0.000058 | | closing tables | 0.000014 | | freeing items | 0.001802 | | cleaning up | 0.000272 | +----------------+----------+ |
如下面的查询show warnings被添加到profiles
|
1 2 3 4 5 6 7 8 9 |
mysql> show profiles; +----------+------------+------------------------------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+------------------------------------------------------------------+ | 1 | 0.00041150 | show variables like '%profil%' | | 2 | 6.41118075 | select * from zabbix.history_uint where clock<1488466329 limit 1 | | 3 | 0.00003900 | show warnings | +----------+------------+------------------------------------------------------------------+ 3 rows in set, 1 warning (0.00 sec) |
获取指定查询的开销（Druation表示持续时间）
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 |
mysql> show profile for query 2; +----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 0.000043 | | checking permissions | 0.000004 | | Opening tables | 0.000014 | | init | 0.000019 | | System lock | 0.000004 | | optimizing | 0.000009 | | statistics | 0.000062 | | preparing | 0.000012 | | executing | 0.000002 | | Sending data | 6.410967 | | end | 0.000009 | | query end | 0.000005 | | closing tables | 0.000010 | | freeing items | 0.000011 | | cleaning up | 0.000011 | +----------------------+----------+ 15 rows in set, 1 warning (0.00 sec) |
Sending data：这个状态的名称很具有误导性，所谓的“Sending data”并不是单纯的发送数据，而是包括“收集 + 发送 数据”。
query end：表示语句执行完毕了，但是还有一些后续工作没做完时的状态。
freeing items：释放查询缓存里面的空间，如果是DML操作，所以相应的缓存里的记录就无效了，所以需要有这一步做处理。
查看所有开销
|
1 |
mysql> show profile all for query 2 ; |
查看特定部分的开销，如下为CPU部分的开销
|
1 |
mysql> show profile cpu for query 2 ; |
如下为MEMORY部分的开销
|
1 |
mysql> show profile memory for query 2 ; |
同时查看不同资源开销
|
1 |
mysql> show profile block io,cpu for query 2; |
4、INFORMATION_SCHEMA.PROFILING
上面已经看到了，show profile命令即将移除，所以可以直接去information_schema.profiling表查看，灵活度更大，其表结构信息如下：
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 |
mysql> desc information_schema.profiling; +---------------------+--------------+------+-----+----------+-------+ | Field | Type | Null | Key | Default | Extra | +---------------------+--------------+------+-----+----------+-------+ | QUERY_ID | int(20) | NO | | 0 | | | SEQ | int(20) | NO | | 0 | | | STATE | varchar(30) | NO | | | | | DURATION | decimal(9,6) | NO | | 0.000000 | | | CPU_USER | decimal(9,6) | YES | | NULL | | | CPU_SYSTEM | decimal(9,6) | YES | | NULL | | | CONTEXT_VOLUNTARY | int(20) | YES | | NULL | | | CONTEXT_INVOLUNTARY | int(20) | YES | | NULL | | | BLOCK_OPS_IN | int(20) | YES | | NULL | | | BLOCK_OPS_OUT | int(20) | YES | | NULL | | | MESSAGES_SENT | int(20) | YES | | NULL | | | MESSAGES_RECEIVED | int(20) | YES | | NULL | | | PAGE_FAULTS_MAJOR | int(20) | YES | | NULL | | | PAGE_FAULTS_MINOR | int(20) | YES | | NULL | | | SWAPS | int(20) | YES | | NULL | | | SOURCE_FUNCTION | varchar(30) | YES | | NULL | | | SOURCE_FILE | varchar(20) | YES | | NULL | | | SOURCE_LINE | int(20) | YES | | NULL | | +---------------------+--------------+------+-----+----------+-------+ 18 rows in set (0.00 sec) |
下面的SQL语句用于查询query_id为2的SQL开销，且按最大耗用时间倒序排列
|
1 |
mysql> set @query_id=2; |
|
1 2 3 4 5 6 7 8 9 10 11 12 13 |
SELECT STATE, SUM(DURATION) AS Total_R, 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; |
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 |
+----------------------+----------+--------+-------+--------------+ | STATE | Total_R | Pct_R | Calls | R/Call | +----------------------+----------+--------+-------+--------------+ | Sending data | 6.410967 | 100.00 | 1 | 6.4109670000 | | statistics | 0.000062 | 0.00 | 1 | 0.0000620000 | | starting | 0.000043 | 0.00 | 1 | 0.0000430000 | | init | 0.000019 | 0.00 | 1 | 0.0000190000 | | Opening tables | 0.000014 | 0.00 | 1 | 0.0000140000 | | preparing | 0.000012 | 0.00 | 1 | 0.0000120000 | | cleaning up | 0.000011 | 0.00 | 1 | 0.0000110000 | | freeing items | 0.000011 | 0.00 | 1 | 0.0000110000 | | closing tables | 0.000010 | 0.00 | 1 | 0.0000100000 | | optimizing | 0.000009 | 0.00 | 1 | 0.0000090000 | | end | 0.000009 | 0.00 | 1 | 0.0000090000 | | query end | 0.000005 | 0.00 | 1 | 0.0000050000 | | System lock | 0.000004 | 0.00 | 1 | 0.0000040000 | | checking permissions | 0.000004 | 0.00 | 1 | 0.0000040000 | | executing | 0.000002 | 0.00 | 1 | 0.0000020000 | +----------------------+----------+--------+-------+--------------+ 15 rows in set (0.01 sec) |
停止profile,可以设置profiling参数，或者在session退出之后,profiling会被自动关闭。
如果您觉得本站对你有帮助，那么可以支付宝扫码捐助以帮助本站更好地发展，在此谢过。
