The Query Profiler in MySQL isn’t something I’ve spent much time in recently – with more sites making use of popular CMSes like WordPress, query performance isn’t something that’s top of mind anymore (Automatic seems to do a good job in this area). But it’s still a useful tool when you’ve already picked the low hanging fruit off of the optimization tree.
Profiling is enabled on an individual basis for each MySQL session; when the session ends, all profiling information is lost.
To check to see if profiling is currently enabled for your session, do:
mysql> SELECT @@profiling;
+-------------+
| @@profiling |
+-------------+
| 0 |
+-------------+
1 row in set (0.00 sec)
Next, enable profiling for all queries:
mysql> SET profiling = 1;
Query OK, 0 rows affected (0.00 sec)
And run the query you’d like to see a breakdown for:
mysql> SELECT COUNT(*) FROM wp_posts;
+----------+
| count(*) |
+----------+
| 238121 |
+----------+
1 row in set (18.80 sec)
Get the numeric ID of the profile we want to see:
mysql> SHOW PROFILES;
+----------+----------+---------------------------------------+
| Query_ID | Duration | Query |
+----------+----------+---------------------------------------+
| 1 | 18.80000 | SELECT COUNT(*) FROM wp_posts; |
+----------+----------+---------------------------------------+
1 row in set (0.00 sec)
Finally, actually see the query profiled:
mysql> SHOW PROFILE FOR QUERY 1;
+--------------------------------+-----------+
| Status | Duration |
+--------------------------------+-----------+
| starting | 0.000027 |
| checking query cache for query | 0.000041 |
| checking permissions | 0.000017 |
| Opening tables | 0.000018 |
| System lock | 0.000008 |
| Table lock | 0.000037 |
| init | 0.000014 |
| optimizing | 0.000008 |
| statistics | 0.000016 |
| preparing | 0.000013 |
| executing | 0.000008 |
| Sending data | 18.802902 |
| end | 0.000015 |
| end | 0.000008 |
| query end | 0.000006 |
| storing result in query cache | 0.000453 |
| freeing items | 0.000009 |
| closing tables | 0.000007 |
| logging slow query | 0.000007 |
| logging slow query | 0.000031 |
| cleaning up | 0.000005 |
+--------------------------------+-----------+
21 rows in set (0.00 sec)
To get even more in depth, check out the optional type values for the SHOW PROFILE command, or use SHOW PROFILE ALL FOR QUERY 1; and view everything MySQL’s got at once.