PROFILE命令剖判品质的用法整理

show profile是由杰里Miko尔捐出给MySQL社区版本的。暗中同意的是关门的,不过会话品级能够张开那个效果。开启它能够让MySQL搜聚在推行语句的时候所采取的财富。为了总计报表,把profiling设为1
 

MySQL中接纳SHOW PROFILE命令分析品质的用法整理,mysqlprofile

show profile是由Jeremy科尔捐募给MySQL社区版本的。暗中认可的是关门的,可是会话品级能够敞开那几个效用。开启它能够让MySQL搜聚在实行语句的时候所使用的财富。为了计算报表,把profiling设为1美高梅开户网址
 

mysql> SET profiling = 1;

 
后来在运维八个询问

mysql> SELECT COUNT(DISTINCT actor.first_name) AS cnt_name, COUNT(*) AS cnt
-> FROM sakila.film_actor
-> INNER JOIN sakila.actor USING(actor_id)
-> GROUP BY sakila.film_actor.film_id
-> ORDER BY cnt_name DESC;
...
997 rows in set (0.03 sec)

 
以此实践语句的深入分析消息囤积在这几个会话中。使用SHOW PROFILES进行查看。

mysql> SHOW PROFILES\G

*************************** 1. row ***************************
Query_ID: 1
Duration: 0.02596900
Query: SELECT COUNT(DISTINCT actor.first_name) AS cnt_name,...

 
您能够选拔SHOW
PROFILE语句来拿到已经积存的解析数据。借使不加参数,会呈现状态以及它们持续的光阴。

mysql> SHOW PROFILE;

+------------------------+-----------+
| Status | Duration |
+------------------------+-----------+
| (initialization) | 0.000005 |
| Opening tables | 0.000033 |
| System lock | 0.000037 |
| Table lock | 0.000024 |
| init | 0.000079 |
| optimizing | 0.000024 |
| statistics | 0.000079 |
| preparing | 0.00003 |
| Creating tmp table | 0.000124 |
| executing | 0.000008 |
| Copying to tmp table | 0.010048 |
| Creating sort index | 0.004769 |
| Copying to group table | 0.0084880 |
| Sorting result | 0.001136 |
| Sending data | 0.000925 |
| end | 0.00001 |
| removing tmp table | 0.00004 |
| end | 0.000005 |
| removing tmp table | 0.00001 |
| end | 0.000011 |
| query end | 0.00001 |
| freeing items | 0.000025 |
| removing tmp table | 0.00001 |
| freeing items | 0.000016 |
| closing tables | 0.000017 |
| logging slow query | 0.000006 |
+------------------------+-----------+

 
每行都以情景变化的历程以及它们持续的年月。Status那一列和SHOW FULL
PROCESSLIST的State应该是同等的。
这些值是源于于thd->proc_info变量。由此你所查看的这么些值是一一向源于MySQL内部的。就算这么些数值是比较直接易懂的,你也能够查看MySQL手册。
 
您能够给SHOW
PROFILES钦命三个Query_ID来查看钦点的讲话,还足以给输出增多新的列。如,查看用户和CPU使用。能够用如下命令。
 

mysql> SHOW PROFILE CPU FOR QUERY 1;

 
SHOW
PROFILE能够深深的查看服务器试行语句的劳作景况。以及也能协助您知道试行语句消耗费时间间的景观。一些限制是它从未完毕的成效,无法查看和剖判别的总是的言语,以及解析时所引起的损耗。

SHOW
PROFILES展现前段时间发放服务器的多条语句,条数根据会话变量profiling_history_size定义,默许是15,最大值为100。设为0等价于关闭剖析效果与利益。

SHOW PROFILE FORAV4 QUEEnclaveY n,这里的n便是对应SHOW
PROFILES输出中的Query_ID。

例如:

mysql> show profiles;

+----------+-------------+---------------------------------------+
| Query_ID | Duration | Query     |
+----------+-------------+---------------------------------------+
| 1 | 0.00037700 | alter table table1 drop column c3 int |
| 2 | 70.37123800 | alter table table1 drop column c3 |
| 3 | 0.00124500 | show tables    |
| 4 | 0.00569800 | select * from table1 where id=2 |
| 5 | 0.00068500 | select count(1) from tables1  |
| 6 | 0.00197900 | select count(1) from table1  |
| 7 | 0.00105900 | alter table tables1 drop c1  |
| 8 | 0.00800200 | alter table table1 drop c1  |
+----------+-------------+---------------------------------------+
8 rows in set (0.00 sec)

 

mysql> SHOW PROFILE FOR QUERY 2; #查看alter table table1 drop column c3的分析

+------------------------------+-----------+
| Status   | Duration |
+------------------------------+-----------+
| starting   | 0.000183 |
| checking permissions  | 0.000057 |
| checking permissions  | 0.000059 |
| init    | 0.000060 |
| Opening tables  | 0.000071 |
| System lock   | 0.000062 |
| setup   | 0.000080 |
| creating table  | 0.005052 |
| After create   | 0.000220 |
| copy to tmp table  | 0.000244 |
| rename result table  | 70.364027 |
| end    | 0.000575 |
| Waiting for query cache lock | 0.000062 |
| end    | 0.000075 |
| query end   | 0.000057 |
| closing tables  | 0.000061 |
| freeing items  | 0.000080 |
| logging slow query  | 0.000056 |
| logging slow query  | 0.000098 |
| cleaning up   | 0.000059 |
+------------------------------+-----------+
20 rows in set (0.00 sec)

若无一点名FO本田UR-V QUEMuranoY,那么输出近期一条语句的音讯。

LIMIT部分的用法与SELECT中LIMIT子句一致,不赘述。

type是可选的,取值范围可以如下:

  • ALL 彰显全体质量新闻
  • BLOCK IO 呈现块IO操作的次数
  • CONTEXT SWITCHES 展现上下文切换次数,不管是主动或许有气无力
  • CPU 呈现用户CPU时间、系统CPU时间
  • IPC 展现发送和吸取的新闻数量
  • MEMORY [暂未落到实处]
  • PAGE FAULTS 呈现页错误数量
  • SOURCE 呈现源码中的函数名称与地方
  • SWAPS 显示SWAP的次数

例:

mysql> show profile cpu for query 2;

+------------------------------+-----------+----------+------------+
| Status   | Duration | CPU_user | CPU_system |
+------------------------------+-----------+----------+------------+
| starting   | 0.000183 | 0.000000 | 0.000000 |
| checking permissions  | 0.000057 | 0.000000 | 0.000000 |
| checking permissions  | 0.000059 | 0.000000 | 0.000000 |
| init    | 0.000060 | 0.000000 | 0.000000 |
| Opening tables  | 0.000071 | 0.000000 | 0.000000 |
| System lock   | 0.000062 | 0.000000 | 0.000000 |
| setup   | 0.000080 | 0.000000 | 0.001000 |
| creating table  | 0.005052 | 0.003000 | 0.001000 |
| After create   | 0.000220 | 0.000000 | 0.000000 |
| copy to tmp table  | 0.000244 | 0.000000 | 0.000000 |
| rename result table  | 70.364027 | 7.470864 | 41.612674 |
| end    | 0.000575 | 0.000000 | 0.001000 |
| Waiting for query cache lock | 0.000062 | 0.000000 | 0.000000 |
| end    | 0.000075 | 0.000000 | 0.000000 |
| query end   | 0.000057 | 0.000000 | 0.000000 |
| closing tables  | 0.000061 | 0.000000 | 0.000000 |
| freeing items  | 0.000080 | 0.000000 | 0.000000 |
| logging slow query  | 0.000056 | 0.000000 | 0.000000 |
| logging slow query  | 0.000098 | 0.000000 | 0.000000 |
| cleaning up   | 0.000059 | 0.000000 | 0.000000 |
+------------------------------+-----------+----------+------------+
20 rows in set (0.00 sec)

ps:
SHOW PROFILE ALL FOWrangler QUEPRADOY 2;的音讯还足以由此SELECT * FROM
information_schema.profiling WHERE query_id = 2 ORDER BY seq;获取。

功用范围 本条命令只是在本会话内起成效,即无法解析本会话外的口舌。

敞开深入分析功用后,全部本会话中的语句都被深入分析(以致席卷实施错误的语句),除了SHOW
PROFILE和SHOW PROFILES两句小编。

行使示范:使用SHOW PROFILE深入分析查询缓存命中的品质优势。

mysql> set profiling=1;

Query OK, 0 rows affected (0.00 sec)

PROFILE命令剖判品质的用法整理。 

mysql> select count(1) as cnt from tran_excution;

+-------+
| cnt |
+-------+
| 14225 |
+-------+
1 row in set (0.00 sec)

由于已经启用了询问缓存,一样查询(非分区表)能够直接在查询缓存中命中。

mysql> select count(1) as cnt from tran_excution;

我们紧凑看下多个同样的说话的辨析。

mysql> show profile source for query 1;

+--------------------------------+----------+-----------------------+---------------+-------------+
| Status    | Duration | Source_function | Source_file | Source_line |
+--------------------------------+----------+-----------------------+---------------+-------------+
| starting   | 0.000048 | NULL   | NULL  | NULL |
| Waiting for query cache lock | 0.000013 | try_lock  | sql_cache.cc |  454 |
| checking query cache for query | 0.000040 | send_result_to_client | sql_cache.cc | 1561 |
| checking permissions  | 0.000023 | check_access  | sql_parse.cc | 4751 |
| Opening tables   | 0.000040 | open_tables  | sql_base.cc | 4831 |
| System lock   | 0.000020 | mysql_lock_tables | lock.cc |  299 |
| Waiting for query cache lock | 0.000037 | try_lock  | sql_cache.cc |  454 |
| init    | 0.000020 | mysql_select  | sql_select.cc | 2579 |
| optimizing   | 0.000015 | optimize  | sql_select.cc |  865 |
| statistics   | 0.000017 | optimize  | sql_select.cc | 1056 |
| preparing   | 0.000016 | optimize  | sql_select.cc | 1078 |
| executing   | 0.000015 | exec   | sql_select.cc | 1836 |
| Sending data   | 0.003875 | exec   | sql_select.cc | 2380 |
| end    | 0.000018 | mysql_select  | sql_select.cc | 2615 |
| query end   | 0.000015 | mysql_execute_command | sql_parse.cc | 4440 |
| closing tables   | 0.000016 | mysql_execute_command | sql_parse.cc | 4492 |
| freeing items   | 0.000016 | mysql_parse  | sql_parse.cc | 5640 |
| Waiting for query cache lock | 0.000012 | try_lock  | sql_cache.cc |  454 |
| freeing items   | 0.000032 | NULL   | NULL  | NULL |
| Waiting for query cache lock | 0.000017 | try_lock  | sql_cache.cc |  454 |
| freeing items   | 0.000016 | NULL   | NULL  | NULL |
| storing result in query cache | 0.000017 | end_of_result  | sql_cache.cc | 1020 |
| logging slow query  | 0.000018 | log_slow_statement | sql_parse.cc | 1461 |
| logging slow query  | 0.000050 | log_slow_statement | sql_parse.cc | 1470 |
| cleaning up   | 0.000018 | dispatch_command | sql_parse.cc | 1417 |
+--------------------------------+----------+-----------------------+---------------+-------------+
25 rows in set (0.00 sec)

 

mysql> show profile source for query 2;

+--------------------------------+----------+-----------------------+--------------+-------------+
| Status    | Duration | Source_function | Source_file | Source_line |
+--------------------------------+----------+-----------------------+--------------+-------------+
| starting   | 0.000051 | NULL   | NULL  | NULL |
| Waiting for query cache lock | 0.000014 | try_lock  | sql_cache.cc |  454 |
| checking query cache for query | 0.000016 | send_result_to_client | sql_cache.cc | 1561 |
| checking privileges on cached | 0.000013 | send_result_to_client | sql_cache.cc | 1652 |
| checking permissions  | 0.000015 | check_access  | sql_parse.cc | 4751 |
| sending cached result to clien | 0.000036 | send_result_to_client | sql_cache.cc | 1749 |
| logging slow query  | 0.000017 | log_slow_statement | sql_parse.cc | 1461 |
| cleaning up   | 0.000018 | dispatch_command | sql_parse.cc | 1417 |
+--------------------------------+----------+-----------------------+--------------+-------------+
8 rows in set (0.00 sec)

能够清晰地阅览缓存中命中时,大大节约了后台的支出。当然缓存的采取也急需基于各样现象(表的数码规模,更新频率等)考查使用,并不是启用缓存就确定可以升高查询功用。这里唯有看做SHOW
PROFILE的三个运用示范。

PROFILE命令分析性能的用法整理,mysqlprofile show profile是由JeremyCole进献给MySQL社区版本的。默许的是破产的,不过会话品级能够…

INFORMATION_SCHEMA PROFILING Table

PROFILING表提供了语句解析消息。 其内容对应于SHOW PROFILES和SHOW
PROFILE语句生成的音信.

INFORMATION_SCHEMA Name SHOW Name Notes
QUERY_ID Query_ID 标识
SEQ 具有相同QUERY_ID值的行的显示顺序的序列号
STATE Status 行测量适用的分析状态
DURATION Duration 在给定状态下,多长时间的语句执行保持在几秒钟内
CPU_USER CPU_user 用户CPU使用,以秒为单位
CPU_SYSTEM CPU_system 系统CPU使用,以秒为单位
CONTEXT_VOLUNTARY Context_voluntary 自愿上下文切换发生
CONTEXT_INVOLUNTARY Context_involuntary 非自愿上下文切换发生
BLOCK_OPS_IN Block_ops_in 输入块操作的数量
BLOCK_OPS_OUT Block_ops_out 输出块操作的数量
MESSAGES_SENT Messages_sent 发送的通信消息的数量
MESSAGES_RECEIVED Messages_received 接收的通信消息的数量
PAGE_FAULTS_MAJOR Page_faults_major 主页面错误的数量
PAGE_FAULTS_MINOR Page_faults_minor 次页面错误的数量
SWAPS Swaps 发生了多少次交换
SOURCE_FUNCTION Source_function 源代码执行分析状态的位置的信息
SOURCE_FILE Source_file 源代码执行分析状态的位置的信息
SOURCE_LINE Source_line 源代码执行分析状态的位置的信息
mysql> SET profiling = 1;

13.7.5.31 SHOW PROFILES Syntax

SHOW PROFILES

SHOW PROFILES语句与SHOW
PROFILE一起展示剖析音信,提醒在此时此刻对话进度中进行的言语的财富使用景况。

 
后来在运行八个查询

13.7.5.30 SHOW PROFILE Syntax

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

能够钦点可选类型值以显示特定的任何类别的消息(对应PROFILING中字段):

type note
ALL 显示所有信息
BLOCK IO 显示块输入和输出操作的计数
CONTEXT SWITCHES 显示自愿和非自愿上下文切换的计数
CPU 显示用户和系统CPU使用时间
IPC 显示发送和接收消息的计数
MEMORY 目前尚未实施
PAGE FAULTS 显示主页和次页错误的计数
SOURCE 显示来自源代码的函数的名称以及该函数发生的文件的名称和行号
SWAPS 显示交换计数

SHOW PROFILE和SHOW
PROFILES语句展现剖判音信,提示在时下对话进程中实行的言辞的能源使用意况。

Profiling由Profiling会话变量支配,私下认可值为0(OFF)。
通过将Profiling设置为1或ON可启用解析:

mysql> SET profiling = 1;

SHOW PROFILES突显发送到服务器的风尚讲话的列表。
列表的大大小小由profiling_history_size会话变量调控,该变量的私下认可值为15.最大值为100.将值设置为0有着禁止使用质量解析的实效。

除SHOW PROFILE和SHOW
PROFILES之外,全体语句都进展了大致剖析,因而你将不会在安顿文件列表中找到那一个言辞。
对于格式错误的实践语句,比如SHOW
PROFILING是贰个非土耳其共和国(The Republic of Turkey)语句,假使您尝试实施该语句,则会并发语法错误,但会来得在差不离深入分析列表中。

SHOW PROFILE显示有关单个语句的详细音信,若无扩充FOENCORE QUEXC60Y
n子句,输出与这二日试行的话语相关;不然展现特定语句的音信。
n的值对应于SHOW PROFILES显示的Query_ID值。

能够交给LIMIT
row_count子句以将出口限制为row_count行。要是给定了LIMIT,则能够增加OFFSET偏移以将出口偏移行起初到整组行。

私下认可情况下,SHOW PROFILE展现状态和不断时间列。

每种会话启用解析。会话停止时,其剖析新闻遗失。

说了那么多,上边那么些早就被撇下啦!!!!

mysql> SELECT COUNT(DISTINCT actor.first_name) AS cnt_name, COUNT(*) AS cnt
-> FROM sakila.film_actor
-> INNER JOIN sakila.actor USING(actor_id)
-> GROUP BY sakila.film_actor.film_id
-> ORDER BY cnt_name DESC;
...
997 rows in set (0.03 sec)
Note:

那几个讲话已被稳步弃用,就要将来的MySQL版本中被删去。

也正是说新本子饱含现在的版本对于品质的监督渐渐使用PEENCOREFORMANCE_SCHEM代替INFORMATION_SCHEMA
–>详见Chapter 25 MySQL Performance
Schema


 
其一实施语句的辨析消息囤积在那个会话中。使用SHOW PROFILES实行查看。

Action

已知:

mysql root@127.0.0.1:nt> SELECT * FROM student
+------+--------+-------+-------+
|   id | name   |   age | sex   |
|------+--------+-------+-------|
|    1 | s1     |    12 | m     |
|    2 | s2     |    12 | w     |
|    3 | s3     |    11 | w     |
+------+--------+-------+-------+
3 rows in set
Time: 0.004s
mysql root@127.0.0.1:nt> SELECT * FROM teacher
+------+--------+
|   id | name   |
|------+--------|
|    1 | Han    |
|    2 | Gou    |
|    3 | Eric   |
+------+--------+
3 rows in set
Time: 0.002s
mysql root@127.0.0.1:nt> SELECT * FROM course
+------+--------------+----------------+
|   id |   teacher_id | name           |
|------+--------------+----------------|
|    1 |            1 | Advanced Maths |
|    2 |            2 | English        |
|    3 |            3 | Arts           |
|    4 |            1 | Physics        |
|    5 |            3 | Programming    |
+------+--------------+----------------+
5 rows in set
Time: 0.003s
mysql root@127.0.0.1:nt> SELECT * FROM score
+--------------+-------------+---------+
|   student_id |   course_id |   score |
|--------------+-------------+---------|
|            1 |           1 |      78 |
|            1 |           2 |      56 |
|            1 |           3 |      89 |
|            1 |           4 |      60 |
|            1 |           5 |      92 |
|            2 |           1 |      92 |
|            2 |           2 |      60 |
|            2 |           3 |      78 |
|            2 |           4 |      77 |
|            2 |           5 |      95 |
|            3 |           1 |      66 |
|            3 |           2 |      50 |
|            3 |           3 |      78 |
|            3 |           4 |      67 |
|            3 |           5 |      86 |
+--------------+-------------+---------+
15 rows in set
Time: 0.003s

解:高数比水墨画分数高的上学的小孩子新闻

SELECT S.* 
FROM (SELECT SC1.STUDENT_ID,SC1.COURSE_ID,SC1.SCORE FROM score SC1) A,
     (SELECT SC2.STUDENT_ID,SC2.COURSE_ID,SC2.SCORE FROM score SC2) B, 
     student S 
WHERE A.STUDENT_ID=B.STUDENT_ID 
AND   A.COURSE_ID=1 
AND   B.COURSE_ID=3 
AND   A.SCORE>B.SCORE 
AND   A.STUDENT_ID=S.ID;

mysql root@127.0.0.1:nt> SELECT @@profiling
+---------------+
|   @@profiling |
|---------------|
|             0 |
+---------------+
1 row in set
Time: 0.002s
mysql root@127.0.0.1:nt> SET profiling = 1
Query OK, 0 rows affected
Time: 0.001s
mysql root@127.0.0.1:nt> SELECT S.*
                      -> FROM (SELECT SC1.STUDENT_ID,SC1.COURSE_ID,SC1.SCORE FROM score SC1) A,
                      ->      (SELECT SC2.STUDENT_ID,SC2.COURSE_ID,SC2.SCORE FROM score SC2) B,
                      ->      student S
                      -> WHERE A.STUDENT_ID=B.STUDENT_ID
                      -> AND   A.COURSE_ID=1
                      -> AND   B.COURSE_ID=3
                      -> AND   A.SCORE>B.SCORE
                      -> AND   A.STUDENT_ID=S.ID;
+------+--------+-------+-------+
|   id | name   |   age | sex   |
|------+--------+-------+-------|
|    2 | s2     |    12 | w     |
+------+--------+-------+-------+
1 row in set
Time: 0.007s
mysql root@127.0.0.1:nt> SHOW PROFILES
+------------+------------+---------------+
|   Query_ID |   Duration | Query         |
|------------+------------+---------------|
|          1 |   4.5e-05  | SHOW WARNINGS |
|          2 |   0.000603 | SELECT S.*
FROM (SELECT SC1.STUDENT_ID,SC1.COURSE_ID,SC1.SCORE FROM score SC1) A,
     (SELECT SC2.STUDENT_ID,SC2.COURSE_ID,SC2.SCORE FROM score SC2) B,
     student S
WHERE A.STUDENT_ID=B.STUDENT_ID
AND   A.COURSE_ID=1
AND   B.COURSE_ID=3
AND   A.SCORE>B.SCORE
AND   A.STUDENT_ID=S.ID               |
+------------+------------+---------------+
2 rows in set
Time: 0.002s
mysql root@127.0.0.1:nt> SHOW PROFILE FOR QUERY 2
+----------------------+------------+
| Status               |   Duration |
|----------------------+------------|
| starting             |   0.000134 |
| checking permissions |   1.1e-05  |
| checking permissions |   4e-06    |
| checking permissions |   7e-06    |
| Opening tables       |   2.4e-05  |
| init                 |   5.2e-05  |
| System lock          |   1.1e-05  |
| optimizing           |   1.5e-05  |
| statistics           |   0.000161 |
| preparing            |   2.7e-05  |
| executing            |   4e-06    |
| Sending data         |   6.4e-05  |
| end                  |   6e-06    |
| query end            |   7e-06    |
| closing tables       |   8e-06    |
| freeing items        |   5.4e-05  |
| cleaning up          |   1.4e-05  |
+----------------------+------------+
17 rows in set
Time: 0.005s

地方的结果太丑

mysql root@127.0.0.1:nt> set @query_id=2
Query OK, 0 rows affected
Time: 0.001s

行使上边包车型客车SQL:

SELECT STATE, SUM(DURATION) AS TOTAL_R,
    ROUND(100 * SUM(DURATION)/(SELECT SUM(DURATION) 
                              FROM information_schema.PROFILING 
                              WHERE QUERY_ID=@query_id),
          2
    ) AS PCT_R,
    COUNT(*) CALLS,
    SUM(DURATION)/COUNT(*) AS "R/CALL"
FROM information_schema.PROFILING
WHERE QUERY_ID=@query_id
GROUP BY STATE
ORDER BY TOTAL_R DESC;

mycli实施上边的sql:

+----------------------+-----------+---------+---------+------------+
| STATE                |   TOTAL_R |   PCT_R |   CALLS |     R/CALL |
|----------------------+-----------+---------+---------+------------|
| statistics           |  0.000161 |   26.7  |       1 | 0.000161   |
| starting             |  0.000134 |   22.22 |       1 | 0.000134   |
| Sending data         |  6.4e-05  |   10.61 |       1 | 6.4e-05    |
| freeing items        |  5.4e-05  |    8.96 |       1 | 5.4e-05    |
| init                 |  5.2e-05  |    8.62 |       1 | 5.2e-05    |
| preparing            |  2.7e-05  |    4.48 |       1 | 2.7e-05    |
| Opening tables       |  2.4e-05  |    3.98 |       1 | 2.4e-05    |
| checking permissions |  2.2e-05  |    3.65 |       3 | 7.3333e-06 |
| optimizing           |  1.5e-05  |    2.49 |       1 | 1.5e-05    |
| cleaning up          |  1.4e-05  |    2.32 |       1 | 1.4e-05    |
| System lock          |  1.1e-05  |    1.82 |       1 | 1.1e-05    |
| closing tables       |  8e-06    |    1.33 |       1 | 8e-06      |
| query end            |  7e-06    |    1.16 |       1 | 7e-06      |
| end                  |  6e-06    |    1    |       1 | 6e-06      |
| executing            |  4e-06    |    0.66 |       1 | 4e-06      |
+----------------------+-----------+---------+---------+------------+
15 rows in set
Time: 0.018s

能够看出来,时间开支占比最高依次:

  1. statistics:服务器正在测算总结消息以开垦查询试行布署。纵然贰个线程长日子处在这种景况,服务器大概是磁盘绑定的,实践别的干活

  2. starting

  3. Sending
    data:线程正在读取和拍卖SELECT语句的行,并向客户端发送数据。由于在此情景之间产生的操作往往实践大气的磁盘访谈(读取),所以在加以查询的全方位生命周期内普通是最长的运行境况

  4. freeing
    items:线程已经实施了叁个指令。在这种气象下成功的品种的一些保释涉及查询缓存。这种景观一般是清理

  5. init:那产生在ALTER
    TABLE,DELETE,INSERT,SELECT或UPDATE语句的开首化此前。处于此意况的服务器选拔的操作包涵刷新二进制日志,InnoDB日志和部分查询缓存清理操作。

对于最终状态,恐怕会时有产生以下操作:

  • 在表中的数量变动后删除查询缓存条约
  • 将事件写入二进制日志
  • 自由内存缓冲区,包罗Blob

上面看看记录2对应的CPU新闻

mysql root@127.0.0.1:nt> SHOW PROFILE CPU FOR QUERY 2
+----------------------+------------+------------+--------------+
| Status               |   Duration |   CPU_user |   CPU_system |
|----------------------+------------+------------+--------------|
| starting             |   0.000134 |   0.000126 |      8e-06   |
| checking permissions |   1.1e-05  |   4e-06    |      6e-06   |
| checking permissions |   4e-06    |   2e-06    |      3e-06   |
| checking permissions |   7e-06    |   4e-06    |      2e-06   |
| Opening tables       |   2.4e-05  |   2.3e-05  |      2e-06   |
| init                 |   5.2e-05  |   4.8e-05  |      3e-06   |
| System lock          |   1.1e-05  |   8e-06    |      2e-06   |
| optimizing           |   1.5e-05  |   1.4e-05  |      2e-06   |
| statistics           |   0.000161 |   0.000113 |      5.3e-05 |
| preparing            |   2.7e-05  |   1.9e-05  |      3e-06   |
| executing            |   4e-06    |   2e-06    |      3e-06   |
| Sending data         |   6.4e-05  |   6.3e-05  |      1e-06   |
| end                  |   6e-06    |   3e-06    |      3e-06   |
| query end            |   7e-06    |   5e-06    |      1e-06   |
| closing tables       |   8e-06    |   7e-06    |      1e-06   |
| freeing items        |   5.4e-05  |   1.3e-05  |      4.2e-05 |
| cleaning up          |   1.4e-05  |   1.2e-05  |      2e-06   |
+----------------------+------------+------------+--------------+
17 rows in set
Time: 0.009s

mysql> SHOW PROFILES\G


*************************** 1. row ***************************
Query_ID: 1
Duration: 0.02596900
Query: SELECT COUNT(DISTINCT actor.first_name) AS cnt_name,...

Qs:为何show profiles结果中的duration和直接试行的小时差别那么大?

 
你能够运用SHOW
PROFILE语句来获得已经积攒的辨析数据。如若不加参数,会来得状态以及它们持续的时光。

mysql> SHOW PROFILE;


+------------------------+-----------+
| Status | Duration |
+------------------------+-----------+
| (initialization) | 0.000005 |
| Opening tables | 0.000033 |
| System lock | 0.000037 |
| Table lock | 0.000024 |
| init | 0.000079 |
| optimizing | 0.000024 |
| statistics | 0.000079 |
| preparing | 0.00003 |
| Creating tmp table | 0.000124 |
| executing | 0.000008 |
| Copying to tmp table | 0.010048 |
| Creating sort index | 0.004769 |
| Copying to group table | 0.0084880 |
| Sorting result | 0.001136 |
| Sending data | 0.000925 |
| end | 0.00001 |
| removing tmp table | 0.00004 |
| end | 0.000005 |
| removing tmp table | 0.00001 |
| end | 0.000011 |
| query end | 0.00001 |
| freeing items | 0.000025 |
| removing tmp table | 0.00001 |
| freeing items | 0.000016 |
| closing tables | 0.000017 |
| logging slow query | 0.000006 |
+------------------------+-----------+

 
每行都是情景变化的历程以及它们持续的岁月。Status那一列和SHOW FULL
PROCESSLIST的State应该是平等的。
其一值是缘于于thd->proc_info变量。因而你所查看的这几个值是直接来自MySQL内部的。尽管那个数值是相比较一直易懂的,你也得以查阅MySQL手册。
 
你能够给SHOW
PROFILES内定一个Query_ID来查阅内定的说话,还足以给输出加多新的列。如,查看用户和CPU使用。能够用如下命令。
 

mysql> SHOW PROFILE CPU FOR QUERY 1;

 
SHOW
PROFILE能够深深的查看服务器施行语句的干活情形。以及也能协理你知道实践语句消耗费时间间的气象。一些限量是它并没有落到实处的效果与利益,不能查看和分析其余总是的口舌,以及剖判时所引起的消耗。

SHOW
PROFILES展现近来发给服务器的多条语句,条数根据会话变量profiling_history_size定义,暗许是15,最大值为100。设为0等价于关闭解析作用。

SHOW PROFILE FO大切诺基 QUE福特ExplorerY n,这里的n便是对应SHOW
PROFILES输出中的Query_ID。

例如:

mysql> show profiles;


+----------+-------------+---------------------------------------+
| Query_ID | Duration | Query     |
+----------+-------------+---------------------------------------+
| 1 | 0.00037700 | alter table table1 drop column c3 int |
| 2 | 70.37123800 | alter table table1 drop column c3 |
| 3 | 0.00124500 | show tables    |
| 4 | 0.00569800 | select * from table1 where id=2 |
| 5 | 0.00068500 | select count(1) from tables1  |
| 6 | 0.00197900 | select count(1) from table1  |
| 7 | 0.00105900 | alter table tables1 drop c1  |
| 8 | 0.00800200 | alter table table1 drop c1  |
+----------+-------------+---------------------------------------+
8 rows in set (0.00 sec)

 

mysql> SHOW PROFILE FOR QUERY 2; #查看alter table table1 drop column c3的分析


+------------------------------+-----------+
| Status   | Duration |
+------------------------------+-----------+
| starting   | 0.000183 |
| checking permissions  | 0.000057 |
| checking permissions  | 0.000059 |
| init    | 0.000060 |
| Opening tables  | 0.000071 |
| System lock   | 0.000062 |
| setup   | 0.000080 |
| creating table  | 0.005052 |
| After create   | 0.000220 |
| copy to tmp table  | 0.000244 |
| rename result table  | 70.364027 |
| end    | 0.000575 |
| Waiting for query cache lock | 0.000062 |
| end    | 0.000075 |
| query end   | 0.000057 |
| closing tables  | 0.000061 |
| freeing items  | 0.000080 |
| logging slow query  | 0.000056 |
| logging slow query  | 0.000098 |
| cleaning up   | 0.000059 |
+------------------------------+-----------+
20 rows in set (0.00 sec)

纵然没有一点点名FO奥迪Q5 QUE奥迪Q3Y,那么输出近日一条语句的消息。

LIMIT部分的用法与SELECT中LIMIT子句一致,不赘述。

type是可选的,取值范围能够如下:

  • ALL 展现全部品质音信
  • BLOCK IO 展现块IO操作的次数
  • CONTEXT SWITCHES 呈现上下文切换次数,不管是主动恐怕有气无力
  • CPU 呈现用户CPU时间、系统CPU时间
  • IPC 突显发送和接到的音讯数量
  • MEMORY [暂未完成]
  • PAGE FAULTS 展现页错误数量
  • SOURCE 显示源码中的函数名称与岗位
  • SWAPS 显示SWAP的次数

例:

mysql> show profile cpu for query 2;


+------------------------------+-----------+----------+------------+
| Status   | Duration | CPU_user | CPU_system |
+------------------------------+-----------+----------+------------+
| starting   | 0.000183 | 0.000000 | 0.000000 |
| checking permissions  | 0.000057 | 0.000000 | 0.000000 |
| checking permissions  | 0.000059 | 0.000000 | 0.000000 |
| init    | 0.000060 | 0.000000 | 0.000000 |
| Opening tables  | 0.000071 | 0.000000 | 0.000000 |
| System lock   | 0.000062 | 0.000000 | 0.000000 |
| setup   | 0.000080 | 0.000000 | 0.001000 |
| creating table  | 0.005052 | 0.003000 | 0.001000 |
| After create   | 0.000220 | 0.000000 | 0.000000 |
| copy to tmp table  | 0.000244 | 0.000000 | 0.000000 |
| rename result table  | 70.364027 | 7.470864 | 41.612674 |
| end    | 0.000575 | 0.000000 | 0.001000 |
| Waiting for query cache lock | 0.000062 | 0.000000 | 0.000000 |
| end    | 0.000075 | 0.000000 | 0.000000 |
| query end   | 0.000057 | 0.000000 | 0.000000 |
| closing tables  | 0.000061 | 0.000000 | 0.000000 |
| freeing items  | 0.000080 | 0.000000 | 0.000000 |
| logging slow query  | 0.000056 | 0.000000 | 0.000000 |
| logging slow query  | 0.000098 | 0.000000 | 0.000000 |
| cleaning up   | 0.000059 | 0.000000 | 0.000000 |
+------------------------------+-----------+----------+------------+
20 rows in set (0.00 sec)

ps:
SHOW PROFILE ALL FOEnclave QUE本田UR-VY 2;的消息还能通过SELECT * FROM
information_schema.profiling WHERE query_id = 2 ORDER BY seq;获取。

成效范围 那些命令只是在本会话内起效果,即无法分析本会话外的口舌。

拉开深入分析效果与利益后,全体本会话中的语句都被深入分析(以致包罗推行错误的话语),除了SHOW
PROFILE和SHOW PROFILES两句小编。

动用示范:使用SHOW PROFILE分析查询缓存命中的质量优势。

mysql> set profiling=1;


Query OK, 0 rows affected (0.00 sec)

 

mysql> select count(1) as cnt from tran_excution;


+-------+
| cnt |
+-------+
| 14225 |
+-------+
1 row in set (0.00 sec)

出于已经启用了查询缓存,一样查询(非分区表)能够一向在询问缓存中命中。

mysql> select count(1) as cnt from tran_excution;

我们精心看下多少个一律的言辞的深入分析。

mysql> show profile source for query 1;


+--------------------------------+----------+-----------------------+---------------+-------------+
| Status    | Duration | Source_function | Source_file | Source_line |
+--------------------------------+----------+-----------------------+---------------+-------------+
| starting   | 0.000048 | NULL   | NULL  | NULL |
| Waiting for query cache lock | 0.000013 | try_lock  | sql_cache.cc |  454 |
| checking query cache for query | 0.000040 | send_result_to_client | sql_cache.cc | 1561 |
| checking permissions  | 0.000023 | check_access  | sql_parse.cc | 4751 |
| Opening tables   | 0.000040 | open_tables  | sql_base.cc | 4831 |
| System lock   | 0.000020 | mysql_lock_tables | lock.cc |  299 |
| Waiting for query cache lock | 0.000037 | try_lock  | sql_cache.cc |  454 |
| init    | 0.000020 | mysql_select  | sql_select.cc | 2579 |
| optimizing   | 0.000015 | optimize  | sql_select.cc |  865 |
| statistics   | 0.000017 | optimize  | sql_select.cc | 1056 |
| preparing   | 0.000016 | optimize  | sql_select.cc | 1078 |
| executing   | 0.000015 | exec   | sql_select.cc | 1836 |
| Sending data   | 0.003875 | exec   | sql_select.cc | 2380 |
| end    | 0.000018 | mysql_select  | sql_select.cc | 2615 |
| query end   | 0.000015 | mysql_execute_command | sql_parse.cc | 4440 |
| closing tables   | 0.000016 | mysql_execute_command | sql_parse.cc | 4492 |
| freeing items   | 0.000016 | mysql_parse  | sql_parse.cc | 5640 |
| Waiting for query cache lock | 0.000012 | try_lock  | sql_cache.cc |  454 |
| freeing items   | 0.000032 | NULL   | NULL  | NULL |
| Waiting for query cache lock | 0.000017 | try_lock  | sql_cache.cc |  454 |
| freeing items   | 0.000016 | NULL   | NULL  | NULL |
| storing result in query cache | 0.000017 | end_of_result  | sql_cache.cc | 1020 |
| logging slow query  | 0.000018 | log_slow_statement | sql_parse.cc | 1461 |
| logging slow query  | 0.000050 | log_slow_statement | sql_parse.cc | 1470 |
| cleaning up   | 0.000018 | dispatch_command | sql_parse.cc | 1417 |
+--------------------------------+----------+-----------------------+---------------+-------------+
25 rows in set (0.00 sec)

 

mysql> show profile source for query 2;


+--------------------------------+----------+-----------------------+--------------+-------------+
| Status    | Duration | Source_function | Source_file | Source_line |
+--------------------------------+----------+-----------------------+--------------+-------------+
| starting   | 0.000051 | NULL   | NULL  | NULL |
| Waiting for query cache lock | 0.000014 | try_lock  | sql_cache.cc |  454 |
| checking query cache for query | 0.000016 | send_result_to_client | sql_cache.cc | 1561 |
| checking privileges on cached | 0.000013 | send_result_to_client | sql_cache.cc | 1652 |
| checking permissions  | 0.000015 | check_access  | sql_parse.cc | 4751 |
| sending cached result to clien | 0.000036 | send_result_to_client | sql_cache.cc | 1749 |
| logging slow query  | 0.000017 | log_slow_statement | sql_parse.cc | 1461 |
| cleaning up   | 0.000018 | dispatch_command | sql_parse.cc | 1417 |
+--------------------------------+----------+-----------------------+--------------+-------------+
8 rows in set (0.00 sec)

能够清楚地看出缓存中命中时,大大节省了后台的开采。当然缓存的运用也须要依靠各样境况(表的数码规模,更新频率等)侦查使用,实际不是启用缓存就必然能够巩固查询功效。这里独有看做SHOW
PROFILE的三个应用示范。

你只怕感兴趣的稿子:

  • MySQL性能深入分析工具profile使用教程
  • MySQL使用profile查询品质的操作教程
  • MySQL利用profile分析慢sql详解(group left
    join效用高于子查询)

发表评论

电子邮件地址不会被公开。 必填项已用*标注

网站地图xml地图