MySQL 性能跟踪语句

   MYSQL5.0家族提供的性能跟踪器确实很爽。
要注意两点。
1、不过版本要在5 . 0 . 37之后

手册上介绍： (SHOW PROFILES and SHOW PROFILE were added in MySQL 5.0.37. )
Important
Please note that the SHOW PROFILE and SHOW PROFILES functionality is part of the MySQL 5.0 Community Server only. 
2、变量profiling是用户变量，每次都得重新启用。
以下是我做的一些实验。数据很明显，就不多解释了。
mysql >  use test
Database  changed
mysql >   set  profiling = 1 ;
Query OK ,  0  rows  affected  ( 0 . 00 sec )

mysql >   show  tables ;
+ ----------------+

|  Tables_in_test  |
+ ----------------+

|  bag_item  |  
|  bag_user  |  
|  score  |  
|  t  |  
+ ----------------+

4  rows   in   set   ( 0 . 03 sec )

mysql >   select   count ( * )   from  t ;
+ ----------+

|   count ( * )   |
+ ----------+

|  2097152  |  
+ ----------+

1  row   in   set   ( 0 . 74 sec )

mysql> show profiles;
+----------+------------+------------------------+
| Query_ID | Duration   | Query                  |
+----------+------------+------------------------+
|        1 | 0.02717000 | show tables            | 
|        2 | 0.74770100 | select count(*) from t | 
+----------+------------+------------------------+
2 rows in set (0.00 sec)

mysql> show profile for query 2;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| (initialization)               | 0.000004 | 
| checking query cache for query | 0.000044 | 
| Opening tables                 | 0.000012 | 
| System lock                    | 0.000017 | 
| Table lock                     | 0.00003  | 
| init                           | 0.000013 | 
| optimizing                     | 0.000008 | 
| statistics                     | 0.000013 | 
| preparing                      | 0.000011 | 
| executing                      | 0.000006 | 
| Sending data                   | 0.747313 | 
| end                            | 0.000014 | 
| query end                      | 0.000006 | 
| storing result in query cache  | 0.000006 | 
| freeing items                  | 0.000012 | 
| closing tables                 | 0.000009 | 
| logging slow query             | 0.000183 | 
+--------------------------------+----------+
17 rows in set (0.00 sec)

mysql> show profile block io,cpu for query 2;
+--------------------------------+----------+----------+------------+--------------+---------------+
| Status                         | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+--------------------------------+----------+----------+------------+--------------+---------------+
| (initialization)               | 0.000004 | 0        | 0          |            0 |             0 | 
| checking query cache for query | 0.000044 | 0        | 0          |            0 |             0 | 
| Opening tables                 | 0.000012 | 0        | 0          |            0 |             0 | 
| System lock                    | 0.000017 | 0        | 0          |            0 |             0 | 
| Table lock                     | 0.00003  | 0        | 0          |            0 |             0 | 
| init                           | 0.000013 | 0        | 0          |            0 |             0 | 
| optimizing                     | 0.000008 | 0        | 0          |            0 |             0 | 
| statistics                     | 0.000013 | 0        | 0          |            0 |             0 | 
| preparing                      | 0.000011 | 0        | 0          |            0 |             0 | 
| executing                      | 0.000006 | 0        | 0          |            0 |             0 | 
| Sending data                   | 0.747313 | 0.746887 | 0          |            0 |             0 | 
| end                            | 0.000014 | 0        | 0          |            0 |             0 | 
| query end                      | 0.000006 | 0        | 0          |            0 |             0 | 
| storing result in query cache  | 0.000006 | 0        | 0          |            0 |             0 | 
| freeing items                  | 0.000012 | 0        | 0          |            0 |             0 | 
| closing tables                 | 0.000009 | 0        | 0          |            0 |             0 | 
| logging slow query             | 0.000183 | 0        | 0          |            0 |             0 | 
+--------------------------------+----------+----------+------------+--------------+---------------+
17 rows in set (0.00 sec)

mysql> insert into t(username) select username from t;
Query OK, 2097152 rows affected (34.17 sec)
Records: 2097152  Duplicates: 0  Warnings: 0

mysql> show profiles;
+----------+-------------+------------------------------------------------+
| Query_ID | Duration    | Query                                          |
+----------+-------------+------------------------------------------------+
|        1 |  0.02717000 | show tables                                    | 
|        2 |  0.74770100 | select count(*) from t                         | 
|        3 |  0.00004200 | show prifile for query 2                       | 
|        4 | 34.30410100 | insert into t(username) select username from t | 
+----------+-------------+------------------------------------------------+
4 rows in set (0.00 sec)

mysql> show profile cpu,block io,memory,swaps for query 4;
+------------------------------+-----------+-----------+------------+--------------+---------------+-------+
| Status                       | Duration  | CPU_user  | CPU_system | Block_ops_in | Block_ops_out | Swaps |
+------------------------------+-----------+-----------+------------+--------------+---------------+-------+
| (initialization)             | 0.000038  | 0         | 0          |            0 |             0 |     0 | 
| checking permissions         | 0.000016  | 0         | 0          |            0 |             0 |     0 | 
| Opening tables               | 0.000014  | 0         | 0          |            0 |             0 |     0 | 
| System lock                  | 0.000007  | 0         | 0          |            0 |             0 |     0 | 
| Table lock                   | 0.000013  | 0         | 0          |            0 |             0 |     0 | 
| init                         | 0.000015  | 0         | 0          |            0 |             0 |     0 | 
| optimizing                   | 0.000006  | 0         | 0          |            0 |             0 |     0 | 
| statistics                   | 0.000012  | 0         | 0          |            0 |             0 |     0 | 
| preparing                    | 0.000011  | 0         | 0          |            0 |             0 |     0 | 
| Creating tmp table           | 0.000029  | 0         | 0          |            0 |             0 |     0 | 
| executing                    | 0.000005  | 0         | 0          |            0 |             0 |     0 | 
| Copying to tmp table         | 1.262877  | 1.24981   | 0.012998   |            0 |             0 |     0 | 
| converting HEAP to MyISAM    | 0.384814  | 0.187971  | 0.19797    |            0 |             0 |     0 | 
| Copying to tmp table on disk | 1.417069  | 1.203817  | 0.191971   |            0 |             0 |     0 | 
| Sending data                 | 31.104185 | 13.965877 | 0.843872   |            0 |             0 |     0 | 
| end                          | 0.000017  | 0         | 0          |            0 |             0 |     0 | 
| removing tmp table           | 0.134872  | 0         | 0.029995   |            0 |             0 |     0 | 
| end                          | 0.000026  | 0         | 0          |            0 |             0 |     0 | 
| query end                    | 0.000006  | 0