MySQL的SQL Profiler性能分析器
MySQL从5.0开始提供了 SQL Profiler性能分析器，其主要用途是显示 sql 执行的整个过程中各项资源的使用情况。这个工具可以很好的展示出 SQL 的性能问题。下面我们从五个角度并举例介绍MySQL SQL Profiler的使用方法(尤其第五个角度,从源码出发,分析了重要的几个项目的含义,便于读者准确掌握其含义)：
一检查是否启用性能分析功能
mysql> select version();
+--------------+
| version() |
+--------------+
| 5.6.12 |
+--------------+
1 row in set (0.00 sec)
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: ALL
| BLOCK IO
| CONTEXT SWITCHES
| CPU
| IPC
| MEMORY
| PAGE FAULTS
| SOURCE
| SWAPS
说明
获取执行过的SQL语句对资源的使用情况。
表示可以指定获取某个特定的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;
+----+-------------+-------+------+---------------+------+---------+------+------+----------------------------------------------------+
|> +----+-------------+-------+------+---------------+------+---------+------+------+----------------------------------------------------+
| 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 | | sql_parse.cc | 5256 |
| checking permissions | 0.000010 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 5256 |
| checking permissions | 0.000009 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 5256 |
| checking permissions | 0.000014 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 5256 |
| checking permissions | 0.000016 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 5256 |
| checking permissions | 0.000013 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 5256 |
| checking permissions | 0.000018 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 5256 |
| Opening tables | 0.000259 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_base.cc | 4911 |
| init | 0.000212 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_select.cc | 1050 |
| System lock | 0.000082 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | lock.cc | 304 |
| optimizing | 0.000149 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_optimizer.cc | 138 |
| statistics | 0.000280 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_optimizer.cc | 362 |
| preparing | 0.000121 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_optimizer.cc | 485 |
| explaining | 0.000423 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_select.cc | 850 |
| query end | 0.000117 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 4956 |
| closing tables | 0.000121 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 5004 |
| freeing items | 0.000280 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | sql_parse.cc | 6264 |
| cleaning up | 0.000060 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL |
NULL | NULL | NULL |NULL | | 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 |”这一行的内容。
页:
[1]