# show profile分析SQL Mysql从5.0.37版本开始增加了对 show profiles 和 show profile 语句的支持。show profiles 能够在做SQL优化时帮助我们了解时间都耗费到哪里去了。 ## 开启show profile ```sql 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) ~~~ | 字段 | 含义 | | ---------- | ------------------------------ | | Status | sql 语句执行的状态 | | Duration | sql 执行过程中每一个步骤的耗时 | | CPU_user | 当前用户占有的cpu | | CPU_system | 系统占有的cpu |