mysql语句详细查询时间

I recently worked on an uncommon slow query: less than 100 rows were read and returned, the whole dataset was fitting in memory but the query took several seconds to run. Long story short: the query was a join involving 21 tables, running on MySQL 5.1. But by default MySQL 5.1 is not good at handling joins with such a large number of tables. The good news is that MySQL 5.6 brings welcome improvements.

Isolating the problem

As always with a slow query, finding the execution plan with EXPLAIN is the 1st step to understand where time is spent. Here the plan was very good with almost all joins using the primary key or a unique key, but perhaps the most interesting part was thatEXPLAIN was very slow as well. This indicates that the optimizer takes a lot of time finding the optimal execution plan. To double check, we can run SHOW PROFILE:

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22

mysql> set @@profiling = 1; mysql> SELECT ….; mysql> SHOW PROFILE; +——————–+———-+ | Status             | Duration | +——————–+———-+ | starting           | 0.000783 | | Opening tables     | 0.000192 | | System lock        | 0.000005 | | Table lock         | 0.000010 | | init               | 0.000369 | | optimizing         | 0.000091 | | statistics         | 3.459529 | | preparing          | 0.000213 | | executing          | 0.000005 | | Sending data       | 0.004597 | | end                | 0.000008 | | query end          | 0.000005 | | freeing items      | 0.000066 | | logging slow query | 0.000004 | | cleaning up        | 0.000006 | +——————–+———-+

‘Statistics’ means ‘finding a good execution plan’. Okay, we have found why the query is slow.

If you have read this post, you already know how to fix the problem: set optimizer_search_depth = 0 and response time instantly drops to 0.02s. Also mentioned in this post, we should expect MySQL 5.6 to be much better at handling such queries. Well, let’s give it a try!

MySQL 5.6

With the default value of optimizer_search_depth, response time is 0.02s in 5.6 and we can see in SHOW PROFILE that the time spent finding a good execution plan is very small:

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21

+———————-+———-+ | Status               | Duration | +———————-+———-+ | starting             | 0.002022 | | checking permissions | 0.000018 | [...] | checking permissions | 0.000015 | | Opening tables       | 0.000130 | | init                 | 0.001093 | | System lock          | 0.000048 | | optimizing           | 0.000200 | | statistics           | 0.009404 | | preparing            | 0.000432 | | executing            | 0.000029 | | Sending data         | 0.005409 | | end                  | 0.000027 | | query end            | 0.000009 | | closing tables       | 0.000034 | | freeing items        | 0.000082 | | cleaning up          | 0.000030 | +———————-+———-+

However ‘Statistics’ is still the most expensive step. What if we set optimizer_search_depth = 0? It is even better:

1 2 3

[...] | statistics           | 0.001896 | [...]

And the response time drops to 0.01s.

Conclusions

• EXPLAIN is a great tool to understand how the server will run a query, but it does not tell you everything. Additional tools (here, SHOW PROFILES) are often useful as well.
• By default MySQL 5.6 is much better than the previous versions at handling joins with many tables: great job optimizer team at Oracle!
• However even with 5.6, you may get better response time with optimizer_search_depth = 0