问题描述
如何分析SQL执行带来的开销从而进行优化与调整。
问题分析
SHOW PROFILE and SHOW PROFILES 语句显示分析信息，指示在当前会话过程中执行的语句的资源使用情况。
解决方案
1.查看当前profiling的系统变量配置
MySQL [(none)]> show variables like '%profil%';
+------------------------+-------+
| Variable_name | Value |
+------------------------+-------+
| have_profiling | YES |
| profiling | OFF |
| profiling_history_size | 15 |
+------------------------+-------+
3 rows in set (0.002 sec)
- profiling_history_size: session记录数量的控制，默认值为 15。最大值为 100
- profiling：0或OFF表示关闭(默认模式)。1或ON表示开启
2.开启profiling
SET profiling = 1;
3.执行SQL并查看记录
MySQL [mdb]> select * from t1;
+---------------------+
| c1 |
+---------------------+
| 2021-01-03 00:00:00 |
| 2019-02-03 00:00:00 |
| 0000-00-00 00:00:00 |
| 0000-00-00 00:00:00 |
| 0001-01-01 00:00:00 |
| 0001-01-01 00:00:00 |
| 0001-01-01 00:00:00 |
+---------------------+
7 rows in set (0.000 sec)
MySQL [mdb]> update t1 set c1="2020-00-00 00:00:00" where c1="0000-00-00 00:00:00";
Query OK, 2 rows affected (0.002 sec)
Rows matched: 2 Changed: 2 Warnings: 0
MySQL [mdb]> show profiles;
+----------+------------+-----------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+-----------------------------------------------------------------------+
| 1 | 0.00027475 | select * from t1 | |
| 2 | 0.00199325 | update t1 set c1="2020-00-00 00:00:00" where c1="0000-00-00 00:00:00" |
+----------+------------+-----------------------------------------------------------------------+
2 rows in set, 1 warning (0.000 sec)
4.查看第一个SQL的执行情况
MySQL [mdb]> SHOW PROFILE FOR QUERY 1;
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000081 |
| Executing hook on transaction | 0.000005 |
| starting | 0.000009 |
| checking permissions | 0.000007 |
| Opening tables | 0.000029 |
| init | 0.000007 |
| System lock | 0.000009 |
| optimizing | 0.000004 |
| statistics | 0.000010 |
| preparing | 0.000014 |
| executing | 0.000039 |
| end | 0.000004 |
| query end | 0.000004 |
| waiting for handler commit | 0.000008 |
| closing tables | 0.000007 |
| freeing items | 0.000029 |
| cleaning up | 0.000011 |
+--------------------------------+----------+
17 rows in set, 1 warning (0.000 sec)
5.查看第一条SQL的CPU执行情况
MySQL [mdb]> SHOW PROFILE CPU FOR QUERY 1;
+--------------------------------+----------+----------+------------+
| Status | Duration | CPU_user | CPU_system |
+--------------------------------+----------+----------+------------+
| starting | 0.000081 | 0.000000 | 0.000076 |
| Executing hook on transaction | 0.000005 | 0.000000 | 0.000004 |
| starting | 0.000009 | 0.000000 | 0.000009 |
| checking permissions | 0.000007 | 0.000000 | 0.000007 |
| Opening tables | 0.000029 | 0.000000 | 0.000028 |
| init | 0.000007 | 0.000000 | 0.000007 |
| System lock | 0.000009 | 0.000000 | 0.000009 |
| optimizing | 0.000004 | 0.000000 | 0.000004 |
| statistics | 0.000010 | 0.000000 | 0.000010 |
| preparing | 0.000014 | 0.000000 | 0.000014 |
| executing | 0.000039 | 0.000000 | 0.000039 |
| end | 0.000004 | 0.000000 | 0.000004 |
| query end | 0.000004 | 0.000000 | 0.000003 |
| waiting for handler commit | 0.000008 | 0.000000 | 0.000008 |
| closing tables | 0.000007 | 0.000000 | 0.000007 |
| freeing items | 0.000029 | 0.000000 | 0.000030 |
| cleaning up | 0.000011 | 0.000000 | 0.000010 |
+--------------------------------+----------+----------+------------+
17 rows in set, 1 warning (0.000 sec)
6.在 INFORMATION_SCHEMA PROFILING表中也可以获取分析信息
MySQL [mdb]> SELECT STATE, FORMAT(DURATION, 6) AS DURATION FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = 1 ORDER BY SEQ;
+--------------------------------+----------+
| STATE | DURATION |
+--------------------------------+----------+
| starting | 0.000081 |
| Executing hook on transaction | 0.000005 |
| starting | 0.000009 |
| checking permissions | 0.000007 |
| Opening tables | 0.000029 |
| init | 0.000007 |
| System lock | 0.000009 |
| optimizing | 0.000004 |
| statistics | 0.000010 |
| preparing | 0.000014 |
| executing | 0.000039 |
| end | 0.000004 |
| query end | 0.000004 |
| waiting for handler commit | 0.000008 |
| closing tables | 0.000007 |
| freeing items | 0.000029 |
| cleaning up | 0.000011 |
+--------------------------------+----------+
17 rows in set, 1 warning (0.001 sec)
参考连接
https://dev.mysql.com/doc/refman/5.7/en/show-profile.html
如果您有其他问题，欢迎您联系火山引擎技术支持服务
