• 首先，开启 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 进行诊断，找出问题根源。

本文来自ChinaUnix博客，如果查看原文请点：http://blog.chinaunix.net/u3/93470/showart_2002151.html