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:
1 2 3 4 5 6 7 | mysql> SELECT @@profiling; + -------------+ | @@profiling | + -------------+ | 0 | + -------------+ 1 row in set (0.00 sec) |
Next, enable profiling for all queries:
1 2 | mysql> SET profiling = 1; Query OK, 0 rows affected (0.00 sec) |
And run the query you’d like to see a breakdown for:
1 2 3 4 5 6 7 | 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:
1 2 3 4 5 6 7 | 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:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 | 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.