Bug #44802 Very slow EXPLAIN when subqueries are used
Submitted: 11 May 2009 20:35 Modified: 24 Sep 2011 17:15
Reporter: norbert van Nobelen Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S3 (Non-critical)
Version:4.1, 5.0, 5.1, 6.0.10-apha OS:Linux
Assigned to: CPU Architecture:Any
Tags: explain, query, slow
Triage: Triaged: D3 (Medium)

[11 May 2009 20:35] norbert van Nobelen
Description:
The explain query is way too slow to be workable. Explain should use statistics to return result. It looks like it is executing the query.

Output of the explain:

+----+-------------+------------+------+---------------------------+---------------+---------+------+--------+-----------------+
| id | select_type | table      | type | possible_keys             | key           | key_len | ref  | rows   | Extra           |
+----+-------------+------------+------+---------------------------+---------------+---------+------+--------+-----------------+
|  1 | PRIMARY     | <derived2> | ALL  | NULL                      | NULL          | NULL    | NULL | 210391 | Using where     |
|  2 | DERIVED     | <derived3> | ALL  | NULL                      | NULL          | NULL    | NULL | 210391 |                 |
|  2 | DERIVED     | <derived4> | ALL  | NULL                      | NULL          | NULL    | NULL |   2000 | Using where     |
|  4 | DERIVED     | <derived5> | ALL  | NULL                      | NULL          | NULL    | NULL |   2000 |                 |
|  5 | DERIVED     | extraval   | ref  | extraval_sk,extraval_sttp | extraval_sttp | 10      |      |  10560 | Using temporary |
|  3 | DERIVED     | extraval   | ref  | extraval_sk,extraval_sttp | extraval_sttp | 10      |      | 274476 | Using index     |
+----+-------------+------------+------+---------------------------+---------------+---------+------+--------+-----------------+
6 rows in set (3 min 44.22 sec)

Versions used:
5.1.31 (was 4min40s)
6.0.10-alpha: 3min44s

How to repeat:
Create an innodb table with ~800mln records and try this:
mysql> explain select uuid FROM (select a.uuid,a,b
    -> FROM (select UUID() as uuid,1 as A FROM extraval where stockkey=475 and testperiod=30 ) a
    -> LEFT OUTER JOIN (
    -> select UUID() as uuid,0 as b FROM (select DISTINCT stockkey, walletvalue, power,numberofdays,historykey,testperiod from extraval where testperiod=200 and stockkey=30 limit
    -> 2000) a
    -> ) b ON a.uuid=b.uuid ) c
    -> WHERE b IS NULL
    -> ;

Suggested fix:
Use statistics on tables only to create plan.
[11 May 2009 20:37] norbert van Nobelen
P.S. The limit of 2000 in the query is used because of slow join performance. Bug report for this will follow soon.
[14 May 2009 17:49] Sveta Smirnova
Thank you for the reasonable feature request.

But, please, note, only subqueries are affected. If rewrite statement what subquery is not used, only statistic would be used for EXPLAIN.

Easier way to repeat:

mysql> explain select * from (select sleep(10) as foo) bar;
+----+-------------+------------+--------+---------------+------+---------+------+------+----------------+
| id | select_type | table      | type   | possible_keys | key  | key_len | ref  | rows | Extra          |
+----+-------------+------------+--------+---------------+------+---------+------+------+----------------+
|  1 | PRIMARY     | <derived2> | system | NULL          | NULL | NULL    | NULL |    1 |                | 
|  2 | DERIVED     | NULL       | NULL   | NULL          | NULL | NULL    | NULL | NULL | No tables used | 
+----+-------------+------------+--------+---------------+------+---------+------+------+----------------+
2 rows in set (10.02 sec)
[14 May 2009 19:52] norbert van Nobelen
Ok, feature request it is (-:

Anyway: The reason to use an explain of the full query is to see if for example where conditions applied to the outer query are substituted by the optimizer in the inner queries.
[7 Sep 2009 19:08] Timour Katchaounov
This is a very old and well known problem. It is currently work in progress WL#3485. The source tree for this task is here:
https://code.launchpad.net/~mysql/mysql-server/mysql-wl3485

To the best of my knowledge the main part of the implementation is finished,
but there are a number of failing test cases that need to be addressed. I have
no ETA when this task will be complete.
[6 Oct 2010 10:07] Roel Van de Paar
From customer (see issue above for logs):

o EXPLAIN was seen in processlist as "sending data" state (output changed to make public posting possible):

| Id   | User | Host      | db  | Command | Time | State        | Info                                    |
-----------------------------------------------------------------------------------------------------------
| 5400 | root | localhost | db1 | Query   | 61   | Sending data | EXPLAIN EXTENDED <subquery_listed_here> | 

o Delay is not consistent. Customer restarted mysqld and there was no delay! Possibly this could be OS level caching though.
[6 Oct 2010 10:37] Simon Mudd
Note: if 

| 5400 | root | localhost | db1 | Query   | 61   | Sending data | EXPLAIN EXTENDED
<subquery_listed_here> | 

is true and the client waited a long time to get 3 lines of output I would say that this is not a feature request but a BUG.

That is if the EXPLAIN is "running" it should not set the state to "Sending data". It seemed to be in this state "Sending data" for a good long time (several seconds). The mysql command line from where I was making this request was idle and doing nothing.

By all means make EXPLAIN faster (feature request), but at least get it to state what it's doing properly first (bug).
[6 Oct 2010 10:46] Roel Van de Paar
See bug #31468
[18 Oct 2010 8:28] Roel Van de Paar
Please re-triage. This is not a F/R but a bug. Subqueries are executed at times when an EXPLAIN is run.
[29 Dec 2010 10:37] Roel Van de Paar
Another example in bug #59203
[24 Sep 2011 17:15] Paul Dubois
Fixed by recent optimizer work:

http://dev.mysql.com/doc/refman/5.6/en/from-clause-subquery-optimization.html