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)