MySQL之SQL优化系列（三）

MySQL精准分析执行时间

当进行sql性能瓶颈分析时，第一反应肯定是查看sql执行时间，那么当使用慢查询日志，以及explain都无法知晓具体信息时，怎么分析。

Query Profiler

Query Profiler是MYSQL自带的一种query诊断分析工具，通过它可以分析出一条SQL语句的性能瓶颈在什么地方。通过show variables like "%pro%";可以查看该工具是否开启：

mysql> show variables like "%pro%";
+------------------------------------------+-------+
| Variable_name                            | Value |
+------------------------------------------+-------+
| check_proxy_users                        | OFF   |
| have_profiling                           | YES   |
| mysql_native_password_proxy_users        | OFF   |
| performance_schema_max_program_instances | -1    |
| profiling                                | OFF   |
| profiling_history_size                   | 15    |
| protocol_version                         | 10    |
| proxy_user                               |       |
| sha256_password_proxy_users              | OFF   |
| slave_compressed_protocol                | OFF   |
| stored_program_cache                     | 256   |
+------------------------------------------+-------+
11 rows in set, 1 warning (0.00 sec)

发现当前为关闭状态，手动开启：

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

使用

首先执行几条sql，作为分析样本：

mysql> select sleep(3);
+----------+
| sleep(3) |
+----------+
|        0 |
+----------+
1 row in set (3.00 sec)

mysql> select 1;
+---+
| 1 |
+---+
| 1 |
+---+
1 row in set (0.00 sec)

查看执行情况：

mysql> show profiles;
+----------+------------+-----------------------------+
| Query_ID | Duration   | Query                       |
+----------+------------+-----------------------------+
|        1 | 0.00325925 | show variables like "%pro%" |
|        2 | 2.99971075 | select sleep(3)             |
|        3 | 0.00051050 | select 1                    |
+----------+------------+-----------------------------+
3 rows in set, 1 warning (0.00 sec)

可以看出具体执行时间，若想查看具体那一条SQL的具体信息：

mysql> show profile for query 2;      
+----------------------+----------+   
| Status               | Duration |   
+----------------------+----------+   
| starting             | 0.000103 |   
| checking permissions | 0.000008 |   
| Opening tables       | 0.000006 |   
| init                 | 0.000016 |   
| optimizing           | 0.000008 |   
| executing            | 0.000018 |   
| User sleep           | 2.999385 |   
| end                  | 0.000016 |   
| query end            | 0.000009 |   
| closing tables       | 0.000005 |   
| freeing items        | 0.000115 |   
| cleaning up          | 0.000023 |   
+----------------------+----------+   
12 rows in set, 1 warning (0.00 sec)  

对系统分析

查看执行sql中对系统的影响，例如，查看磁盘IO：

mysql> show profile block io for query 2;
+----------------------+----------+--------------+---------------+
| Status               | Duration | Block_ops_in | Block_ops_out |
+----------------------+----------+--------------+---------------+
| starting             | 0.000103 |         NULL |          NULL |
| checking permissions | 0.000008 |         NULL |          NULL |
| Opening tables       | 0.000006 |         NULL |          NULL |
| init                 | 0.000016 |         NULL |          NULL |
| optimizing           | 0.000008 |         NULL |          NULL |
| executing            | 0.000018 |         NULL |          NULL |
| User sleep           | 2.999385 |         NULL |          NULL |
| end                  | 0.000016 |         NULL |          NULL |
| query end            | 0.000009 |         NULL |          NULL |
| closing tables       | 0.000005 |         NULL |          NULL |
| freeing items        | 0.000115 |         NULL |          NULL |
| cleaning up          | 0.000023 |         NULL |          NULL |
+----------------------+----------+--------------+---------------+
12 rows in set, 1 warning (0.00 sec)

可以完整的看出select sleep(3);该sql执行过程中对磁盘IO的影响。类似的还有：

mysql> show profile cpu for query 2;
mysql> show profile memory for query 2;
mysql> show profile swaps for query 2;
mysql> show profile context switches for query 2;
mysql> show profile all for query 2;