sql优化-4-SQL执行时间

查看sql执行时间

profiles 会记录所有profiling打开之后的全部SQL查询语句所花费的时间。

打开profiles

mysql> show variables like '%profiling%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| have_profiling         | YES   |
| profiling              | OFF   |
| profiling_history_size | 15    | --页面容量只有15条，只显示最近15条
+------------------------+-------+
3 rows in set (0.00 sec)

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

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

mysql> select * from dept;      
Empty set (0.00 sec)

show profiles;

缺点:不够精确,只能看到总共消费的时间,不能看到各个硬件消费的时间(cpu io)

mysql> show profiles;
+----------+------------+-----------------------------------+
| Query_ID | Duration   | Query                             |
+----------+------------+-----------------------------------+
|        1 | 0.00057475 | show variables like '%profiling%' |
|        2 | 0.00016700 | select * from dept                |
+----------+------------+-----------------------------------+
2 rows in set, 1 warning (0.00 sec)      
                                  
mysql>                                                       

精确分析

show profile all for query 上一步查询到的Query_Id;
show profile cpu,block io for query 上一步查询到的Query_Id;

mysql> show profile cpu,block io for query 5;                                             
+----------------------+----------+----------+------------+--------------+---------------+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting             | 0.000034 | 0.000000 |   0.000000 |         NULL |          NULL |
| checking permissions | 0.000004 | 0.000000 |   0.000000 |         NULL |          NULL |
| Opening tables       | 0.000014 | 0.000000 |   0.000000 |         NULL |          NULL |
| init                 | 0.000012 | 0.000000 |   0.000000 |         NULL |          NULL |
| System lock          | 0.000004 | 0.000000 |   0.000000 |         NULL |          NULL |
| optimizing           | 0.000004 | 0.000000 |   0.000000 |         NULL |          NULL |
| statistics           | 0.000014 | 0.000000 |   0.000000 |         NULL |          NULL |
| preparing            | 0.000006 | 0.000000 |   0.000000 |         NULL |          NULL |
| executing            | 0.000001 | 0.000000 |   0.000000 |         NULL |          NULL |
| Sending data         | 0.000060 | 0.000000 |   0.000000 |         NULL |          NULL |
| end                  | 0.000002 | 0.000000 |   0.000000 |         NULL |          NULL |
| query end            | 0.000004 | 0.000000 |   0.000000 |         NULL |          NULL |
| closing tables       | 0.000005 | 0.000000 |   0.000000 |         NULL |          NULL |
| freeing items        | 0.000038 | 0.000000 |   0.000000 |         NULL |          NULL |
| cleaning up          | 0.000013 | 0.000000 |   0.000000 |         NULL |          NULL |
+----------------------+----------+----------+------------+--------------+---------------+
15 rows in set, 1 warning (0.00 sec)                                                      
                                                                                          
mysql>