MySQL的SQL Profiler性能分析器

 

MySQL5.0开始提供了 SQL Profiler性能分析器,其主要用途是显示 sql 执行的整个过程当中各项资源的使用状况。这个工具能够很好的展现出 SQL 的性能问题。mysql


下面咱们从五个角度并举例介绍MySQL SQL Profiler的使用方法(尤为第五个角度,从源码出发,分析了重要的几个项目的含义,便于读者准确掌握其含义):
sql


一检查是否启用性能分析功能函数

mysql> select version();工具

+--------------+oop

| version() |源码分析

+--------------+性能

| 5.6.12 |优化

+--------------+xml

1 row in set (0.00 sec)blog


mysql> SELECT @@profiling;

+-------------+

| @@profiling |

+-------------+

| 0 |

+-------------+

1 row in set, 1 warning (0.00 sec)

说明:

0表示没有开启性能分析功能


二开启性能关系功能

mysql> SET profiling = 1;

Query OK, 0 rows affected (0.00 sec)


三查询获取性能信息

3.1)显示单条SQL语句的执行过程的性能信息:

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

说明

获取执行过的SQL语句对资源的使用状况。

[FOR QUERY n]表示能够指定获取某个特定的SQL的性能信息,此信息的输出和获取所有SQL语句的输出内容不一样,对于查看特定的语句的过程环节,更有帮助。

3.2)显示全部SQL语句的执行状况:

SHOW PROFILE;

四示例

建立表:

CREATE TABLE a(col INT);

CREATE TABLE b(col INT);

执行SQL

mysql> set profiling=1;

Query OK, 0 rows affected, 1 warning (0.00 sec)


mysql> EXPLAIN SELECT 1 FROM

-> a

-> LEFT JOIN b ON b.col = a.col

-> RIGHT JOIN a AS T0 ON b.col = a.col

-> LEFT JOIN a AS T1 ON T1.col = a.col

-> RIGHT JOIN b AS T2 ON T2.col = a.col

-> JOIN a AS T3 ON T3.col = a.col

-> JOIN b AS t4 ON T4.col = a.col;

+----+-------------+-------+------+---------------+------+---------+------+------+----------------------------------------------------+

| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |

+----+-------------+-------+------+---------------+------+---------+------+------+----------------------------------------------------+

| 1 | SIMPLE | a | ALL | NULL | NULL | NULL | NULL | 1 | NULL |

| 1 | SIMPLE | b | ALL | NULL | NULL | NULL | NULL | 1 | Using where; Using join buffer (Block Nested Loop) |

| 1 | SIMPLE | T0 | ALL | NULL | NULL | NULL | NULL | 1 | Using join buffer (Block Nested Loop) |

| 1 | SIMPLE | T1 | ALL | NULL | NULL | NULL | NULL | 1 | Using where; Using join buffer (Block Nested Loop) |

| 1 | SIMPLE | T2 | ALL | NULL | NULL | NULL | NULL | 1 | Using where; Using join buffer (Block Nested Loop) |

| 1 | SIMPLE | T3 | ALL | NULL | NULL | NULL | NULL | 1 | Using where; Using join buffer (Block Nested Loop) |

| 1 | SIMPLE | t4 | ALL | NULL | NULL | NULL | NULL | 1 | Using where; Using join buffer (Block Nested Loop) |

+----+-------------+-------+------+---------------+------+---------+------+------+----------------------------------------------------+

7 rows in set (0.00 sec)


以下输出,有价值的是“Duration”列,标示了一个Query的执行时间

mysql> SHOW PROFILES;

+----------+------------+-----------------------------------------------------------------------------------------------------------------------------

----------------------------------------------------------------------------------------------------+

| Query_ID | Duration | Query

|

+----------+------------+-----------------------------------------------------------------------------------------------------------------------------

----------------------------------------------------------------------------------------------------+

| 1 | 0.00274225 | EXPLAIN SELECT 1 FROM

a

LEFT JOIN b ON b.col = a.col

RIGHT JOIN a AS T0 ON b.col = a.col

LEFT JOIN a AS T1 ON T1.col = a.col

RIGHT JOIN b AS T2 ON T2.col = a.col

JOIN a AS T3 ON T3.col = a.col

JOIN b AS t4 ON T4.col = a.col |

+----------+------------+-----------------------------------------------------------------------------------------------------------------------------

----------------------------------------------------------------------------------------------------+

1 row in set, 1 warning (0.00 sec)


以下能够根据上条语句的输出信息中的“Query_ID”列的值,查询一条语句的具体状况

 

 
 

mysql> SHOW PROFILE ALL FOR QUERY 1;
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+--
-----------------+-------------------+-------------------+-------+-----------------+------------------+-------------+
| Status               | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent | M
essages_received | Page_faults_major | Page_faults_minor | Swaps | Source_function | Source_file      | Source_line |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+--
-----------------+-------------------+-------------------+-------+-----------------+------------------+-------------+
| starting             | 0.000543 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | NULL            | NULL             |        NULL |
| checking permissions | 0.000018 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        5256 |
| checking permissions | 0.000010 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        5256 |
| checking permissions | 0.000009 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        5256 |
| checking permissions | 0.000014 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        5256 |
| checking permissions | 0.000016 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        5256 |
| checking permissions | 0.000013 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        5256 |
| checking permissions | 0.000018 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        5256 |
| Opening tables       | 0.000259 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_base.cc      |        4911 |
| init                 | 0.000212 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_select.cc    |        1050 |
| System lock          | 0.000082 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | lock.cc          |         304 |
| optimizing           | 0.000149 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_optimizer.cc |         138 |
| statistics           | 0.000280 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_optimizer.cc |         362 |
| preparing            | 0.000121 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_optimizer.cc |         485 |
| explaining           | 0.000423 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_select.cc    |         850 |
| query end            | 0.000117 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        4956 |
| closing tables       | 0.000121 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        5004 |
| freeing items        | 0.000280 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        6264 |
| cleaning up          | 0.000060 | 0.000000 |   0.000000 |              NULL |                NULL |         NULL |          NULL |          NULL |
            NULL |              NULL |              NULL |  NULL | <unknown>       | sql_parse.cc     |        1774 |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+--
-----------------+-------------------+-------------------+-------+-----------------+------------------+-------------+
19 rows in set, 1 warning (0.00 sec)



五经过源码分析了解性能分析工具输出信息所表达的含义

看这个简单运行结果,能够分析一条SQL语句执行的各个阶段的时间花费(根据源码分析获得的内容分析直接加在右侧)

 
 

mysql> SHOW PROFILE FOR QUERY 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000543 |
| checking permissions | 0.000018 |
| checking permissions | 0.000010 |
| checking permissions | 0.000009 |
| checking permissions | 0.000014 |
| checking permissions | 0.000016 |
| checking permissions | 0.000013 |
| checking permissions | 0.000018 |
| Opening tables       | 0.000259 |
| init                 | 0.000212 |
| System lock          | 0.000082 |
| optimizing           | 0.000149 |在JOIN::optimize()在函数中,大多数逻辑查询优化工做(如外链接消除/条件化简/)在这个阶段完成,若是这个时间花费多,则检查SQL进行逻辑查询优化调优工做
| statistics           | 0.000280 |调用make_join_statistics()函数完成多表链接,主要执行的是物理查询优化,若是这个时间多,则多表链接的过程须要优化尤为注意要链接的表的个数较多的话,须要查看optimizer_search_depth的值,若是值很大,则须要修改其值为一个较小的数,如7
| preparing            | 0.000121 |多表链接完成,准备其余一些优化操做,为调用JOIN::exec()做执行前的准备工做
| explaining           | 0.000423 |
| query end            | 0.000117 |
| closing tables       | 0.000121 |
| freeing items        | 0.000280 |
| cleaning up          | 0.000060 |
+----------------------+----------+
19 rows in set, 1 warning (0.00 sec)

说明:

第一列,在代码中,一般都是调用以下相似语句完成:

thd_proc_info(thd, "preparing");,对应的就是“| preparing | 0.000121 |”这一行的内容。