show profiles 檢視MySQL語句的執行時間
阿新 • • 發佈:2020-12-08
一、 作用範圍
這個命令只是在本會話內起作用,無法分析本會話外的語句。開啟後所有本會話中的語句都被分析(甚至包括執行錯誤的語句),除了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 |
+--------------------------------+