mysql查询单条语句_如何使用mysql profiling功能分析单条查询语句

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.01sec)

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.00sec)

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.00sec)

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.00sec)

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.00sec)

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)

上面的输出中可以以很高的精度显示了查询的响应时间，列出了查询执行的每个步骤花费的时间