show profile是由jeremy cole捐献给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 for query 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)
如果没有指定for query,那么输出最近一条语句的信息。
limit部分的用法与select中limit子句一致,不赘述。
type是可选的,取值范围可以如下:
例:
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 for query 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-关系代数-并、交、差、等值连接、自然连接、左连接。。。
【MySQL牛客】10.获取所有非manager的员工emp_no
网友评论