MySQL中show profile详解

1.SHOW PROFILE 官网

参考文档链接：https://dev.mysql.com/doc/refman/8.0/en/show-profile.html
SHOW PROFILE [type [, type] ... ] 
        [FOR QUERY n] 
        [LIMIT row_count [OFFSET offset]] 
type: { 
       ALL 
      | BLOCK IO 
      | CONTEXT SWITCHES 
      | CPU 
      | IPC 
      | MEMORY 
      | PAGE FAULTS 
      | SOURCE 
      | SWAPS 
}

2.开启show profile功能

#1.默认为：关闭，To control profiling, use the profiling session variable, which has a default value of 0 (OFF). 
               Enable profiling by setting profiling to 1 or ON:1表示开启，0表示关闭

#2，在线开启

mysql> SET profiling = 1;

3.show profile参数解析：

#1.参数

①ALL：显示所有的开销信息。

②BLOCK IO：显示块IO开销。

③CONTEXT SWITCHES：上下文切换开销。

④CPU：显示CPU开销信息。

⑤IPC：显示发送和接收开销信息。

⑥MEMORY：显示内存开销信息。

⑦PAGE FAULTS：显示页面错误开销信息。

⑧SOURCE：显示和Source_function，Source_file，Source_line相关的开销信息。

⑨SWAPS：显示交换次数开销信息。

#2:日常开发需注意的结论
①Converting HEAP to MyISAM：查询结果太大，内存不够，数据往磁盘上搬了。

②Creating tmp table：创建临时表。先拷贝数据到临时表，用完后再删除临时表。

③Copying to tmp table on disk：把内存中临时表复制到磁盘上，危险！！！

④locked。

ALL displays all information
BLOCK IO displays counts for block input and output operations
CONTEXT SWITCHES displays counts for voluntary and involuntary context switches
CPU displays user and system CPU usage times
IPC displays counts for messages sent and received
MEMORY is not currently impPAGE FAULTS displays counts for majSOURCE displays the names of functions from the source code, together with the name and line number of the file in which the funSWAPS displamysql> SELECT @@profiling+------------| @@profiling | +-------------+ | 0 mysql> SET profiling

4.举例说明

mysql> show variables like "profiling";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling     | OFF   |
+---------------+-------+
1 row in set (0.01 sec)

mysql> SET profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show variables like "profiling";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling     | ON    |
+---------------+-------+
1 row in set (0.00 sec)

mysql> show profile for query 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000082 |
| checking permissions | 0.000022 |
| Opening tables       | 0.000106 |
| init                 | 0.000011 |
| System lock          | 0.000010 |
| optimizing           | 0.000007 |
| optimizing           | 0.000010 |
| statistics           | 0.000029 |
| preparing            | 0.000021 |
| statistics           | 0.000010 |
| preparing            | 0.000013 |
| executing            | 0.001263 |
| end                  | 0.000015 |
| query end            | 0.000016 |
| closing tables       | 0.000011 |
| freeing items        | 0.000022 |
| cleaning up          | 0.000013 |
+----------------------+----------+
17 rows in set, 1 warning (0.00 sec)

mysql> show profile for query 2;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000076 |
| checking permissions | 0.000014 |
| Opening tables       | 0.000042 |
| init                 | 0.000014 |
| optimizing           | 0.000012 |
| executing            | 0.000014 |
| end                  | 0.000006 |
| query end            | 0.000008 |
| closing tables       | 0.000007 |
| freeing items        | 0.000015 |
| cleaning up          | 0.000024 |
+----------------------+----------+
11 rows in set, 1 warning (0.00 sec)

mysql> show profile for query 3;
+----------------------------+----------+
| Status                     | Duration |
+----------------------------+----------+
| starting                   | 0.000120 |
| checking permissions       | 0.000013 |
| Opening tables             | 0.000803 |
| init                       | 0.000014 |
| System lock                | 0.000009 |
| optimizing                 | 0.000018 |
| statistics                 | 0.000044 |
| preparing                  | 0.000028 |
| Creating tmp table         | 0.000367 |
| executing                  | 0.000275 |
| end                        | 0.000010 |
| query end                  | 0.000005 |
| waiting for handler commit | 0.000014 |
| closing tables             | 0.000012 |
| freeing items              | 0.000020 |
| cleaning up                | 0.000022 |
+----------------------------+----------+
16 rows in set, 1 warning (0.00 sec)

mysql> show profile cpu for query 3;
+----------------------------+----------+----------+------------+
| Status                     | Duration | CPU_user | CPU_system |
+----------------------------+----------+----------+------------+
| starting                   | 0.000120 | 0.000117 |   0.000000 |
| checking permissions       | 0.000013 | 0.000012 |   0.000000 |
| Opening tables             | 0.000803 | 0.000807 |   0.000000 |
| init                       | 0.000014 | 0.000009 |   0.000000 |
| System lock                | 0.000009 | 0.000009 |   0.000000 |
| optimizing                 | 0.000018 | 0.000017 |   0.000000 |
| statistics                 | 0.000044 | 0.000045 |   0.000000 |
| preparing                  | 0.000028 | 0.000028 |   0.000000 |
| Creating tmp table         | 0.000367 | 0.000369 |   0.000000 |
| executing                  | 0.000275 | 0.000275 |   0.000000 |
| end                        | 0.000010 | 0.000007 |   0.000000 |
| query end                  | 0.000005 | 0.000005 |   0.000000 |
| waiting for handler commit | 0.000014 | 0.000013 |   0.000000 |
| closing tables             | 0.000012 | 0.000012 |   0.000000 |
| freeing items              | 0.000020 | 0.000020 |   0.000000 |
| cleaning up                | 0.000022 | 0.000021 |   0.000000 |
+----------------------------+----------+----------+------------+
16 rows in set, 1 warning (0.00 sec)

mysql> show profile all for query 1;
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
| Status               | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent | Messages_received | Page_faults_major | Page_faults_minor | Swaps | Source_function       | Source_file          | Source_line |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
| starting             | 0.000082 | 0.000027 |   0.000052 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | NULL                  | NULL                 |        NULL |
| checking permissions | 0.000022 | 0.000008 |   0.000014 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | check_access          | sql_authorization.cc |        2200 |
| Opening tables       | 0.000106 | 0.000036 |   0.000069 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_tables           | sql_base.cc          |        5761 |
| init                 | 0.000011 | 0.000003 |   0.000006 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | execute               | sql_select.cc        |         552 |
| System lock          | 0.000010 | 0.000004 |   0.000007 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc              |         331 |
| optimizing           | 0.000007 | 0.000002 |   0.000005 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | optimize              | sql_optimizer.cc     |         277 |
| optimizing           | 0.000010 | 0.000004 |   0.000006 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | optimize              | sql_optimizer.cc     |         277 |
| statistics           | 0.000029 | 0.000010 |   0.000020 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | optimize              | sql_optimizer.cc     |         590 |
| preparing            | 0.000021 | 0.000007 |   0.000013 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | optimize              | sql_optimizer.cc     |         674 |
| statistics           | 0.000010 | 0.000003 |   0.000007 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | optimize              | sql_optimizer.cc     |         590 |
| preparing            | 0.000013 | 0.000005 |   0.000008 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | optimize              | sql_optimizer.cc     |         674 |
| executing            | 0.001263 | 0.001267 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 7 |     0 | ExecuteIteratorQuery  | sql_union.cc         |        1127 |
| end                  | 0.000015 | 0.000011 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | execute               | sql_select.cc        |         585 |
| query end            | 0.000016 | 0.000016 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_execute_command | sql_parse.cc         |        4566 |
| closing tables       | 0.000011 | 0.000011 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_execute_command | sql_parse.cc         |        4624 |
| freeing items        | 0.000022 | 0.000021 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | dispatch_sql_command  | sql_parse.cc         |        5075 |
| cleaning up          | 0.000013 | 0.000013 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | dispatch_command      | sql_parse.cc         |        2276 |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+
17 rows in set, 1 warning (0.00 sec)

5.注意

1.Show Profile默认是关闭的，并且开启后只存活于当前会话，也就说每次使用前都需要开启。也可修改MYSQL配置文件来修改。

2.通过Show Profiles查看sql语句的耗时时间，然后通过Show Profile命令对耗时时间长的sql语句进行诊断。

3.注意Show Profile诊断结果中出现相关字段的含义，判断是否需要优化SQL语句。

mysql>SELECT@@profiling;+-------------+| @@profiling |+-------------+| 0 |+-------------+1 row in set (0.00 sec)mysql>SET profiling =1;Query OK, 0 rows affected (0.00 sec)mysql>DROPTABLEIFEXISTS t1;Query OK, 0 rows affected, 1 warning (0.00 sec)mysql>CREATETABLE T1 (id INT);Query OK, 0 rows affected (0.01 sec)mysql>SHOWPROFILES;+----------+----------+--------------------------+| Query_ID | Duration | Query |+----------+----------+--------------------------+| 0 | 0.000088 | SET PROFILING = 1 || 1 | 0.000136 | DROP TABLE IF EXISTS t1 || 2 | 0.011947 | CREATE TABLE t1 (id INT) |+----------+----------+--------------------------+3 rows in set (0.00 sec)mysql>SHOWPROFILE;+----------------------+----------+| Status | Duration |+----------------------+----------+| checking permissions | 0.000040 || creating table | 0.000056 || After create | 0.011363 || query end | 0.000375 || freeing items | 0.000089 || logging slow query | 0.000019 || cleaning up | 0.000005 |+----------------------+----------+7 rows in set (0.00 sec)mysql>SHOWPROFILEFORQUERY1;+--------------------+----------+| Status | Duration |+--------------------+----------+| query end | 0.000107 || freeing items | 0.000008 || logging slow query | 0.000015 || cleaning up | 0.000006 |+--------------------+----------+4 rows in set (0.00 sec)mysql>SHOWPROFILECPUFORQUERY2;+----------------------+----------+----------+------------+| Status | Duration | CPU_user | CPU_system |+----------------------+----------+----------+------------+| checking permissions | 0.000040 | 0.000038 | 0.000002 || creating table | 0.000056 | 0.000028 | 0.000028 || After create | 0.011363 | 0.000217 | 0.001571 || query end | 0.000375 | 0.000013 | 0.000028 || freeing items | 0.000089 | 0.000010 | 0.000014 || logging slow query | 0.000019 | 0.000009 | 0.000010 || cleaning up | 0.000005 | 0.000003 | 0.000002 |+----------------------+----------+----------+------------+7 rows in set (0.00 sec)

posted @ 2022-08-29 15:59 Linux运维-Friend 阅读(254) 评论(0) 收藏举报

刷新页面返回顶部

MySQL中show profile详解

公告