前言：
而今看官们对“mysqlprofiling详解”都比较讲究，各位老铁们都想要剖析一些“mysqlprofiling详解”的相关资讯。那么小编也在网络上网罗了一些有关“mysqlprofiling详解””的相关知识，希望小伙伴们能喜欢，大家快快来了解一下吧！关注我「程序猿集锦」获取更多分享。
前言开启profiling功能查看profiling记录的SQL列表profiling记录的SQL语句详细信息BLOCK IOCONTEXT SWITCHESCPUIPCPAGE FAULTSSOURCESWAPSALLINFORMATION_SCHEMA.PROFILING使用performance_schema下面的表来分析SQLperformance_schema.setup_actorsperformance_schema.setup_instrumentsperformance_schema.setup_consumersperformance_schema.events_statements_history_longperformance_schema.events_stages_history_long总结前言
当我们发现一个SQL语句执行特别慢的时候，我们不确定它到底为什么慢，慢在了哪里，此时我们可以通过MySQL自带的profiling功能去分析这个慢的SQL语句到底在执行的哪一个环节慢。
profiling的功能记录了SQL语句在执行的过程中每一个环境对资源的使用情况，包括CPU、内存、I/O等各种资源的使用情况都有详细的记录。我们可以通过这里的记录来定位我们的SQL就是是哪个环节拖垮了整个SQL的执行时间。
开启profiling功能
在默认情况下，MySQL是没有开启profiling功能的，可以通过下面的命令来查看当前的MySQL是否开启了profiling功能。
mysql> show variables like '%profiling%';+------------------------+-------+| Variable_name | Value |+------------------------+-------+| have_profiling | YES |/*表示当前的MySQL版本是否支持profiling功能。*/| profiling | OFF |/*表示当前MySQL的profiling功能是否已经开启，ON为开启，OFF为关闭。*/| profiling_history_size | 15 |/*表示当前profiling功能所能记录的SQL语句的最大数目。*/+------------------------+-------+3 rows in set (0.00 sec)mysql>
开启profiling功能的方式可以通过如下的命令，下面两个命令的任何一个命令都可以开启profiling功能。
mysql> set profiling=1;Query OK, 0 rows affected, 1 warning (0.00 sec)mysql> set profiling=on;Query OK, 0 rows affected, 1 warning (0.00 sec)mysql> show variables like '%profiling%';+------------------------+-------+| Variable_name | Value |+------------------------+-------+| have_profiling | YES || profiling | ON || profiling_history_size | 15 |+------------------------+-------+3 rows in set (0.00 sec)mysql>
profiling不会记录所有的SQL语句执行过程对资源的使用情况，默认只会记录最近15条SQL语句对服务器资源的使用情况。如果想修改记录SQL语句，可以通过参数profiling_history_size参数来实现。这个参数的取值范围为[0,100]，默认为15。如果记录的数目达到最大值15之后，新被执行的SQL语句会覆盖之前执行的SQL语句，仅仅保留最近最新的15条SQL语句。如果修改为0，则表示关闭了profiling的功能，和设置profiling=0、profiling=off的功能是一样的。
虽然profiling会记录所有的SQL语句对资源的使用情况，但是它不会记录show profiles和show profile这样的SQL语句对资源的使用情况，也就是说他不会记录它自己在执行的过程中对资源的消耗情况。
查看profiling记录的SQL列表
在开启了profiling功能之后，我们可以通过如下的命令查看profiling记录的SQL语句有哪些。
mysql> show profiles;+----------+------------+----------------------------------------------------------------------+| Query_ID | Duration | Query |+----------+------------+----------------------------------------------------------------------+| 3 | 0.00110100 | set profiling=on || 4 | 0.00453800 | show variables like '%profiling%' || 5 | 0.01818100 | show databases || 6 | 0.00376500 | SELECT DATABASE() || 7 | 0.00932000 | show databases || 8 | 0.00321300 | show tables || 9 | 0.00070100 | show tables || 10 | 0.01077600 | select * from feng || 11 | 0.09039000 | select * from test || 12 | 0.00236400 | show profiles for query 11 || 13 | 0.00444200 | show tables || 14 | 0.02663000 | desc test || 15 | 0.94789800 | select * from test order by variable_value desc ,variable_name asc |+----------+------------+----------------------------------------------------------------------+13 rows in set, 1 warning (0.00 sec)mysql>Query_ID表示当前记录的SQL语句的ID编号。Duration表示对用的SQL语句执行的实际，单位是秒。Query表示当前记录的SQL语句的具体内容。profiling记录的SQL语句详细信息
profiling对每一个SQL语句使用资源的记录，我们可以通过下面的命令来查看。
mysql> show profile for query 15;/*query后面跟的就是通过show profiles命令输出的Query_ID的值。*/+----------------------+----------+| Status | Duration |+----------------------+----------+| starting | 0.000062 || checking permissions | 0.000008 || Opening tables | 0.000015 || init | 0.000022 || System lock | 0.000007 || optimizing | 0.000005 || statistics | 0.000012 || preparing | 0.000788 || Sorting result | 0.000013 || executing | 0.000004 || Sending data | 0.000011 || Creating sort index | 0.946867 |/*这里可以看到，在创建排序索引的时候，消耗的实际最长。*/| end | 0.000008 || query end | 0.000008 || closing tables | 0.000006 || freeing items | 0.000048 || cleaning up | 0.000014 |+----------------------+----------+17 rows in set, 1 warning (0.00 sec)mysql>
上面命令中的show profile for query关键字后面跟的就是通过show profiles命令输出的Query_ID的值。
如果我们查看更为详细的信息，可以通过如下命令查看：
show profile ALL for query 15;
在profile和for中间可以有如下参数，注意包括但不仅限于下面几个参数，这里只列出重要的几个参数。
BLOCK IO
BLOCK IO可以显示出数据块读取的数量。示例如下：
mysql> show profile BLOCK IO for query 17;+----------------------+----------+--------------+---------------+| Status | Duration | Block_ops_in | Block_ops_out |+----------------------+----------+--------------+---------------+| starting | 0.000062 | 0 | 0 || checking permissions | 0.000008 | 0 | 0 || Opening tables | 0.000015 | 0 | 0 || init | 0.000022 | 0 | 0 || System lock | 0.000007 | 0 | 0 || optimizing | 0.000005 | 0 | 0 || statistics | 0.000012 | 0 | 0 || preparing | 0.000788 | 0 | 0 || Sorting result | 0.000013 | 0 | 0 || executing | 0.000004 | 0 | 0 || Sending data | 0.000011 | 0 | 0 || Creating sort index | 0.946867 | 0 | 0 || end | 0.000008 | 0 | 0 || query end | 0.000008 | 0 | 0 || closing tables | 0.000006 | 0 | 0 || freeing items | 0.000048 | 0 | 0 || cleaning up | 0.000014 | 0 | 0 |+----------------------+----------+--------------+---------------+17 rows in set, 1 warning (0.00 sec)mysql>CONTEXT SWITCHES
CONTEXT SWITCHES可以显示自愿和非自愿上下文切换的次数。示例如下：
mysql> show profile CONTEXT SWITCHES for query 17;+----------------------+----------+-------------------+---------------------+| Status | Duration | Context_voluntary | Context_involuntary |+----------------------+----------+-------------------+---------------------+| starting | 0.000062 | 0 | 0 || checking permissions | 0.000008 | 0 | 0 || Opening tables | 0.000015 | 0 | 0 || init | 0.000022 | 0 | 0 || System lock | 0.000007 | 0 | 0 || optimizing | 0.000005 | 0 | 0 || statistics | 0.000012 | 0 | 0 || preparing | 0.000788 | 0 | 1 || Sorting result | 0.000013 | 0 | 0 || executing | 0.000004 | 0 | 0 || Sending data | 0.000011 | 0 | 0 || Creating sort index | 0.946867 | 559 | 589 || end | 0.000008 | 0 | 0 || query end | 0.000008 | 0 | 0 || closing tables | 0.000006 | 0 | 0 || freeing items | 0.000048 | 1 | 0 || cleaning up | 0.000014 | 0 | 0 |+----------------------+----------+-------------------+---------------------+17 rows in set, 1 warning (0.00 sec)mysql>CPU
CPU可以显示出各个环节对CPU资源使用的情况。示例如下：
mysql> show profile CPU for query 17;+----------------------+----------+----------+------------+| Status | Duration | CPU_user | CPU_system |+----------------------+----------+----------+------------+| starting | 0.000062 | 0.000056 | 0.000007 || checking permissions | 0.000008 | 0.000005 | 0.000002 || Opening tables | 0.000015 | 0.000014 | 0.000001 || init | 0.000022 | 0.000020 | 0.000001 || System lock | 0.000007 | 0.000007 | 0.000001 || optimizing | 0.000005 | 0.000003 | 0.000001 || statistics | 0.000012 | 0.000011 | 0.000001 || preparing | 0.000788 | 0.000016 | 0.000113 || Sorting result | 0.000013 | 0.000007 | 0.000006 || executing | 0.000004 | 0.000002 | 0.000001 || Sending data | 0.000011 | 0.000010 | 0.000002 || Creating sort index | 0.946867 | 0.405542 | 0.293859 || end | 0.000008 | 0.000003 | 0.000005 || query end | 0.000008 | 0.000006 | 0.000002 || closing tables | 0.000006 | 0.000006 | 0.000000 || freeing items | 0.000048 | 0.000010 | 0.000028 || cleaning up | 0.000014 | 0.000010 | 0.000003 |+----------------------+----------+----------+------------+17 rows in set, 1 warning (0.00 sec)mysql>IPC
IPC可以显示发送和接收消息的数目。示例如下：
mysql> show profile IPC for query 17;+----------------------+----------+---------------+-------------------+| Status | Duration | Messages_sent | Messages_received |+----------------------+----------+---------------+-------------------+| starting | 0.000062 | 0 | 0 || checking permissions | 0.000008 | 0 | 0 || Opening tables | 0.000015 | 0 | 0 || init | 0.000022 | 0 | 0 || System lock | 0.000007 | 0 | 0 || optimizing | 0.000005 | 0 | 0 || statistics | 0.000012 | 0 | 0 || preparing | 0.000788 | 0 | 0 || Sorting result | 0.000013 | 0 | 0 || executing | 0.000004 | 0 | 0 || Sending data | 0.000011 | 0 | 0 || Creating sort index | 0.946867 | 874 | 0 || end | 0.000008 | 0 | 0 || query end | 0.000008 | 0 | 0 || closing tables | 0.000006 | 0 | 0 || freeing items | 0.000048 | 3 | 0 || cleaning up | 0.000014 | 0 | 0 |+----------------------+----------+---------------+-------------------+17 rows in set, 1 warning (0.01 sec)mysql>PAGE FAULTS
PAGE FAULTS可以显示主要和次要页面错误的统计数。示例如下：
mysql> show profile PAGE FAULTS for query 17;+----------------------+----------+-------------------+-------------------+| Status | Duration | Page_faults_major | Page_faults_minor |+----------------------+----------+-------------------+-------------------+| starting | 0.000062 | 0 | 0 || checking permissions | 0.000008 | 0 | 0 || Opening tables | 0.000015 | 0 | 0 || init | 0.000022 | 0 | 0 || System lock | 0.000007 | 0 | 0 || optimizing | 0.000005 | 0 | 0 || statistics | 0.000012 | 0 | 0 || preparing | 0.000788 | 1 | 0 || Sorting result | 0.000013 | 0 | 0 || executing | 0.000004 | 0 | 0 || Sending data | 0.000011 | 0 | 0 || Creating sort index | 0.946867 | 29 | 885 || end | 0.000008 | 0 | 0 || query end | 0.000008 | 0 | 0 || closing tables | 0.000006 | 0 | 0 || freeing items | 0.000048 | 0 | 0 || cleaning up | 0.000014 | 0 | 0 |+----------------------+----------+-------------------+-------------------+17 rows in set, 1 warning (0.00 sec)mysql>SOURCE
SOURCE可以显示源代码中函数的名称，以及函数所在的文件的名称和行号。示例如下：
mysql> show profile SOURCE for query 17;+----------------------+----------+-----------------------+----------------------+-------------+| Status | Duration | Source_function | Source_file | Source_line |+----------------------+----------+-----------------------+----------------------+-------------+| starting | 0.000062 | NULL | NULL | NULL || checking permissions | 0.000008 | check_access | sql_authorization.cc | 809 || Opening tables | 0.000015 | open_tables | sql_base.cc | 5781 || init | 0.000022 | handle_query | sql_select.cc | 128 || System lock | 0.000007 | mysql_lock_tables | lock.cc | 330 || optimizing | 0.000005 | optimize | sql_optimizer.cc | 158 || statistics | 0.000012 | optimize | sql_optimizer.cc | 374 || preparing | 0.000788 | optimize | sql_optimizer.cc | 482 || Sorting result | 0.000013 | make_tmp_tables_info | sql_select.cc | 3849 || executing | 0.000004 | exec | sql_executor.cc | 126 || Sending data | 0.000011 | exec | sql_executor.cc | 202 || Creating sort index | 0.946867 | sort_table | sql_executor.cc | 2621 || end | 0.000008 | handle_query | sql_select.cc | 206 || query end | 0.000008 | mysql_execute_command | sql_parse.cc | 4956 || closing tables | 0.000006 | mysql_execute_command | sql_parse.cc | 5009 || freeing items | 0.000048 | mysql_parse | sql_parse.cc | 5622 || cleaning up | 0.000014 | dispatch_command | sql_parse.cc | 1931 |+----------------------+----------+-----------------------+----------------------+-------------+17 rows in set, 1 warning (0.00 sec)mysql>SWAPS
SWAPS可以显示交换的统计数目。示例如下：
mysql> show profile SWAPS for query 17;+----------------------+----------+-------+| Status | Duration | Swaps |+----------------------+----------+-------+| starting | 0.000062 | 0 || checking permissions | 0.000008 | 0 || Opening tables | 0.000015 | 0 || init | 0.000022 | 0 || System lock | 0.000007 | 0 || optimizing | 0.000005 | 0 || statistics | 0.000012 | 0 || preparing | 0.000788 | 0 || Sorting result | 0.000013 | 0 || executing | 0.000004 | 0 || Sending data | 0.000011 | 0 || Creating sort index | 0.946867 | 0 || end | 0.000008 | 0 || query end | 0.000008 | 0 || closing tables | 0.000006 | 0 || freeing items | 0.000048 | 0 || cleaning up | 0.000014 | 0 |+----------------------+----------+-------+17 rows in set, 1 warning (0.00 sec)mysql>ALL
ALL可以查看某个SQL语句资源消耗的全部详细信息，前面列举的各个指标的集合。
我们通过上面的show profile for query XXX可以清楚的看出某一个SQL语句在各个环节对资源使用的情况和他们消耗的实际时间，然后我们就可以有针对性的去对SQL语句进行优化了。
INFORMATION_SCHEMA.PROFILING
我们除了通过如下命令来查看SQL语句对资源的使用情况之外，
show profiles;show profile for query xx;show profile xxx for query yyy;
还可以通过information_schema.profiling表中的信息开查看SQL语句对资源的消耗情况。这个表中记录的信息和使用上面的命令查询的结果是一致的。所以使用命令和查询表这两种方式都可以查看SQL语句对资源的消耗情况。
select * from information_schema.profiling; /*查看所有的SQL语句对资源的使用情况*/select * from information_schema.profiling where query_id=XXX order by seq asc; /*查看指定的SQL语句对资源的使用情况*/使用performance_schema下面的表来分析SQL
show profiles命令已经过时，在未来的MySQL版本中这个功能模块将会被移除，但是MySQL也提供了新的支持类似于profiling功能的模块。就是通过配置performance_schema下面的一些表来完成类似于profiling的功能。
涉及到的表主要有以下几张表：
setup_actors：这个表用于配置哪些用户发起的SQL语句会被记录下来。setup_instruments：这个表用于配置记录SQL语句的哪些指标。setup_consumers：这个表用于配置记录SQL语句的哪些指标。这个表不支持增加和删除里面初始化的记录，只支持修改和查询已经存在的记录。events_statements_history_long：这个表用于记录哪些SQL语句的执行过程被记录下来了。里面存储着类似于show profiles命令输出的SQL列表结果。events_stages_history_long：这个表用于记录详细的SQL语句性能指标。里面存储着类似于show profiles for query XXX命令输出的结果。performance_schema.setup_actors
performance_schema下面的setup_actors表结构如下：它主要用来配置需要对哪些用户的SQL语句进行分析和记录。
mysql> desc performance_schema.setup_actors;+---------+------------------+------+-----+---------+-------+| Field | Type | Null | Key | Default | Extra |+---------+------------------+------+-----+---------+-------+| HOST | char(60) | NO | | % | || USER | char(32) | NO | | % | || ROLE | char(16) | NO | | % | || ENABLED | enum('YES','NO') | NO | | YES | || HISTORY | enum('YES','NO') | NO | | YES | |+---------+------------------+------+-----+---------+-------+5 rows in set (0.00 sec)mysql>其中各个字段的具体含义简单列出：
HOST：表示用户连接到MySQL的IP地址段。USER：表示MySQL用户的名称。ROLE：MySQL用户的角色名称，MySQL8.0中才支持角色的概念，如果是5.7版本，这个应该不用关系。ENABLED：是否开启SQL语句的记录功能。YES开启，NO不开启。HISTORY：是否记录历史的SQL语句。YES记录，NO不记录。
表setup_actors中的初始化数据只有一行，如下所示。这表示MySQL中的任何用户执行的SQL对资源的使用情况都会被记录下来。
mysql> select * from performance_schema.setup_actors;+------+------+------+---------+---------+| HOST | USER | ROLE | ENABLED | HISTORY |+------+------+------+---------+---------+| % | % | % | YES | YES |+------+------+------+---------+---------+1 row in set (0.00 sec)mysql>
但是通常情况下，我们不会记录所有用户的SQL执行的详细信息，而是指定某一个应用使用的用户下面的SQL。所以我们会把这一行初始化的数据中的两个YES修改为NO。
mysql> update performance_schema.setup_actors set enabled = 'NO' , history = 'NO' where host = '%' and user = '%' and role = '%';Query OK, 0 rows affected (0.00 sec)Rows matched: 1 Changed: 0 Warnings: 0mysql> select * from performance_schema.setup_actors;+------+------+------+---------+---------+| HOST | USER | ROLE | ENABLED | HISTORY |+------+------+------+---------+---------+| % | % | % | NO | NO |+------+------+------+---------+---------+1 row in set (0.00 sec)mysql>
然后再插入一行数据，指定的一个用户信息，这样就可以只针对指定的用户进行SQL性能的监控和记录。我们这里配置root用户的SQL语句进行记录。
mysql> insert into performance_schema.setup_actors values ('%', 'root', '%', 'YES', 'YES');Query OK, 1 row affected (0.00 sec)mysql> select * from performance_schema.setup_actors;+------+------+------+---------+---------+| HOST | USER | ROLE | ENABLED | HISTORY |+------+------+------+---------+---------+| % | % | % | NO | NO || % | root | % | YES | YES |+------+------+------+---------+---------+2 rows in set (0.00 sec)mysql>相比前面我们提到的set profiling=on;一刀切的方式，这样的实现更加的人性化，符合软件开发中的低耦合的思想。
performance_schema.setup_instruments
表setup_instruments中内容，配置着哪些事件可以被记录收集。这个表中不支持truncate操作，只能对其进行update操作。表中的结构如下所示：
mysql> desc performance_schema.setup_instruments;+---------+------------------+------+-----+---------+-------+| Field | Type | Null | Key | Default | Extra |+---------+------------------+------+-----+---------+-------+| NAME | varchar(128) | NO | | NULL | || ENABLED | enum('YES','NO') | NO | | NULL | || TIMED | enum('YES','NO') | NO | | NULL | |+---------+------------------+------+-----+---------+-------+3 rows in set (0.00 sec)mysql>表中各个字段的含义如下所示：
NAME：具体的事件名称，大致分为四类事件。ENABLED：是否启用记录事件的功能，YES表示启用，NO表示不启用。TIMED：是否启用记录该事件的执行时间，YES表示启用，NO表示不启用。
表里面的配置选项大致分为如下四大类配置选项。其中每一类配置选项中又包含更细粒度的配置。
memory：内存的各个事件。stage：SQL各个阶段的事件。statement：SQL语句的各个事件。wait：等待的各个事件。
当我们要观察记录SQL运行整个生命周期的详细信息的时候，一般配置stage和statement两大类的配置就可以了。配置过程一般为如下所示：其中有一些事件的配置，默认就是YES选项，这个可以从结果输出中看出来。
mysql> update performance_schema.setup_instruments set enabled = 'YES', timed = 'YES' where name like '%stage/%';Query OK, 128 rows affected (0.00 sec)Rows matched: 137 Changed: 128 Warnings: 0mysql> update performance_schema.setup_instruments set enabled = 'YES', timed = 'YES' where name like '%statement/%';Query OK, 22 rows affected (0.00 sec)Rows matched: 215 Changed: 22 Warnings: 0mysql> select * from performance_schema.setup_instruments where name like '%stage/%' order by name limit 5;+--------------------------------------------+---------+-------+| NAME | ENABLED | TIMED |+--------------------------------------------+---------+-------+| stage/innodb/alter table (end) | YES | YES || stage/innodb/alter table (flush) | YES | YES || stage/innodb/alter table (insert) | YES | YES || stage/innodb/alter table (log apply index) | YES | YES || stage/innodb/alter table (log apply table) | YES | YES |+--------------------------------------------+---------+-------+5 rows in set (0.00 sec)mysql> select * from performance_schema.setup_instruments where name like '%statement/%' order by name limit 5;+--------------------------------+---------+-------+| NAME | ENABLED | TIMED |+--------------------------------+---------+-------+| statement/abstract/new_packet | YES | YES || statement/abstract/Query | YES | YES || statement/abstract/relay_log | YES | YES || statement/com/Binlog Dump | YES | YES || statement/com/Binlog Dump GTID | YES | YES |+--------------------------------+---------+-------+5 rows in set (0.00 sec)mysql>performance_schema.setup_consumers
表setup_consumers表中的数据内容如下：
mysql> select * from performance_schema.setup_consumers;+----------------------------------+---------+| NAME | ENABLED |+----------------------------------+---------+| events_stages_current | NO || events_stages_history | NO || events_stages_history_long | NO || events_statements_current | YES || events_statements_history | YES || events_statements_history_long | NO || events_transactions_current | NO || events_transactions_history | NO || events_transactions_history_long | NO || events_waits_current | NO || events_waits_history | NO || events_waits_history_long | NO || global_instrumentation | YES || thread_instrumentation | YES || statements_digest | YES |+----------------------------------+---------+15 rows in set (0.00 sec)mysql>
我们需要把其中stage和statement相关的配置启用，使用如下命令启用：
mysql> update performance_schema.setup_consumers set enabled = 'YES' where name like 'events_stages%';Query OK, 3 rows affected (0.00 sec)Rows matched: 3 Changed: 3 Warnings: 0mysql>mysql> update performance_schema.setup_consumers set enabled = 'YES' where name like 'events_statements%';Query OK, 1 row affected (0.00 sec)Rows matched: 3 Changed: 1 Warnings: 0mysql>
修改后的数据内容如下所示：
mysql> select * from performance_schema.setup_consumers;+----------------------------------+---------+| NAME | ENABLED |+----------------------------------+---------+| events_stages_current | YES || events_stages_history | YES || events_stages_history_long | YES || events_statements_current | YES || events_statements_history | YES || events_statements_history_long | YES || events_transactions_current | NO || events_transactions_history | NO || events_transactions_history_long | NO || events_waits_current | NO || events_waits_history | NO || events_waits_history_long | NO || global_instrumentation | YES || thread_instrumentation | YES || statements_digest | YES |+----------------------------------+---------+15 rows in set (0.00 sec)mysql>performance_schema.events_statements_history_long
表events_statements_history_long中记录着被收集信息的所有的SQL列表。通过这个表，我们可以实现执行show profiles;命令所达到的同等效果，它的表结构如下：
mysql> desc performance_schema.events_statements_history_long;+-------------------------+------------------------------------------------+------+-----+---------+-------+| Field | Type | Null | Key | Default | Extra |+-------------------------+------------------------------------------------+------+-----+---------+-------+| THREAD_ID | bigint(20) unsigned | NO | | NULL | || EVENT_ID | bigint(20) unsigned | NO | | NULL | || END_EVENT_ID | bigint(20) unsigned | YES | | NULL | || EVENT_NAME | varchar(128) | NO | | NULL | || SOURCE | varchar(64) | YES | | NULL | || TIMER_START | bigint(20) unsigned | YES | | NULL | || TIMER_END | bigint(20) unsigned | YES | | NULL | || TIMER_WAIT | bigint(20) unsigned | YES | | NULL | || LOCK_TIME | bigint(20) unsigned | NO | | NULL | || SQL_TEXT | longtext | YES | | NULL | || DIGEST | varchar(32) | YES | | NULL | || DIGEST_TEXT | longtext | YES | | NULL | || CURRENT_SCHEMA | varchar(64) | YES | | NULL | || OBJECT_TYPE | varchar(64) | YES | | NULL | || OBJECT_SCHEMA | varchar(64) | YES | | NULL | || OBJECT_NAME | varchar(64) | YES | | NULL | || OBJECT_INSTANCE_BEGIN | bigint(20) unsigned | YES | | NULL | || MYSQL_ERRNO | int(11) | YES | | NULL | || RETURNED_SQLSTATE | varchar(5) | YES | | NULL | || MESSAGE_TEXT | varchar(128) | YES | | NULL | || ERRORS | bigint(20) unsigned | NO | | NULL | || WARNINGS | bigint(20) unsigned | NO | | NULL | || ROWS_AFFECTED | bigint(20) unsigned | NO | | NULL | || ROWS_SENT | bigint(20) unsigned | NO | | NULL | || ROWS_EXAMINED | bigint(20) unsigned | NO | | NULL | || CREATED_TMP_DISK_TABLES | bigint(20) unsigned | NO | | NULL | || CREATED_TMP_TABLES | bigint(20) unsigned | NO | | NULL | || SELECT_FULL_JOIN | bigint(20) unsigned | NO | | NULL | || SELECT_FULL_RANGE_JOIN | bigint(20) unsigned | NO | | NULL | || SELECT_RANGE | bigint(20) unsigned | NO | | NULL | || SELECT_RANGE_CHECK | bigint(20) unsigned | NO | | NULL | || SELECT_SCAN | bigint(20) unsigned | NO | | NULL | || SORT_MERGE_PASSES | bigint(20) unsigned | NO | | NULL | || SORT_RANGE | bigint(20) unsigned | NO | | NULL | || SORT_ROWS | bigint(20) unsigned | NO | | NULL | || SORT_SCAN | bigint(20) unsigned | NO | | NULL | || NO_INDEX_USED | bigint(20) unsigned | NO | | NULL | || NO_GOOD_INDEX_USED | bigint(20) unsigned | NO | | NULL | || NESTING_EVENT_ID | bigint(20) unsigned | YES | | NULL | || NESTING_EVENT_TYPE | enum('TRANSACTION','STATEMENT','STAGE','WAIT') | YES | | NULL | || NESTING_EVENT_LEVEL | int(11) | YES | | NULL | |+-------------------------+------------------------------------------------+------+-----+---------+-------+41 rows in set (0.00 sec)mysql>我们主要关注的有以下几个字段：
EVENT_ID：就是每一个SQL语句的ID，也就是我们在show profiles for query XXX命令中使用的QUERY_ID。TIMER_WAIT：记录着某个实际执行过程中消耗的实际，其单位是皮秒，在查询这个表的时候，可以使用TIMER_WAIT/1000000000000的换算方式来以秒的单位显示结果（1秒=1000000000000皮秒）。SQL_TEXT：具体执行的SQL语句的内容。
表中的数据查询结果如下：
mysql> SELECT EVENT_ID, TRUNCATE(TIMER_WAIT/1000000000000,6) as Duration, SQL_TEXT FROM performance_schema.events_statements_history_long;+----------+----------+----------------------------------------------------------------------------------------------------+| EVENT_ID | Duration | SQL_TEXT |+----------+----------+----------------------------------------------------------------------------------------------------+| 22 | 0.000281 | update performance_schema.setup_consumers set enabled = 'YES' where name like 'events_statements%' || 34 | 0.000159 | select * from performance_schema.setup_consumers || 50 | 0.002162 | SELECT DATABASE() || 62 | 0.000029 | NULL || 65 | 0.000376 | show tables || 84 | 0.001102 | select * from test limit 10 || 100 | 0.000101 | select * from test order by variables_name || 110 | 0.302449 | select * from test order by variable_name |+----------+----------+----------------------------------------------------------------------------------------------------+8 rows in set (0.00 sec)mysql>performance_schema.events_stages_history_long
表events_stages_history_long中，记录着搜集的所有的SQL语句在执行过程中各个阶段锁消耗的时间。它的结构如下所示：
mysql> desc performance_schema.events_stages_history_long;+--------------------+------------------------------------------------+------+-----+---------+-------+| Field | Type | Null | Key | Default | Extra |+--------------------+------------------------------------------------+------+-----+---------+-------+| THREAD_ID | bigint(20) unsigned | NO | | NULL | || EVENT_ID | bigint(20) unsigned | NO | | NULL | || END_EVENT_ID | bigint(20) unsigned | YES | | NULL | || EVENT_NAME | varchar(128) | NO | | NULL | || SOURCE | varchar(64) | YES | | NULL | || TIMER_START | bigint(20) unsigned | YES | | NULL | || TIMER_END | bigint(20) unsigned | YES | | NULL | || TIMER_WAIT | bigint(20) unsigned | YES | | NULL | || WORK_COMPLETED | bigint(20) unsigned | YES | | NULL | || WORK_ESTIMATED | bigint(20) unsigned | YES | | NULL | || NESTING_EVENT_ID | bigint(20) unsigned | YES | | NULL | || NESTING_EVENT_TYPE | enum('TRANSACTION','STATEMENT','STAGE','WAIT') | YES | | NULL | |+--------------------+------------------------------------------------+------+-----+---------+-------+12 rows in set (0.00 sec)mysql>比较重要的字段有如下3个，我们主要关注这3个字段。
NESTING_EVENT_ID：对应performance_schema.events_statements_history_long表中的EVENT_ID，也就是SQL的QUERY_ID。EVENT_NAME：事件名称，也就是SQL语句执行的各个阶段名称。TIMER_WAIT：SQL每一个阶段执行所需要的时间，单位是皮秒。
mysql> SELECT event_name AS Stage, TRUNCATE(TIMER_WAIT/1000000000000,6) AS Duration FROM performance_schema.events_stages_history_long WHERE NESTING_EVENT_ID=110;+--------------------------------+----------+| Stage | Duration |+--------------------------------+----------+| stage/sql/starting | 0.000087 || stage/sql/checking permissions | 0.000005 || stage/sql/Opening tables | 0.000018 || stage/sql/init | 0.000024 || stage/sql/System lock | 0.000009 || stage/sql/optimizing | 0.000002 || stage/sql/statistics | 0.000013 || stage/sql/preparing | 0.000010 || stage/sql/Sorting result | 0.000002 || stage/sql/executing | 0.000001 || stage/sql/Sending data | 0.000012 || stage/sql/Creating sort index | 0.302188 || stage/sql/end | 0.000002 || stage/sql/query end | 0.000007 || stage/sql/closing tables | 0.000005 || stage/sql/freeing items | 0.000060 || stage/sql/cleaning up | 0.000002 |+--------------------------------+----------+17 rows in set (0.00 sec)mysql>总结
这篇文章中，我们介绍了使用传统的命令show profiles来收集SQL语句执行过程的详细信息。主要有以下几个命令。
set profiling = on;set profiling = off;show profiles;show profile for query XXX;show profile CPU, BLOCK IO for query XXX;
接着我们说到除了使用上述命令之外，还可以去information_schema.profiling表中去查看收集到的SQL执行过程的详细信息。
在最后我们提到show profiles这种命令将会在以后的MySQL版本中删除。建议通过performance_schema下面的一些配置表来配置收集指定用户的SQL语句执行过程的详细信息。主要涉及到的表有以下几张表：
select * from performance_schema.setup_actors;select * from performance_schema.setup_instruments;select * from performance_schema.setup_consumers;select * from performance_schema.events_statements_history_long;select * from performance_schema.events_stages_history_long;
关注我「程序猿集锦」获取更多分享。
版权声明：
本站文章均来自互联网搜集，如有侵犯您的权益，请联系我们删除，谢谢。
标签： #mysqlprofiling详解 #mysql分析sql性能
