Mysql从5.1版本开始引入show profile来剖析单条语句功能
一、 查看是否支持这个功能
yes表示支持
mysql> show variables like 'have_profiling';
+----------------+-------+
| Variable_name | Value |
+----------------+-------+
| have_profiling | YES |
+----------------+-------+
1 row in set (0.01 sec)
二、使用步骤
1.在 sql命令行中输入：set profiling=1;来开启（当前会话关闭前，只需要执行一次）
mysql> set profiling=1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
2.然后在服务器上执行你的SQL语句，都会被测量其消耗的时间和其他一些查询执行状态变更相关的数据
mysql> select count(*) from he_store_discount;
+----------+
| count(*) |
+----------+
| 1 |
+----------+
1 row in set (0.00 sec)
3. 然后再执行：show prifiles;命令，所有的查询SQL都会被列出来
mysql> show profiles;
+----------+------------+----------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+----------------------------------------+
| 1 | 0.00013000 | select count(*) from he_store_discount |
| 2 | 0.00290900 | show databases |
| 3 | 0.00016200 | SELECT DATABASE() |
| 4 | 0.00052800 | show databases |
| 5 | 0.00204500 | show tables |
| 6 | 0.00027000 | select count(*) from he_store_discount |
+----------+------------+----------------------------------------+
6 rows in set, 1 warning (0.00 sec)
4.然后再根据编号(即Query_ID)查询具体SQL的执行过程
mysql> show profile for query 1; +---------------+----------+ | Status | Duration | +---------------+----------+ | starting | 0.000091 | | freeing items | 0.000028 | | cleaning up | 0.000011 | +---------------+----------+ 3 rows in set, 1 warning (0.01 sec) mysql> show profile for query 2; +----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 0.000044 | | checking permissions | 0.000011 | | Opening tables | 0.000039 | | init | 0.000013 | | System lock | 0.000008 | | optimizing | 0.000006 | | statistics | 0.000012 | | preparing | 0.000012 | | executing | 0.002696 | | Sending data | 0.000021 | | end | 0.000004 | | query end | 0.000006 | | closing tables | 0.000003 | | removing tmp table | 0.000006 | | closing tables | 0.000003 | | freeing items | 0.000017 | | cleaning up | 0.000008 | +----------------------+----------+ 17 rows in set, 1 warning (0.00 sec) mysql> show profile for query 3; +----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 0.000046 | | checking permissions | 0.000009 | | Opening tables | 0.000008 | | init | 0.000014 | | optimizing | 0.000008 | | executing | 0.000012 | | end | 0.000006 | | query end | 0.000008 | | closing tables | 0.000007 | | freeing items | 0.000027 | | cleaning up | 0.000017 | +----------------------+----------+ 11 rows in set, 1 warning (0.00 sec)
5.当查到最耗时的线程状态时，可以进一步选择all或者cpu,block io,page faults等明细类型来查看mysql在每个线程状态中使用什么资源上耗费了过高的时间：
mysql> show profile all for query 1; +---------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+------------------+--------------+-------------+ | Status | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent | Messages_received | Page_faults_major | Page_faults_minor | Swaps | Source_function | Source_file | Source_line | +---------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+------------------+--------------+-------------+ | starting | 0.000091 | 0.000073 | 0.000012 | 0 | 1 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL | | freeing items | 0.000028 | 0.000016 | 0.000011 | 0 | 0 | 0 | 0 | 1 | 0 | 0 | 0 | 0 | mysql_parse | sql_parse.cc | 5593 | | cleaning up | 0.000011 | 0.000008 | 0.000003 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | dispatch_command | sql_parse.cc | 1902 | +---------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+------------------+--------------+-------------+ 3 rows in set, 1 warning (0.00 sec) mysql> show profile cpu for query 1; +---------------+----------+----------+------------+ | Status | Duration | CPU_user | CPU_system | +---------------+----------+----------+------------+ | starting | 0.000091 | 0.000073 | 0.000012 | | freeing items | 0.000028 | 0.000016 | 0.000011 | | cleaning up | 0.000011 | 0.000008 | 0.000003 | +---------------+----------+----------+------------+ 3 rows in set, 1 warning (0.00 sec) mysql> show profile block io for query 1; +---------------+----------+--------------+---------------+ | Status | Duration | Block_ops_in | Block_ops_out | +---------------+----------+--------------+---------------+ | starting | 0.000091 | 0 | 0 | | freeing items | 0.000028 | 0 | 0 | | cleaning up | 0.000011 | 0 | 0 | +---------------+----------+--------------+---------------+ 3 rows in set, 1 warning (0.00 sec) mysql> show profile page faults for query 1; +---------------+----------+-------------------+-------------------+ | Status | Duration | Page_faults_major | Page_faults_minor | +---------------+----------+-------------------+-------------------+ | starting | 0.000091 | 0 | 0 | | freeing items | 0.000028 | 0 | 0 | | cleaning up | 0.000011 | 0 | 0 | +---------------+----------+-------------------+-------------------+ 3 rows in set, 1 warning (0.00 sec)
上面的输出中可以以很高的精度显示了查询的响应时间，列出了查询执行的每个步骤花费的时间