show profiles 查看MySQL语句的执行时间
show profiles作用范围
这个命令只是在本会话内起作用，即无法分析本会话外的语句。
开启分析功能后，所有本会话中的语句都被分析（甚至包括执行错误的语句），除了SHOW PROFILE和SHOW PROFILES两句本身。
方法一：profiling
mysql>show variables like "profiling";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling | OFF |
+---------------+-------+
1 row in set (0.01 sec)
mysql> set profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
mysql> select user,authentication_string,host from mysql.user;
5 rows in set (0.00 sec)
mysql> show profile for query 1;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000069 |
| checking permissions | 0.000008 |
| Opening tables | 0.000109 |
| init | 0.000018 |
| System lock | 0.000009 |
| optimizing | 0.000003 |
| statistics | 0.000014 |
| preparing | 0.000010 |
| executing | 0.000003 |
| Sending data | 0.000038 |
| end | 0.000004 |
| query end | 0.000005 |
| closing tables | 0.000007 |
| freeing items | 0.000011 |
| cleaning up | 0.000013 |
+----------------------+----------+
15 rows in set, 1 warning (0.01 sec)
mysql> show profile cpu, block io, memory,swaps,context switches,source for query 1;
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+-----------------------+----------------------+-------------+
| Status | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Swaps | Source_function | Source_file | Source_line |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+-----------------------+----------------------+-------------+
| starting | 0.000069 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL |
| checking permissions | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | check_access | sql_authorization.cc | 810 |
| Opening tables | 0.000109 | 0.001000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | open_tables | sql_base.cc | 5650 |
| init | 0.000018 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | handle_query | sql_select.cc | 121 |
| System lock | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock.cc | 323 |
| optimizing | 0.000003 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | optimize | sql_optimizer.cc | 151 |
| statistics | 0.000014 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | optimize | sql_optimizer.cc | 367 |
| preparing | 0.000010 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | optimize | sql_optimizer.cc | 475 |
| executing | 0.000003 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | exec | sql_executor.cc | 119 |
| Sending data | 0.000038 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | exec | sql_executor.cc | 195 |
| end | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | handle_query | sql_select.cc | 199 |
| query end | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 4968 |
| closing tables | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command | sql_parse.cc | 5020 |
| freeing items | 0.000011 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | mysql_parse | sql_parse.cc | 5596 |
| cleaning up | 0.000013 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | dispatch_command | sql_parse.cc | 1902 |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+-----------------------+----------------------+-------------+
15 rows in set, 1 warning (0.00 sec)
mysql>select * from employees.employees where emp_no=10001;
+--------+------------+------------+-----------+--------+------------+
| emp_no | birth_date | first_name | last_name | gender | hire_date|
+--------+------------+------------+-----------+--------+------------+
|10001 | 1953-09-02 | Georgi |> +--------+------------+------------+-----------+--------+------------+
1 row in set (0.00 sec)
mysql> show profile cpu, block io, memory,swaps,context switches,source for query 2;
+---------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+------------------+--------------+-------------+
| Status | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Swaps | Source_function| Source_file| Source_line |
+---------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+------------------+--------------+-------------+
| starting | 0.000083 | 0.000000 | 0.001000 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL |
| freeing items | 0.000016 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | mysql_parse | sql_parse.cc | 5596 |
| cleaning up | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | 0 | 0 | 0 | dispatch_command | sql_parse.cc | 1902 |
+---------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+------------------+--------------+-------------+
3 rows in set, 1 warning (0.00 sec)
mysql> show profile for query 2;
+---------------+----------+
| Status | Duration |
+---------------+----------+
| starting | 0.000083 |
| freeing items | 0.000016 |
| cleaning up | 0.000005 |
+---------------+----------+
3 rows in set, 1 warning (0.01 sec)
mysql>set profiling=0 ;
Query OK, 0 rows affected, 1 warning (0.00 sec)
方法二：timestampdiff来查看执行时间。
mysql>
set @d=now();
select * from employees.employees where emp_no=10001;
select timestampdiff(second,@d,now());
--回车
+--------------------------------+
| timestampdiff(second,@d,now()) |
+--------------------------------+
| 21 |
+--------------------------------+
1 row in set (0.00 sec)
参考：http://blog.csdn.net/mydriverc2/article/details/53837435
页:
[1]