概述
Show Profile 是什么？
- 是mysql提供可以用来分析当前会话中语句执行的资源消耗情况。可以用于SQL的调优测量
- 官网：http://dev.mysql.com/doc/refman/5.5/en/show-profile.html
- 默认情况下，参数处于关闭状态，并保存最近15次的运行结果
sql执行经历连接 服务 引擎 存储四个层次，show profile可以告知我们每一个操作分别花了多长时间
慢查询分析步骤
- 慢查询抓取
- explain
- show profile
- 服务器重要参数调优
分析步骤
查看是当前的SQL版本是否支持Show Profile
1
2
3
4
5
6
7
8
|
# 查看Show Profile功能是否开启
mysql> SHOW VARIABLES LIKE 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling | OFF |
+---------------+-------+
1 row in set (0.00 sec)
|
开启功能 Show Profile ，默认是关闭，使用前需要开启
1
2
3
|
# 开启Show Profile功能
mysql> SET profiling=ON;
Query OK, 0 rows affected, 1 warning (0.00 sec)
|
运行SQL
1
2
|
SELECT * FROM `emp` GROUP BY `id`%10 LIMIT 150000;
SELECT * FROM `emp` GROUP BY `id`%20 ORDER BY 5;
|
查看结果，执行SHOW PROFILES;
Duration：持续时间。
1
2
3
4
5
6
7
8
9
10
|
mysql> SHOW PROFILES;
+----------+------------+---------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+---------------------------------------------------+
| 1 | 0.00156100 | SHOW VARIABLES LIKE 'profiling' |
| 2 | 0.56296725 | SELECT * FROM `emp` GROUP BY `id`%10 LIMIT 150000 |
| 3 | 0.52105825 | SELECT * FROM `emp` GROUP BY `id`%10 LIMIT 150000 |
| 4 | 0.51279775 | SELECT * FROM `emp` GROUP BY `id`%20 ORDER BY 5 |
+----------+------------+---------------------------------------------------+
4 rows in set, 1 warning (0.00 sec)
|
诊断SQL，SHOW PROFILE cpu,block io FOR QUERY Query_ID;
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
|
# 这里的3是第四步中的Query_ID。
# 可以在SHOW PROFILE中看到一条SQL中完整的生命周期。
# sql导致查询慢，要么cpu计算复杂，要么频繁io
mysql> SHOW PROFILE cpu,block io FOR QUERY 3;
+----------------------+----------+----------+------------+--------------+---------------+
| Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting | 0.000097 | 0.000090 | 0.000002 | 0 | 0 |
| checking permissions | 0.000010 | 0.000009 | 0.000000 | 0 | 0 |
| Opening tables | 0.000039 | 0.000058 | 0.000000 | 0 | 0 |
| init | 0.000046 | 0.000046 | 0.000000 | 0 | 0 |
| System lock | 0.000011 | 0.000000 | 0.000000 | 0 | 0 |
| optimizing | 0.000005 | 0.000000 | 0.000000 | 0 | 0 |
| statistics | 0.000023 | 0.000037 | 0.000000 | 0 | 0 |
| preparing | 0.000014 | 0.000000 | 0.000000 | 0 | 0 |
| Creating tmp table | 0.000041 | 0.000053 | 0.000000 | 0 | 0 |
| Sorting result | 0.000005 | 0.000000 | 0.000000 | 0 | 0 |
| executing | 0.000003 | 0.000000 | 0.000000 | 0 | 0 |
| Sending data | 0.520620 | 0.516267 | 0.000000 | 0 | 0 |
| Creating sort index | 0.000060 | 0.000051 | 0.000000 | 0 | 0 |
| end | 0.000006 | 0.000000 | 0.000000 | 0 | 0 |
| query end | 0.000011 | 0.000000 | 0.000000 | 0 | 0 |
| removing tmp table | 0.000006 | 0.000000 | 0.000000 | 0 | 0 |
| query end | 0.000004 | 0.000000 | 0.000000 | 0 | 0 |
| closing tables | 0.000009 | 0.000000 | 0.000000 | 0 | 0 |
| freeing items | 0.000032 | 0.000064 | 0.000000 | 0 | 0 |
| cleaning up | 0.000019 | 0.000000 | 0.000000 | 0 | 0 |
+----------------------+----------+----------+------------+--------------+---------------+
20 rows in set, 1 warning (0.00 sec)
|
Show Profile查询参数备注：
ALL：显示所有的开销信息。BLOCK IO：显示块IO相关开销（通用）。CONTEXT SWITCHES：上下文切换相关开销。CPU：显示CPU相关开销信息（通用）。IPC：显示发送和接收相关开销信息。MEMORY：显示内存相关开销信息。PAGE FAULTS：显示页面错误相关开销信息。SOURCE：显示和Source_function。SWAPS：显示交换次数相关开销的信息。
Show Profile查询列表，日常开发需要注意的结论：
-
converting HEAP to MyISAM：查询结果太大，内存都不够用了，往磁盘上搬了。
-
Creating tmp table：创建临时表（拷贝数据到临时表，用完再删除），非常耗费数据库性能。
Sorting result 对应 Filesort
-
Copying to tmp table on disk：把内存中的临时表复制到磁盘，危险！！！
-
locked：死锁。
全局查询日志
全局查询日志用于保存所有的sql执行记录，该功能主要用于测试环境，在生产环境中永远不要开启该功能。
配置启用全局查询日志
1
2
3
4
5
6
7
8
|
# 开启
general_log=1
# 记录日志文件的路径
general_log_file=/path/logfile
# 输出格式
log_output=FILE
|
编码启用全局查询日志
1
2
|
set global general_log=1;
set global log_output='TABLE';
|
- 此后，你所执行的sql语句，将会记录到mysql库里的general_log表，可以用下面的命令查看
1
|
select * from mysql.general_log;
|
1
2
3
4
5
6
7
8
9
|
mysql> select * from mysql.general_log;
+---------------------+---------------------------+-----------+-----------+--------------+-----------------------------------------------+
| event_time | user_host | thread_id | server_id | command_type | argument |
+---------------------+---------------------------+-----------+-----------+--------------+-----------------------------------------------+
| 2020-08-05 14:41:07 | root[root] @ localhost [] | 14 | 0 | Query | select * from emp group by id%10 limit 150000 |
| 2020-08-05 14:41:12 | root[root] @ localhost [] | 14 | 0 | Query | select COUNT(*) from emp |
| 2020-08-05 14:41:30 | root[root] @ localhost [] | 14 | 0 | Query | select * from mysql.general_log |
+---------------------+---------------------------+-----------+-----------+--------------+-----------------------------------------------+
3 rows in set (0.00 sec)
|