[转载文章]

mysql sql profiler分析

MySQL从5.0.37起,提供了profile的功能,对性能调试极其有用. profile的功能主要用途是显示 sql 执行的整个过程中各项资源的使用情况。分析器可以更好的展示出不良 SQL 的性能问题所在。

下面我们举例介绍一下 MySQL SQL Profiler 的使用方法:

首先,开启 MySQL SQL Profiler

mysql> SELECT @@profiling;

+————-+

@@profiling

+————-+

0

+————-+

1 row in set (0.00 sec)

mysql> SET profiling = 1;

Query OK, 0 rows affected (0.00 sec)

mysql> SELECT @@profiling;

+————-+

@@profiling

+————-+

1

+————-+

1 row in set (0.00 sec)

默认情况下 profiling 的值为 0 表示 MySQL SQL Profiler 处于 OFF 状态,开启 SQL 性能分析器后 profiling 的值为 1.

通过 sql 性能分析器,我们来对比一下 下列语句前后 2 次执行过程的差异,对我们了解 sql 的详细执行过程是非常有帮助的。

mysql> create table t_engines select * from t_engines1;

Query OK, 57344 rows affected (0.10 sec)

Records: 57344 Duplicates: 0 Warnings: 0

mysql> select count(*) from t_engines;

+———-+

count(*)

+———-+

57344

+———-+

1 row in set (0.00 sec)

mysql> select count(*) from t_engines;

+———-+

count(*)

+———-+

57344

+———-+

1 row in set (0.00 sec)

mysql> SHOW PROFILES;

+———-+————+————————————————-+

Query_ID Duration Query

+———-+————+————————————————-+

26 0.10213775 create table t_engines select * from t_engines1
27 0.00032775 select count(*) from t_engines
28 0.00003850 select count(*) from t_engines

+———-+————+————————————————-+

15 rows in set (0.01 sec)

mysql> SHOW PROFILE FOR QUERY 27;

+——————————–+————+

Status Duration

+——————————–+————+

(initialization) 0.00000425
checking query cache for query 0.00004050
checking permissions 0.00001050
Opening tables 0.00018250
System lock 0.00000450
Table lock 0.00001775
init 0.00001075
optimizing 0.00000550
executing 0.00002775
end 0.00000450
query end 0.00000325
storing result in query cache 0.00000400
freeing items 0.00000400
closing tables 0.00000500
logging slow query 0.00000300

+——————————–+————+

15 rows in set (0.00 sec)

mysql> SHOW PROFILE FOR QUERY 28;

+————————————-+————+

Status Duration

+————————————-+————+

(initialization) 0.00000350
checking query cache for query 0.00000750
checking privileges on cached query 0.00000500
checking permissions 0.00000525
sending cached result to client 0.00001275
logging slow query 0.00000450

+————————————-+————+

6 rows in set (0.00 sec)

mysql> SELECT sum( FORMAT(DURATION, 6)) AS DURATION FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID =27 ORDER BY SEQ;

+———-+

DURATION

+———-+

0.000326

+———-+

1 row in set (0.00 sec)

mysql> SELECT sum( FORMAT(DURATION, 6)) AS DURATION FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID =28 ORDER BY SEQ;

+———-+

DURATION

+———-+

0.000039

+———-+

1 row in set (0.00 sec)

mysql>

从上面的例子中我们可以清晰的看出 2 次执行 count 语句的差别, SHOW PROFILE FOR QUERY 27 展现的是第一次 count 统计的执行过程,包含了 Opening tables 、 Table lock 等操作 。而 SHOW PROFILE FOR QUERY 28 展示了第二次 count 统计的执行过程 , 第二次 count 直接从查询缓存中返回 count 统计结果,通过对比 2 次统计的总执行时间发现,缓存读的速度接近物理读的 10 倍。通过使用 SQL 性能分析器可以帮助我们对一些比较难以确定性能问题的 SQL 进行诊断,找出问题根源。

原文地址:http://www.chineselinuxuniversity.net/articles/34244.shtml