information_schema.profiling可以用来分析每一条SQL在它执行的各个阶段的用时,注意这个表是session 级的,也就是说如果session1 开启了它;session2没有开启,这个情况下session2 去查询只会返回一个空表
mysql> show variables like 'version'; +---------------+--------+ | Variable_name | Value | +---------------+--------+ | version | 5.6.35 | +---------------+--------+ 1 row in set (0.00 sec) mysql> show variables like '%profil%'; +------------------------+-------+ | Variable_name | Value | +------------------------+-------+ | have_profiling | YES | | profiling | ON | | profiling_history_size | 15 | +------------------------+-------+ 3 rows in set (0.00 sec) mysql> select count(*) from i_insert_test; +----------+ | count(*) | +----------+ | 8 | +----------+ 1 row in set (0.00 sec) mysql> show profiles; +----------+------------+-------------------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+-------------------------------------------------------+ | 1 | 0.00483875 | select * from i_insert_test where id in (1,5) | | 2 | 0.00464025 | explain select * from i_insert_test where id in (3,7) | | 3 | 0.00016200 | SELECT @@profiling | | 4 | 0.00072150 | show variables like 'version' | | 5 | 0.00081350 | show variables like '%profil%' | | 6 | 0.00287725 | select count(*) from i_insert_test | +----------+------------+-------------------------------------------------------+ 6 rows in set, 1 warning (0.00 sec) mysql> show warnings; +---------+------+--------------------------------------------------------------------------------------------------------------+ | Level | Code | Message | +---------+------+--------------------------------------------------------------------------------------------------------------+ | Warning | 1287 | 'SHOW PROFILES' is deprecated and will be removed in a future release. Please use Performance Schema instead | +---------+------+--------------------------------------------------------------------------------------------------------------+ 1 row in set (0.00 sec) mysql> show profile; +----------------+----------+ | Status | Duration | +----------------+----------+ | starting | 0.000045 | | query end | 0.000005 | | closing tables | 0.000002 | | freeing items | 0.000042 | | cleaning up | 0.000012 | +----------------+----------+ 5 rows in set, 1 warning (0.00 sec) mysql> show profile for query 6; +----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 0.000061 | | checking permissions | 0.000012 | | Opening tables | 0.000023 | | init | 0.002015 | | System lock | 0.000018 | | optimizing | 0.000525 | | statistics | 0.000027 | | preparing | 0.000012 | | executing | 0.000003 | | Sending data | 0.000059 | | end | 0.000007 | | query end | 0.000007 | | closing tables | 0.000011 | | freeing items | 0.000083 | | cleaning up | 0.000015 | +----------------------+----------+ 15 rows in set, 1 warning (0.00 sec) SELECT STATE, SUM(DURATION) AS Total_R, ROUND( 100 * SUM(DURATION) / (SELECT SUM(DURATION) FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = @query_id ), 2) AS Pct_R, COUNT(*) AS Calls, SUM(DURATION) / COUNT(*) AS "R/Call" FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = @query_id GROUP BY STATE ORDER BY Total_R DESC; mysql> set @query_id=6; Query OK, 0 rows affected (0.00 sec) mysql> SELECT STATE, SUM(DURATION) AS Total_R, -> ROUND( -> 100 * SUM(DURATION) / -> (SELECT SUM(DURATION) -> FROM INFORMATION_SCHEMA.PROFILING -> WHERE QUERY_ID = @query_id -> ), 2) AS Pct_R, -> COUNT(*) AS Calls, -> SUM(DURATION) / COUNT(*) AS "R/Call" -> FROM INFORMATION_SCHEMA.PROFILING -> WHERE QUERY_ID = @query_id -> GROUP BY STATE -> ORDER BY Total_R DESC; +----------------------+----------+-------+-------+--------------+ | STATE | Total_R | Pct_R | Calls | R/Call | +----------------------+----------+-------+-------+--------------+ | init | 0.002015 | 70.01 | 1 | 0.0020150000 | | optimizing | 0.000525 | 18.24 | 1 | 0.0005250000 | | freeing items | 0.000083 | 2.88 | 1 | 0.0000830000 | | starting | 0.000061 | 2.12 | 1 | 0.0000610000 | | Sending data | 0.000059 | 2.05 | 1 | 0.0000590000 | | statistics | 0.000027 | 0.94 | 1 | 0.0000270000 | | Opening tables | 0.000023 | 0.80 | 1 | 0.0000230000 | | System lock | 0.000018 | 0.63 | 1 | 0.0000180000 | | cleaning up | 0.000015 | 0.52 | 1 | 0.0000150000 | | preparing | 0.000012 | 0.42 | 1 | 0.0000120000 | | checking permissions | 0.000012 | 0.42 | 1 | 0.0000120000 | | closing tables | 0.000011 | 0.38 | 1 | 0.0000110000 | | end | 0.000007 | 0.24 | 1 | 0.0000070000 | | query end | 0.000007 | 0.24 | 1 | 0.0000070000 | | executing | 0.000003 | 0.10 | 1 | 0.0000030000 | +----------------------+----------+-------+-------+--------------+ 15 rows in set (0.00 sec) mysql> set profiling=off; Query OK, 0 rows affected, 1 warning (0.00 sec)