1. 程式人生 > 其它 >show profiles 檢視MySQL語句的執行時間

show profiles 檢視MySQL語句的執行時間

技術標籤:MYSQL效能

一、 作用範圍

這個命令只是在本會話內起作用,無法分析本會話外的語句。開啟後所有本會話中的語句都被分析(甚至包括執行錯誤的語句),除了SHOW PROFILE和SHOW PROFILES兩句本身。

二、 方法一 profiling

1. 開啟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)

2. 執行待分析語句

mysql> select user,authentication_string,host from mysql.user;
5 rows in set (0.00 sec)

3. 檢視profiling結果

  • 各部分消耗時間詳情,query 1表示執行的第一個sql。
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)

4. 關閉profiling

mysql> set profiling=0;
Query OK, 0 rows affected, 1 warning (0.00 sec)

三、 方法二 timestampdiff檢視執行時間

set @d=now();

select * from employees.employees where emp_no=10001;

select timestampdiff(second,@d,now()); 
+--------------------------------+
| timestampdiff(second,@d,now()) |
+--------------------------------+
|              21                |
+--------------------------------+

參考:http://blog.csdn.net/mydriverc2/article/details/53837435