MySQL中使用SHOW PROFILE命令分析性能的用法整理

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是可选的,取值范围可以如下:

  • 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 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的一个应用示例。

(0)

相关推荐

  • MySQL性能分析工具profile使用教程

    分析SQL执行带来的开销是优化SQL的重要手段.在MySQL数据库中,可以通过配置profiling参数来启用SQL剖析.该参数可以在全局和session级别来设置.对于全局级别则作用于整个MySQL实例,而session级别紧影响当前session.该参数开启后,后续执行的SQL语句都将记录其资源开销,诸如IO,上下文切换,CPU,Memory等等.根据这些开销进一步分析当前SQL瓶颈从而进行优化与调整.本文描述了如何使用MySQL profile,不涉及具体的样例分析. 1.有关profil

  • MySQL利用profile分析慢sql详解(group left join效率高于子查询)

    使用profile来分析慢sql mysql 的 sql 性能分析器主要用途是显示 sql 执行的整个过程中各项资源的使用情况.分析器可以更好的展示出不良 SQL 的性能问题所在. 最近遇到一个查询比较慢的sql语句,用了子查询,大概需要0.8秒左右,这个消耗时间比较长,严重影响了性能,所以需要进行优化.单独查询单表或者子查询记录都很快,下面来看看详细的介绍. 开启profile mysql> show profiles; -- 查看是否开启 Empty set, 1 warning (0.00

  • MySQL使用profile查询性能的操作教程

    MYSQL的profiling功能要在Mysql版本5.0.37以上才能使用. 查看profile是否开启 mysql> show variables like '%profil%'; +------------------------+-------+ | Variable_name | Value | +------------------------+-------+ | profiling | OFF | --开启SQL语句剖析功能 | profiling_history_size |

  • MySQL中使用SHOW PROFILE命令分析性能的用法整理

    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_act

  • MySQL中的binlog相关命令和恢复技巧

    操作命令: 复制代码 代码如下: show binlog events in 'mysql-bin.000016' limit 10; reset master 删除所有的二进制日志flush logs  产生一个新的binlog日志文件 show master logs; 或者 show binary logs; 查看二进制文件列表和文件大小 复制代码 代码如下: ./mysqlbinlog --start-datetime="2012-05-21 15:30:00" --stop-

  • MySQL中exists、in及any的基本用法

    [1]exists 对外表用loop逐条查询,每次查询都会查看exists的条件语句. 当 exists里的条件语句能够返回记录行时(无论记录行是多少,只要能返回),条件就为真 , 返回当前loop到的这条记录.反之如果exists里的条件语句不能返回记录行,条件为假,则当前loop到的这条记录被丢弃. exists的条件就像一个boolean条件,当能返回结果集则为1,不能返回结果集则为 0. 语法格式如下: select * from tables_name where [not] exis

  • MySQL中执行计划explain命令示例详解

    前言 explain命令是查看查询优化器如何决定执行查询的主要方法. 这个功能有局限性,并不总会说出真相,但它的输出是可以获取的最好信息,值得花时间去了解,因为可以学习到查询是如何执行的. 调用EXPLAIN 在select之前添加explain,mysql会在查询上设置一个标记,当执行查询计划时,这个标记会使其返回关于执行计划中每一步的信息,而不是执行它. 它会返回一行或多行信息,显示出执行计划中的每一部分和执行次序. 这是一个简单的explain效果: 在查询中每个表在输出只有一行,如果查询

  • MySQL中使用load data命令实现数据导入的方法

    使用方式如下: 复制代码 代码如下: mysql>load data local infile "D:/ab.txt" into table mytbl(name,age); 使用上述的命令就可以将D:/ab.txt文件的内容导入到表mytbl中,其中name和age是表mytbl的字段,对应ab.txt文件中每行的数据.如果编译安装mysql时没有指定 –enable-local-infile,那么在使用上述命令时会报如下错误: 复制代码 代码如下: ERROR 1148 (4

  • MySQL中的alter table命令的基本使用方法及提速优化

    一.基本用法 1. 增加列 alter table tbl_name add col_name type 例如,  给pet的表增加一列 weight, mysql>alter table pet add weight int; 2. 删除列 alter table tbl_name drop col_name 例如, 删除pet表中的weight这一列 mysql>alter table pet drop weight; 3. 改变列 分为改变列的属性和改变列的名字 改变列的属性--方法1:

  • mysql数据库备份及恢复命令 mysqldump,source的用法

    还原一个数据库:mysql -h localhost -u root -p123456 www<c:\www.sql 备份一个数据库:mysqldump -h localhost -u root -p123456 www > d:\www2008-2-26.sql //以下是在程序中进行测试 //$command = "mysqldump --opt -h $dbhost -u $dbuser -p $dbpass $dbname | gzip > $backupFile&qu

  • JSP中常用的JSTL fmt(format格式化)标签用法整理

    JSTL标签提供了对国际化(I18N)的支持,它可以根据发出请求的客户端地域的不同来显示不同的语言.同时还提供了格式化数据和日期的方法.实现这些功能需要I18N格式标签库(I18N-capable formation tags liberary).引入该标签库的方法为: <%@ taglib prefix="fmt" uri="http://java.sun.com/jsp/jstl/fmt" %> I18N格式标签库提供了11个标签,这些 标签从功能上

  • MySQL中的 Binlog 深度解析及使用详情

    目录 配置文件参数说明 常用的Binlog操作命令 写Binlog的时机 Binlog文件以及扩展 Binlog与Redo log区别 Binlog写入过程 二阶段提交 redo 与 binlog 的刷盘时机 能否只用 redo log 不要 binlog? Binlog 组提交机制 Binlog的日志格式 Statement Row Mixed Binlog 相关参数 清理过期的Binlog日志 手工删除binlog 自动删除binlog 用途 主从同步 复制线程 主从复制优化 数据恢复 my

  • MySQL中distinct与group by之间的性能进行比较

    最近在网上看到了一些测试,感觉不是很准确,今天亲自测试了一番.得出了结论,测试过程在个人计算机上,可能不够全面,仅供参考. 测试过程: 准备一张测试表 CREATE TABLE `test_test` ( `id` int(11) NOT NULL auto_increment, `num` int(11) NOT NULL default '0', PRIMARY KEY (`id`) ) ENGINE=MyISAM DEFAULT CHARSET=utf8 AUTO_INCREMENT=1

随机推荐