Mysql从5.0.37版本开始增加了对 show profiles 和 show profile 语句的支持。show profiles 能够在做SQL优化时帮助我们了解时间都耗费到哪里去了。

开启show profile

set profiling=1; //开启profiling 开关；

通过profile，我们能够更清楚地了解SQL执行的过程。

示例1：

mysql> select * from t_user;
+----+----------+--------------------------------------------------------------+--------+
| id | username | password                                                     | name   |
+----+----------+--------------------------------------------------------------+--------+
| 1  | super    | $2a$10$TJ4TmCdK.X4wv/tCqHW14.w70U3CC33CeVncD3SLmyMXMknstqKRe | ?????  |
| 2  | admin    | $2a$10$TJ4TmCdK.X4wv/tCqHW14.w70U3CC33CeVncD3SLmyMXMknstqKRe | ?????  |
| 3  | itcast   | $2a$10$8qmaHgUFUAmPR5pOuWhYWOr291WJYjHelUlYn07k5ELF8ZCrW0Cui | test02 |
| 4  | stu1     | $2a$10$pLtt2KDAFpwTWLjNsmTEi.oU1yOZyIn9XkziK/y/spH5rftCpUMZa | ??1    |
| 5  | stu2     | $2a$10$nxPKkYSez7uz2YQYUnwhR.z57km3yqKn3Hr/p1FR6ZKgc18u.Tvqm | ??2    |
| 6  | t1       | $2a$10$TJ4TmCdK.X4wv/tCqHW14.w70U3CC33CeVncD3SLmyMXMknstqKRe | ??1    |
+----+----------+--------------------------------------------------------------+--------+
6 rows in set (0.00 sec)

mysql> show profiles;
+----------+------------+------------------------------------+
| Query_ID | Duration   | Query                              |
+----------+------------+------------------------------------+
|        1 | 0.00422300 | select * from tb_item where id < 5 |
|        2 | 0.00370000 | show tables                        |
|        3 | 0.00065000 | select * from t_user               |
+----------+------------+------------------------------------+
3 rows in set, 1 warning (0.00 sec)

示例2：

通过show profile for query query_id 语句可以查看到该SQL执行过程中每个线程的状态和消耗的时间：

mysql> show profile for query 3;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.000103 |
| Executing hook on transaction  | 0.000014 |
| starting                       | 0.000007 |
| checking permissions           | 0.000017 |
| Opening tables                 | 0.000106 |
| init                           | 0.000021 |
| System lock                    | 0.000027 |
| optimizing                     | 0.000023 |
| statistics                     | 0.000092 |
| preparing                      | 0.000028 |
| executing                      | 0.000003 |
| Sending data                   | 0.000073 |
| end                            | 0.000004 |
| query end                      | 0.000003 |
| waiting for handler commit     | 0.000007 |
| closing tables                 | 0.000007 |
| freeing items                  | 0.000012 |
| cleaning up                    | 0.000103 |
+--------------------------------+----------+
18 rows in set, 1 warning (0.00 sec)

TIP ：
	Sending data 状态表示MySQL线程开始访问数据行并把结果返回给客户端，而不仅仅是返回个客户端。由于在Sending data状态下，MySQL线程往往需要做大量的磁盘读取操作，所以经常是整各查询中耗时最长的状态。

在获取到最消耗时间的线程状态后，MySQL支持进一步选择all、cpu、block io 、context switch、page faults等明细类型类查看MySQL在使用什么资源上耗费了过高的时间。例如，选择查看CPU的耗费时间 ：

mysql> show profile cpu for query 3;
+--------------------------------+----------+----------+------------+
| Status                         | Duration | CPU_user | CPU_system |
+--------------------------------+----------+----------+------------+
| starting                       | 0.000103 | 0.000052 |   0.000051 |
| Executing hook on transaction  | 0.000014 | 0.000003 |   0.000010 |
| starting                       | 0.000007 | 0.000006 |   0.000002 |
| checking permissions           | 0.000017 | 0.000005 |   0.000012 |
| Opening tables                 | 0.000106 | 0.000037 |   0.000069 |
| init                           | 0.000021 | 0.000007 |   0.000014 |
| System lock                    | 0.000027 | 0.000009 |   0.000017 |
| optimizing                     | 0.000023 | 0.000005 |   0.000018 |
| statistics                     | 0.000092 | 0.000021 |   0.000071 |
| preparing                      | 0.000028 | 0.000012 |   0.000016 |
| executing                      | 0.000003 | 0.000002 |   0.000002 |
| Sending data                   | 0.000073 | 0.000043 |   0.000030 |
| end                            | 0.000004 | 0.000003 |   0.000001 |
| query end                      | 0.000003 | 0.000002 |   0.000001 |
| waiting for handler commit     | 0.000007 | 0.000005 |   0.000001 |
| closing tables                 | 0.000007 | 0.000006 |   0.000001 |
| freeing items                  | 0.000012 | 0.000006 |   0.000007 |
| cleaning up                    | 0.000103 | 0.000021 |   0.000082 |
+--------------------------------+----------+----------+------------+
18 rows in set, 1 warning (0.00 sec)