目录

show profile

概述

Show Profile 是什么?

  1. 是mysql提供可以用来分析当前会话中语句执行的资源消耗情况。可以用于SQL的调优测量
  2. 官网:http://dev.mysql.com/doc/refman/5.5/en/show-profile.html
  3. 默认情况下,参数处于关闭状态,并保存最近15次的运行结果

sql执行经历连接 服务 引擎 存储四个层次,show profile可以告知我们每一个操作分别花了多长时间

慢查询分析步骤

  1. 慢查询抓取
  2. explain
  3. show profile
  4. 服务器重要参数调优

分析步骤

查看是当前的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)

诊断SQLSHOW 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执行记录,该功能主要用于测试环境,在生产环境中永远不要开启该功能。

配置启用全局查询日志

  • 在mysql的my.cnf中,设置如下:
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)