You are here

How the MySQL Optimizer with MySQL Cluster is cheating you...

At a customer we had a nice example of how the MySQL Optimizer is cheating when used in combination with the MySQL Cluster. The customer had queries running not too slow in the development environment but when he tried them on the acceptance test environment (with more data) the query was running much too long which was unacceptable because this query can occur many times per second.

What has happened?

First of all we had a look at the execution plan of the query generated by the MySQL Optimizer:

EXPLAIN
SELECT t0.*, t1.*
  FROM t2
  JOIN t0 ON t2.t0_id = t0.id
  JOIN t1 ON t1.t0_id = t0.id
 WHERE t2.productnumber LIKE '%3301'
   AND t0.organization_id = 157
   AND t0.type = 'User';

1 row in set (8.78 sec)

+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+
| table | type   | possible_keys       | key           | key_len | ref      | rows | Extra                             |
+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+
| t0    | ref    | PRIMARY,ORG_ID,TYPE | ORG_ID        | 5       | const    |   10 | Using where with pushed condition |
| t1    | eq_ref | PRIMARY             | PRIMARY       | 4       | t0.id    |    1 |                                   |
| t2    | ref    | PRODUCTNUMBER       | PRODUCTNUMBER | 5       | t1.t0_id |    1 | Using where with pushed condition |
+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+

The execution plan looks close to perfect. 10 rows for the first table (t0) and then a Nested Loop Join through t1 and t2. But the slow query log shows a bit a different picture:

# Query_time: 8.784943  Lock_time: 0.000367 Rows_sent: 1  Rows_examined: 40052

40052 rows are touched (Rows_examined) for a result set of just ONE single row (Rows_sent). According to the execution plan we should touch between 10 and 30 rows (depending on how you are counting rows).

The SHOW SESSION STATUS command before and after the query gives us some more information:

Before:

SHOW SESSION STATUS LIKE 'ndb%count';
+--------------------------------+-----------+
| Variable_name                  | Value     |
+--------------------------------+-----------+
| Ndb_execute_count              | 0         |
| Ndb_scan_count                 | 0         |
+--------------------------------+-----------+

After:

SHOW SESSION STATUS LIKE 'ndb%count';
+--------------------------------+-----------+
| Variable_name                  | Value     |
+--------------------------------+-----------+
| Ndb_execute_count              | 40052     |
| Ndb_scan_count                 | 8         |
+--------------------------------+-----------+

Ndb_execute_count: Provides the number of round trips to the NDB kernel made by operations. [ 1 ]
Ndb_scan_count: This variable holds a count of the total number of scans executed. [ 2 ]

According to the GLOBAL STATUS VARIABLES we do 40052 round trips to the cluster and 8 scans. From the execution plan I expect less or equal 21 round trips and 2 to 3 scans.

With this information we found at least a trace why it could take so long. A short calculation proves, that we are on the right track:

60 µs (ping) per round-trip x 40052 round trips = 2.4 seconds.

With 2.4 seconds we are at least in the right scale for looking for the problem.

But why the hell is he doing 40k round-trips when we expect just about 20? So let us do by hand what the optimizer should do:
SELECT COUNT(*)
  FROM t0
 WHERE t0.organization_id = 157
   AND t0.type = 'User';

40044 rows in set (0.78 sec)

+-------+------+---------------+--------+---------+-------+------+-----------------------------------+
| table | type | possible_keys | key    | key_len | ref   | rows | Extra                             |
+-------+------+---------------+--------+---------+-------+------+-----------------------------------+
| t0    | ref  | ORG_ID,TYPE   | ORG_ID | 5       | const |   10 | Using where with pushed condition |
+-------+------+---------------+--------+---------+-------+------+-----------------------------------+

Aha! The execution plan looks the same. And the query returns 40044 rows (in 0.78 s) instead of just 10!!! So the optimizer was completely fooling us!

SHOW SESSION STATUS shows us:

Ndb_execute_count = 1
Ndb_scan_count    = 1

The second step then causes the massive amount of round trips (and consumes the most time):

SELECT COUNT(*)
  FROM t0
  JOIN t1 ON t1.t0_id = t0.id
 WHERE t0.organization_id = 157
   AND t0.type = 'User';

7 rows in set (8.73 sec)

Ndb_execute_count = 40044
Ndb_scan_count    = 1

And the last step causes another 7 round trips (7 rows out of step 2) and 6 scans:

SELECT COUNT(*)
  FROM t2
  JOIN t0 ON t2.t0_id = t0.id
  JOIN t1 ON t1.t0_id = t0.id
 WHERE t2.productnumber LIKE '%3301'
   AND t0.organization_id = 157
   AND t0.type = 'User';

1 row in set (8.78 sec)

Ndb_execute_count = 7
Ndb_scan_count    = 6

Conclusion: The MySQL Optimizer did the wrong choice by starting with table t0.

Being an Optimizer ourself

Now we have to do it better... What possibilities do we have (now we are playing a bit optimizer)?

query_diagram.png

We can start with:

  • Table t2 doing a full table scan with filtering or doing an index scan with filtering on criteria t2.productnumber LIKE '%3301' which is a "bad" filter.
  • Table t0 doing a full table scan with filtering or doing an index scan with filtering on organization_id = 157 OR type = 'User' (there is currently NO combined index on both attributes).
  • Table t1 doing a full table scan (what we do anyway in the cluster it looks like).

Let us find the best starting point with the smallest result set first, because round trips in MySQL Cluster joins matter:

SELECT COUNT(*)
  FROM t2
 WHERE t2.productnumber LIKE '%3301';

--> 1 row

SELECT COUNT(*)
  FROM t0
 WHERE t0.organization_id = 157
   AND t0.type = 'User';

--> 40044 rows (that is what we already have and know is bad.

SELECT COUNT(*)
  FROM t1;

--> 325 rows

Query Possibilities

Starting with t2 in this specific query and take the risk of a full table scan should give us much better results. More information about this technique you can find in [3].

To see if our idea gives us a better result we force the MySQL Optimizer to use the STRAIGHT_JOIN [4] hint:

SELECT STRAIGHT_JOIN COUNT(*)
  FROM t2
  JOIN t0 ON t2.t0_id = t0.id
  JOIN t1 ON t1.t0_id = t0.id
 WHERE t2.productnumber LIKE '%3301'
   AND t0.organization_id = 157
   AND t0.type = 'User';

1 row in set (0.02 sec)

+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+
| id | select_type | table | type   | possible_keys       | key     | key_len | ref      | rows | Extra                             |
+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+
|  1 | SIMPLE      | t2    | ALL    | PRODUCTNUMBER       | NULL    | NULL    | NULL     | 1099 | Using where with pushed condition |
|  1 | SIMPLE      | t0    | eq_ref | PRIMARY,ORG_ID,TYPE | PRIMARY | 4       | t2.t0_id |    1 | Using where with pushed condition |
|  1 | SIMPLE      | t1    | eq_ref | PRIMARY             | PRIMARY | 4       | t0.id    |    1 | Using where                       |
+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+

Ndb_execute_count = 3
Ndb_scan_count    = 1

SELECT STRAIGHT_JOIN COUNT(*)
  FROM t2
  JOIN t1 ON t1.t0_id = t2.t0_id
  JOIN t0 ON t1.t0_id = t0.id
 WHERE t2.productnumber LIKE '%3301'
   AND t0.organization_id = 157
   AND t0.type = 'User';

1 row in set (0.02 sec)

+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+
| id | select_type | table | type   | possible_keys       | key     | key_len | ref      | rows | Extra                             |
+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+
|  1 | SIMPLE      | t2    | ALL    | PRODUCTNUMBER       | NULL    | NULL    | NULL     | 1099 | Using where with pushed condition |
|  1 | SIMPLE      | t1    | eq_ref | PRIMARY             | PRIMARY | 4       | t2.t0_id |    1 |                                   |
|  1 | SIMPLE      | t0    | eq_ref | PRIMARY,ORG_ID,TYPE | PRIMARY | 4       | t1.t0_id |    1 | Using where with pushed condition |
+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+

Ndb_execute_count 3
Ndb_scan_count    1

So it seems that variant 2 and 3 are more or less equal. And we have improved the query from about 9 seconds to about 20 ms (f=450!)

Unfortunately the customer could not accept this solution because his generic framework does not allow query hinting and the application should be generic for other database back-ends.

What further came into my mind as alternative solution is to create a VIEW to hide the Hint:

CREATE VIEW t2_t1_t0_v AS
SELECT STRAIGHT_JOIN t0.*, t1.*, t2.productnumber
  FROM t2
  JOIN t1 ON t1.t0_id = t2.t0_id
  JOIN t0 ON t1.t0_id = t0.id;

But it looks like the query is rewritten in a way that the hint was ignored:

EXPLAIN
SELECT COUNT(*)
  FROM t2_t1_t0_v
 WHERE productnumber LIKE '%3301'
   AND organization_id = 157
   AND type = 'User';

+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+
| id | select_type | table | type   | possible_keys       | key           | key_len | ref      | rows | Extra                             |
+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+
|  1 | SIMPLE      | t0    | ref    | PRIMARY,ORG_ID,TYPE | ORG_ID        | 5       | const    |   10 | Using where with pushed condition |
|  1 | SIMPLE      | t1    | eq_ref | PRIMARY             | PRIMARY       | 4       | t0.id    |    1 |                                   |
|  1 | SIMPLE      | t2    | ref    | PRODUCTNUMBER       | PRODUCTNUMBER | 5       | t1.t0_id |    1 | Using where                       |
+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+

If the query is executed as follows (with a Hint) it will be executed again in the right order, but this is something we wanted to avoid because of the customer...

SELECT STRAIGHT_JOIN COUNT(*)
  FROM t2_t1_t0_v
 WHERE productnumber LIKE '%3301'
   AND organization_id = 157
   AND type = 'User';

According to MySQL this is NOT a bug but a "feature request"... :-( More details you can find under MySQL Bug #28700.

Risks

  • One problem with the hints is that they prevent future MySQL releases/features to show their full power when they will be implemented once. For example if the BKA (batched key access) [9] or the Push-Down-Join feature [5] becomes true or if the optimizer becomes more clever about the MySQL Cluster data distribution and does better estimates. We possibly can obstruct even better execution plans in the future.
  • A second problem is, that starting with a full table scan on t2 does not scale if the amount of data becomes bigger in the future. So at a certain point a full table scan will be worse than 40k round trips.
  • What we have not discussed at all in this article is that there is a big potential by changing the data/table structure for the filter criteria on t2. A search for "%xyz" is bad and results in a scan. If the content of the field is reverted a search like 'zyx%' could make use of an index and avoid the full table scan.
  • If the trick with the VIEW would have worked, there is an other problem: Because the VIEW is stored in the SQL nodes and not in the MySQL Cluster, you have to make sure, that ALL SQL nodes are kept in sync and you have to take care about the backup of the VIEW which is not so simple with MySQL Cluster in combination with objects located in the SQL nodes.
  • If the filter criteria on t2 would not be that selective the trick would not work out.

What we have learned

  • Size of your test data matters. If you have much more data in production than on your test system you will not find the performance problems unless you go life. So fill your testing system with the same amount of data like your production system or at least your acceptance testing system.
  • The MySQL Optimizer is cheating because he is not aware of the real data distribution. The MySQL Optimizer works currently best with MyISAM/Maria. Testing a query and getting a "good" execution plan with MySQL will show us the following:
    +----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-------------+
    | id | select_type | table | type   | possible_keys       | key           | key_len | ref      | rows | Extra       |
    +----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-------------+
    |  1 | SIMPLE      | t1    | ALL    | PRIMARY             | NULL          | NULL    | NULL     |  325 |             |
    |  1 | SIMPLE      | t2    | ref    | PRODUCTNUMBER       | PRODUCTNUMBER | 5       | t1.t0_id |    3 | Using where |
    |  1 | SIMPLE      | t0    | eq_ref | PRIMARY,ORG_ID,TYPE | PRIMARY       | 4       | t1.t0_id |    1 | Using where |
    +----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-------------+

    We could also try this variant...

  • The MySQL bug #52940.
  • Hints and views do somehow not cooperate in the way as I would expect it.
  • MySQL Cluster does more scans than I would expect it. But we can prove this with the ndb_%count status variables.

Further research

I found some parameters (ndb_index_stat_cache_entries, ndb_index_stat_enable and ndb_index_stat_update_freq [7]) which smell very much as they could help here. But I have not found anything how I could influence the MySQL Optimizer to do what I want him to do. If anybody has a hint or an example I would greatly appreciate it when he/she could let me know more about those parameters.

MySQL Cluster consulting from FromDual

If you want to know more about MySQL Cluster and query optimization we will be happy to see you as one of our customers.

Literature

[1] Ndb_execute_count
[2] Ndb_scan_count
[3] Dan Tow: SQL Tuning
[4] STRAIGHT_JOIN
[5] Trying out MySQL Push-Down-Join (SPJ) preview
[6] Bug #52940: ndb_*_count status variables ARE session related in contrary what docu says.
[7] ndb_index_stat%
[8] See also the very good article of Johan Andersson about the same mater: Optimizing Queries on Cluster
[9] Batched Key Access (BKA) [10] How does the MySQL Optimizer work [11] Bug #28700: VIEWs using the MERGE algorithm ignore STRAIGHT_JOIN
Taxonomy upgrade extras: 

Comments

To find out more about the VIEW's behaviour I was playing around with the ALGORITHM = TEMPTABLE feature [1]. It was also related to a customers question of how VIEW's effect performance of queries. The results are ambivalent:
EXPLAIN
SELECT * FROM v LIMIT 10;
CREATE ALGORITHM = MERGE VIEW v
+----+-------------+-------+--------+---------------+---------+---------+-------------+--------+-------------+
| id | select_type | table | type   | possible_keys | key     | key_len | ref         | rows   | Extra       |
+----+-------------+-------+--------+---------------+---------+---------+-------------+--------+-------------+
|  1 | SIMPLE      | b     | ALL    | NULL          | NULL    | NULL    | NULL        | 131073 |             |
|  1 | SIMPLE      | a     | eq_ref | PRIMARY       | PRIMARY | 4       | test.b.a_id |      1 | Using where |
+----+-------------+-------+--------+---------------+---------+---------+-------------+--------+-------------+
2 rows in set (0.00 sec)
-> = default behaviour. STRAIGHT_JOIN hint is NOT taken.
CREATE ALGORITHM = TEMPTABLE VIEW v
+----+-------------+------------+------+---------------+------+---------+------+--------+--------------------------------+
| id | select_type | table      | type | possible_keys | key  | key_len | ref  | rows   | Extra                          |
+----+-------------+------------+------+---------------+------+---------+------+--------+--------------------------------+
|  1 | PRIMARY     | <derived2> | ALL  | NULL          | NULL | NULL    | NULL | 131073 |                                |
|  2 | DERIVED     | a          | ALL  | PRIMARY       | NULL | NULL    | NULL |   1024 |                                |
|  2 | DERIVED     | b          | ALL  | NULL          | NULL | NULL    | NULL | 131073 | Using where; Using join buffer |
+----+-------------+------------+------+---------------+------+---------+------+--------+--------------------------------+
3 rows in set (21.76 sec)
-> Hint seems to be taken BUT a Cartesian product is done. The EXPLAIN itself was not instantaneous (like it happens in some other situations with MySQL) but generated some traffic on the database. Running the query is about 2000 times slower than with MERGE. Maybe this needs a bit more sophisticated work by MySQL/Oracle?
olicomment

Excellent help with EXPLAIN command.. but.. I'm having issues.. why reason there's no results after execute this: SHOW SESSION STATUS LIKE 'ndb%count'; ??
amatuscomment

Hello amatus, Not sure if I understood you correctly. But the output is in the following Before and After code boxes... I have changed this now a bit for beeing more clear. Please elaborate a bit more if I missed you. Regards, Oli
olicomment