show profiles 查看MySQL语句的执行时间

farmer111

　　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