MySQL使用profile查询性能的操作教程_MySQL
- WBOYOriginal
- 2016-05-27 13:45:48930browse
MYSQL的profiling功能要在Mysql版本5.0.37以上才能使用。
查看profile是否开启
mysql> show variables like '%profil%';
+------------------------+-------+ | Variable_name | Value | +------------------------+-------+ | profiling | OFF | --开启SQL语句剖析功能 | profiling_history_size | 15 | --设置保留profiling的数目，缺省为15，范围为0至100，为0时将禁用profiling +------------------------+-------+ 2 rows in set (0.00 sec)
基于会话级别开启
mysql> set profiling = 1; --关闭则用set profiling = off
Query OK, 0 rows affected (0.00 sec)
mysql> select distinct d.account,a.server_id from tab_appserver_user a -> inner join tab_department_parent b on a.key_id = b.parent_id -> inner join tab_department_member c on b.department_id = c.department_id and c.state=1 -> and c.isdefault=1 inner join tab_user_info d on c.user_id = d.user_id and d.state=1 -> where a.type=1 -> union -> select distinct b.account,a.server_id from tab_appserver_user a -> inner join tab_user_info b on a.key_id = b.user_id and b.state=1 -> where a.type=0;
查看是否设置生效：
select @@profiling;
默认是0，设置成功是1
运行SQL语句：
mysql> select * FROM hx_line WHERE id = '1455023';
查看profiles
mysql> show profiles;
+----------+------------+---------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+---------------------------------------------+ | 1 | 0.00036150 | select * FROM hx_line WHERE id = '1455023' | +----------+------------+---------------------------------------------+
查看具体某条的profile
mysql> show profile FOR QUERY 1;
+--------------------------------+----------+ | Status | Duration | +--------------------------------+----------+ | starting | 0.000013 | | Waiting for query cache lock | 0.000014 | | checking query cache for query | 0.000038 | | checking permissions | 0.000006 | | Opening tables | 0.000013 | | System lock | 0.000009 | | Waiting for query cache lock | 0.000024 | | init | 0.000060 | | optimizing | 0.000014 | | statistics | 0.000046 | | preparing | 0.000017 | | executing | 0.000004 | | Sending data | 0.000081 | | end | 0.000005 | | query end | 0.000004 | | closing tables | 0.000008 | | freeing items | 0.000009 | | Waiting for query cache lock | 0.000003 | | freeing items | 0.000013 | | Waiting for query cache lock | 0.000003 | | freeing items | 0.000003 | | storing result in query cache | 0.000005 | | logging slow query | 0.000003 | | cleaning up | 0.000004 | +--------------------------------+----------+ 24 rows
我们看到了一个简单的查询，MYSQL内部做了24次操作。
另外，看到了一堆query cache的操作，试着把query_cache_size=0，把query_cache关闭，再次测试：
mysql> show profile FOR QUERY 1;
+----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 0.000040 | | checking permissions | 0.000007 | | Opening tables | 0.000015 | | System lock | 0.000010 | | init | 0.000061 | | optimizing | 0.000013 | | statistics | 0.000059 | | preparing | 0.000018 | | executing | 0.000004 | | Sending data | 0.000092 | | end | 0.000006 | | query end | 0.000004 | | closing tables | 0.000008 | | freeing items | 0.000020 | | logging slow query | 0.000003 | | cleaning up | 0.000004 | +----------------------+----------+ 16 rows in set (0.00 sec)
当开启了query_cache的情况下，需要多操作6次，在这个示例里面多化了0.000087s。
查询这条语句对CPU的使用情况：
mysql> show profile cpu FOR QUERY 1;
+----------------------+----------+----------+------------+ | Status | Duration | CPU_user | CPU_system | +----------------------+----------+----------+------------+ | starting | 0.000037 | 0.000000 | 0.000000 | | checking permissions | 0.000009 | 0.000000 | 0.000000 | | Opening tables | 0.000014 | 0.000000 | 0.000000 | | System lock | 0.000009 | 0.000000 | 0.000000 | | init | 0.000059 | 0.000000 | 0.000000 | | optimizing | 0.000009 | 0.000000 | 0.000000 | | statistics | 0.000044 | 0.000000 | 0.000000 | | preparing | 0.000015 | 0.000000 | 0.000000 | | executing | 0.000004 | 0.000000 | 0.000000 | | Sending data | 0.000081 | 0.000000 | 0.000000 | | end | 0.000006 | 0.000000 | 0.000000 | | query end | 0.000004 | 0.000000 | 0.000000 | | closing tables | 0.000008 | 0.000000 | 0.000000 | | freeing items | 0.000021 | 0.000000 | 0.000000 | | logging slow query | 0.000004 | 0.000000 | 0.000000 | | cleaning up | 0.000004 | 0.000000 | 0.000000 | +----------------------+----------+----------+------------+
查看io及cpu的消耗
mysql> show profile block io,cpu for query 1;
+--------------------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +--------------------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000018 | NULL | NULL | NULL | NULL | | checking query cache for query | 0.000099 | NULL | NULL | NULL | NULL | | Opening tables | 0.000963 | NULL | NULL | NULL | NULL | | System lock | 0.000015 | NULL | NULL | NULL | NULL | | Table lock | 0.000169 | NULL | NULL | NULL | NULL | | optimizing | 0.000020 | NULL | NULL | NULL | NULL | | statistics | 0.000027 | NULL | NULL | NULL | NULL | | preparing | 0.000018 | NULL | NULL | NULL | NULL | | Creating tmp table | 0.000055 | NULL | NULL | NULL | NULL | | executing | 0.000003 | NULL | NULL | NULL | NULL | | Copying to tmp table | 0.704845 | NULL | NULL | NULL | NULL | | Sending data | 0.130039 | NULL | NULL | NULL | NULL | | optimizing | 0.000029 | NULL | NULL | NULL | NULL | | statistics | 0.000029 | NULL | NULL | NULL | NULL | | preparing | 0.000020 | NULL | NULL | NULL | NULL | | Creating tmp table | 0.000142 | NULL | NULL | NULL | NULL | | executing | 0.000003 | NULL | NULL | NULL | NULL | | Copying to tmp table | 0.000086 | NULL | NULL | NULL | NULL | | Sending data | 0.000067 | NULL | NULL | NULL | NULL | | optimizing | 0.000004 | NULL | NULL | NULL | NULL | | statistics | 0.000005 | NULL | NULL | NULL | NULL | | preparing | 0.000005 | NULL | NULL | NULL | NULL | | executing | 0.000002 | NULL | NULL | NULL | NULL | | Sending data | 0.023963 | NULL | NULL | NULL | NULL | | removing tmp table | 0.003420 | NULL | NULL | NULL | NULL | | Sending data | 0.000005 | NULL | NULL | NULL | NULL | | removing tmp table | 0.003308 | NULL | NULL | NULL | NULL | | Sending data | 0.000006 | NULL | NULL | NULL | NULL | | removing tmp table | 0.000007 | NULL | NULL | NULL | NULL | | Sending data | 0.000009 | NULL | NULL | NULL | NULL | | query end | 0.000003 | NULL | NULL | NULL | NULL | | freeing items | 0.000144 | NULL | NULL | NULL | NULL | | storing result in query cache | 0.000011 | NULL | NULL | NULL | NULL | | logging slow query | 0.000003 | NULL | NULL | NULL | NULL | | cleaning up | 0.000006 | NULL | NULL | NULL | NULL | +--------------------------------+----------+----------+------------+--------------+---------------+ 35 rows in set (0.00 sec)
使用查询语句对消耗进行排序
mysql> SELECT STATE, SUM(DURATION) AS Total_R,ROUND( 100 * SUM(DURATION) / (SE CT SUM(DURATION) -> FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = 1), 2) AS Pct_R, CO T(*) AS Calls,SUM(DURATION) / COUNT(*) AS "R/Call" -> FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = 1 GROUP BY STATE O ER BY Total_R DESC;
+--------------------------------+----------+-------+-------+--------------+ | STATE | Total_R | Pct_R | Calls | R/Call | +--------------------------------+----------+-------+-------+--------------+ | Copying to tmp table | 0.704931 | 81.26 | 2 | 0.3524655000 | | Sending data | 0.154089 | 17.76 | 6 | 0.0256815000 | | removing tmp table | 0.006735 | 0.78 | 3 | 0.0022450000 | | Opening tables | 0.000963 | 0.11 | 1 | 0.0009630000 | | Creating tmp table | 0.000197 | 0.02 | 2 | 0.0000985000 | | Table lock | 0.000169 | 0.02 | 1 | 0.0001690000 | | freeing items | 0.000144 | 0.02 | 1 | 0.0001440000 | | checking query cache for query | 0.000099 | 0.01 | 1 | 0.0000990000 | | statistics | 0.000061 | 0.01 | 3 | 0.0000203333 | | optimizing | 0.000053 | 0.01 | 3 | 0.0000176667 | | preparing | 0.000043 | 0.00 | 3 | 0.0000143333 | | starting | 0.000018 | 0.00 | 1 | 0.0000180000 | | System lock | 0.000015 | 0.00 | 1 | 0.0000150000 | | storing result in query cache | 0.000011 | 0.00 | 1 | 0.0000110000 | | executing | 0.000008 | 0.00 | 3 | 0.0000026667 | | cleaning up | 0.000006 | 0.00 | 1 | 0.0000060000 | | logging slow query | 0.000003 | 0.00 | 1 | 0.0000030000 | | query end | 0.000003 | 0.00 | 1 | 0.0000030000 | +--------------------------------+----------+-------+-------+--------------+ 18 rows in set (0.01 sec)
show profile额外一些命令：
* ALL - displays all information
* BLOCK IO - displays counts for block input and output Operations
* CONTEXT SWITCHES - displays counts for voluntary and involuntary context switches
* ipC - displays counts for messages sent and received
* MEMORY - is not currently implemented
* PAGE FAULTS - displays counts for major and minor page faults
* SOURCE - displays the names of functions from the source code, together with the name and line number of the file in which the function occurs
* SWAPS - displays swap counts
最后说明：profile是一个非常量化的子标，可以根据这些量化指标来比较各项资源的消耗，有利于我们对该语句的整体把控！
Statement：
The content of this article is voluntarily contributed by netizens, and the copyright belongs to the original author. This site does not assume corresponding legal responsibility. If you find any content suspected of plagiarism or infringement, please contact admin@php.cn
Previous article：MySQL对数据库数据进行复制的基本过程详解_MySQLNext article：MySQL缓存的查询和清除命令使用详解_MySQL