mysql显示SQL语句执行所消耗的时间

MySQL中查看SQL的执行计划主要是使用explain来查看，但这个没有办法知道内存及CPU等使用情况，自MySQL 5.0.37以后，mysql提供MySQL Query Profile可以查询到SQL执行所花费的时间，例如SQL执行过程中的SYSTEM LOCK,TABLE LOCK等所花费的时间。

MySQL Query Profile主要功能：

• Bottleneck Analysis
• Workload Analysis
• Ratio-based analysis

MySQL Query Profile使用方法

开启：

1	mysql > set profiling = 1 ;

查看SQL Profile

1 2 3 4 5 6 7 8 9 10 11 12

mysql > show profiles ; mysql > show profiles ; + -- -- -- -- -- + -- -- -- -- -- -- + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- + | Query_ID | Duration    | Query                                      | + -- -- -- -- -- + -- -- -- -- -- -- + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- + |        11 | 0.00006600 | show global variables buffer                | |        12 | 0.00059900 | show global variables like '%buffer%'      | |        15 | 0.00052900 | show global variables like '%buffer%'      | |        16 | 0.00048700 | show global variables like '%cache%'        | |        17 | 0.00032600 | select versioin ( )                          | |        18 | 0.00010300 | select version ( )                            | + -- -- -- -- -- + -- -- -- -- -- -- + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- +

查询各SQL执行所花费的时间

1 2 3 4 5 6 7 8 9 10 11 12

mysql > show profile for query 19 ; # Query ID=19 + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- + -- -- -- -- -- + | Status                          | Duration | + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- + -- -- -- -- -- + | starting                        | 0.000019 | | checking query cache for query | 0.000009 | | checking privileges on cached    | 0.000005 | | sending cached result to clien | 0.000011 | | logging slow query              | 0.000002 | | cleaning up                      | 0.000002 | + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- + -- -- -- -- -- + 6 rows in set ( 0.01 sec )

 

1 2 3 4 5 6 7 8 9 10 11 12 13

mysql > SHOW PROFILE CPU FOR QUERY 2 ; + -- -- -- -- -- -- -- -- -- -- -- + -- -- -- -- -- + -- -- -- -- -- + -- -- -- -- -- -- + | Status                | Duration | CPU_user | CPU_system | + -- -- -- -- -- -- -- -- -- -- -- + -- -- -- -- -- + -- -- -- -- -- + -- -- -- -- -- -- + | checking permissions | 0.000040 | 0.000038 |    0.000002 | | creating table        | 0.000056 | 0.000028 |    0.000028 | | After create          | 0.011363 | 0.000217 |    0.001571 | | query end              | 0.000375 | 0.000013 |    0.000028 | | freeing items          | 0.000089 | 0.000010 |    0.000014 | | logging slow query    | 0.000019 | 0.000009 |    0.000010 | | cleaning up            | 0.000005 | 0.000003 |    0.000002 | + -- -- -- -- -- -- -- -- -- -- -- + -- -- -- -- -- + -- -- -- -- -- + -- -- -- -- -- -- + 7 rows in set ( 0.00 sec )

 

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36

Syntax : SHOW PROFILE [ type [ , type ] . . . ]      [ FOR QUERY n ]      [ LIMIT row_count [ OFFSET offset ] ]   type :      ALL    | BLOCK IO    | CONTEXT SWITCHES    | CPU    | IPC    | MEMORY    | PAGE FAULTS    | SOURCE    | SWAPS   o ALL displays all information   o BLOCK IO displays counts for block input and output operations   o CONTEXT SWITCHES displays counts for voluntary and involuntary    context switches   o CPU displays user and system CPU usage times   o IPC displays counts for messages sent and received   o MEMORY is not currently implemented   o PAGE FAULTS displays counts for major and minor page faults   o SOURCE displays the names of functions from the source code , together    with the name and line number of the file in which the function    occurs   o SWAPS displays swap counts

设置profileing存储记录的size

1 2 3 4 5 6 7 8 9 10 11

mysql > show variables like '%profiling%' ; + -- -- -- -- -- -- -- -- -- -- -- -- + -- -- -- - + | Variable_name            | Value | + -- -- -- -- -- -- -- -- -- -- -- -- + -- -- -- - + | have_profiling          | YES    | | profiling                | OFF    | | profiling_history_size | 15      | + -- -- -- -- -- -- -- -- -- -- -- -- + -- -- -- - + 3 rows in set ( 0.00 sec )   mysql >

关闭profile

1	mysql > set profiling = 0 ;

Profiling is enabled per session. When a session ends, its profiling
information is lost.