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.