| Bug #78997 | optimizer prefers using index `a` to ORDER instead of `b,a` to EQ and ORDER | ||
|---|---|---|---|
| Submitted: | 28 Oct 2015 9:53 | Modified: | 5 Dec 2015 7:31 |
| Reporter: | Kenny Gryp | Email Updates: | |
| Status: | No Feedback | Impact on me: | |
| Category: | MySQL Server: Optimizer | Severity: | S3 (Non-critical) |
| Version: | 5.6.27, 5.7.9 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | Optimizer | ||
[28 Oct 2015 9:53]
Kenny Gryp
optimizer_trace.forced.txt
Attachment: optimizer_trace.forced.txt (text/plain), 12.43 KiB.
[28 Oct 2015 9:54]
Kenny Gryp
optimizer_trace.orig.txt
Attachment: optimizer_trace.orig.txt (text/plain), 19.80 KiB.
[28 Oct 2015 10:11]
Kenny Gryp
change synopsis
[29 Oct 2015 15:51]
MySQL Verification Team
Hi, First of all, this is about the balance between the EQ and ORDER. Sometimes it is faster to go for EQ and sometimes for ORDER. Just for your info, second query changes how ORDER is resolved. The chosen index (actually forced one) is used mostly for EQ. Our current GA version & release is 5.7.9. It has so many optimizer improvements, so may be this is one of those that were fixed already. Can you please try the same table and same query on 5.7.9 and report to us if you still see the same problem. If 5.7.9 has the same behavior, can you please upload the optimizer trace for the query. Also, in that case, please upload data for the table in question. You can zip them or compress them in any other way. Do data upload in a private comment.
[30 Oct 2015 9:31]
Kenny Gryp
Hello Sinisa, Yes the forced query does EQ mostly on the `installation_id`, but it also does not need to do any filesorts. and with having ORDER BY ... LIMIT 1 this is perfect. Thousands of times better than not doing any EQ at all.
[30 Oct 2015 16:48]
MySQL Verification Team
Hi Kenny, Please, follow all of our other advices and requests that we have provided. I am repeating those. Our current GA version & release is 5.7.9. It has so many optimizer improvements, so may be this is one of those that were fixed already. Can you please try the same table and same query on 5.7.9 and report to us if you still see the same problem. If 5.7.9 has the same behavior, can you please upload the optimizer trace for the query. Also, in that case, please upload data for the table in question. You can zip them or compress them in any other way. Do data upload in a private comment.
[30 Oct 2015 17:27]
Kenny Gryp
In MySQL 5.7.9 the ``IDontKnoo_insid_zone_time_ix`` index is used and manual filesorting is prefered.
This is not good as well.
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: IDontKnoo_1203
partitions: p201405,p201412,p201501,p201502,p201503,p201504,p201505,p201506,p201507,p201508,p201509,p201510,p201511,p201512,pmax
type: range
possible_keys: IDontKnoo_time_ix,IDontKnoo_insid_time_ix,IDontKnoo_insid_sid_time_ix,IDontKnoo_insid_sid_zone_time_ix,IDontKnoo_insid_zone_time_ix
key: IDontKnoo_time_ix
key_len: 5
ref: NULL
rows: 67900674
filtered: 0.00
Extra: Using index condition; Using where
1 row in set, 1 warning (5.62 sec)
mysql> select version(); +-----------+
| version() |
+-----------+
| 5.7.9-log |
+-----------+
1 row in set (0.00 sec)
[30 Oct 2015 17:28]
Kenny Gryp
Please remove my previous post on 30 Oct 17:27 CET (wrong information)
Same problem in MySQL 5.7.9:
*************************** 1. row ***************************
id: 1
select_type: SIMPLE
table: IDontKnoo_1203
partitions: p201405,p201412,p201501,p201502,p201503,p201504,p201505,p201506,p201507,p201508,p201509,p201510,p201511,p201512,pmax
type: range
possible_keys: IDontKnoo_time_ix,IDontKnoo_insid_time_ix,IDontKnoo_insid_sid_time_ix,IDontKnoo_insid_sid_zone_time_ix,IDontKnoo_insid_zone_time_ix
key: IDontKnoo_time_ix
key_len: 5
ref: NULL
rows: 67900674
filtered: 0.00
Extra: Using index condition; Using where
1 row in set, 1 warning (5.62 sec)
mysql> select version(); +-----------+
| version() |
+-----------+
| 5.7.9-log |
+-----------+
1 row in set (0.00 sec)
[30 Oct 2015 17:29]
Kenny Gryp
optimizer_trace.orig.579.txt
Attachment: optimizer_trace.orig.579.txt (text/plain), 18.26 KiB.
[30 Oct 2015 17:44]
MySQL Verification Team
Please, follow all the instructions from my last comment.
[30 Oct 2015 17:48]
MySQL Verification Team
Sorry for the last comment. Can you upload the data so that we can test this ourselves ??? Thanks in advance.
[2 Nov 2015 8:33]
Kenny Gryp
Hello Sinisa, Thank you for taking the time to look into this. Unfortunately, I cannot share this confidential data, not even in private. The table is also +100GB in size. I expected the optimizer trace feature in MySQL to be there to be able to give a lot of detailed information on how the optimizer made it's decision, including the costs of different execution plans, and the reasoning on the decision the optimizer made, which in turn helps the developers to identify the problem more easily. When I look at it, I can clearly see the optimizer choosing an index with a very very high cost which it does not need to do. Kenny
[2 Nov 2015 15:15]
MySQL Verification Team
Hi Kenny, I have studied this case carefully again. I made my diagnosis and shared it with our Developers from the Optimizer team. They agreed 100 % with me. The explanation is quite simple. With UPDATE, when the optimizer has to choose between the index with columns that could be possibly changed with the UPDATE and the second best index that is created over columns that will not be updated, then this second best index will ALWAYS be chosen. The reason is very strong. When columns that are updated belong to the index by which a search would be made, then a temporary table is created and filled with current values of these columns (or this column). The cost of creation and insertion of data on disk is so high that it offsets all differences in index search costs. This is final diagnosis, as confirmed by our Optimizer team. This closes this bug as "Not a Bug" and finishes communication on it.
[2 Nov 2015 15:27]
MySQL Verification Team
Sorry for the miscommunication !!!! Please, disregard my last comment. What I truly wanted to write to you is that we can not do much without your data. Traces simply proved insufficient. Hence, if you can repeat your problem on a subset of data, then we could look more closely into the problem.
[2 Nov 2015 16:09]
Kenny Gryp
Hello Sinisa, Please tell me what I can do to provide you more information so Oracle gets enough information to debug this properly, without giving you any data. What should I do? What commands should I run? (Basically, what would you run to get more information after you repeated it yourself)
[2 Nov 2015 16:18]
Kenny Gryp
Why is this bug currently marked as private?
[2 Nov 2015 16:22]
MySQL Verification Team
Hi Kenny, Bug is private for a short period. The reason is not any security problem, but the error on my part. We have studied traces and do not see any way forward without having a fully repeatable test case. We shall try again, but it will take at least one more week, due to the high influx of new bugs reports.
[3 Nov 2015 19:01]
MySQL Verification Team
an idea how to generate a fake testcase might come from the similar bug, that is fixed long ago: https://bugs.mysql.com/bug.php?id=73837
[4 Nov 2015 15:48]
MySQL Verification Team
We are continuing with our efforts of analyzing all traces. It is possible that we might resort into an attempt of generating data that would display the same behavior. Generating data by ourselves might take lots of time. On your side, please try to repeat this behavior by using a subset of data. That would help a lot. Thanks in advance.
[4 Nov 2015 17:15]
MySQL Verification Team
Hi Kenny, We have problems in making a test case ourselves, so may be you can help by sending the outputs of these queries: select count(*) from IDontKnoo_1203; select count(distinct installation_id) from IDontKnoo_1203; select count(*) from IDontKnoo_1203 where installation_id=594100; select count(*) from IDontKnoo_1203 where time>'2014-12-13 22:20:59'; select count(*) from IDontKnoo_1203 where time<='2014-12-13 22:20:59'; select count(*) from IDontKnoo_1203 where time>'2014-12-13 22:20:59' and installation_id=594100; select count(*) from IDontKnoo_1203 where time<='2014-12-13 22:20:59' and installation_id=594100;
[6 Dec 2015 1:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
Description: The following query:: SELECT installation_id, node_id, gateway_id, relay_gateway_id, signal_id, time, rec_time FROM Stowlen.IDontKnoo_1203 WHERE installation_id=594100 AND time>'2014-12-13 22:20:59' AND node_id=34267405 AND (gateway_id<>34267405 OR relay_gateway_id<>34267405) AND signal_id<>12 AND rec_seqno>=0 ORDER BY time LIMIT 1; on the following table ``CREATE TABLE``:: CREATE TABLE `IDontKnoo_1203` ( `installation_id` int(10) unsigned NOT NULL, `cid` varchar(13) NOT NULL, `zone` char(8) NOT NULL, `signal_id` int(11) NOT NULL, `state` tinyint(1) DEFAULT NULL, `time` datetime NOT NULL, `message` varchar(255) DEFAULT NULL, `rec_time` datetime DEFAULT NULL, `rec_seqno` int(11) DEFAULT NULL, `transpath` char(8) DEFAULT NULL, `callerid` char(20) DEFAULT NULL, `node_id` int(10) unsigned DEFAULT NULL, `gateway_id` int(10) unsigned DEFAULT NULL, `relay_gateway_id` int(10) unsigned DEFAULT NULL, `signal_id_index` tinyint(3) unsigned DEFAULT '0', KEY `IDontKnoo_time_ix` (`time`), KEY `IDontKnoo_insid_time_ix` (`installation_id`,`time`), KEY `IDontKnoo_insid_sid_time_ix` (`installation_id`,`signal_id`,`time`), KEY `IDontKnoo_insid_sid_zone_time_ix` (`installation_id`,`signal_id`,`zone`,`time`), KEY `IDontKnoo_insid_zone_time_ix` (`installation_id`,`zone`,`time`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 /*!50100 PARTITION BY RANGE (to_days(time)) (PARTITION p201405 VALUES LESS THAN (735750) ENGINE = InnoDB, PARTITION p201406 VALUES LESS THAN (735780) ENGINE = InnoDB, PARTITION p201407 VALUES LESS THAN (735811) ENGINE = InnoDB, PARTITION p201408 VALUES LESS THAN (735842) ENGINE = InnoDB, PARTITION p201409 VALUES LESS THAN (735872) ENGINE = InnoDB, PARTITION p201410 VALUES LESS THAN (735903) ENGINE = InnoDB, PARTITION p201411 VALUES LESS THAN (735933) ENGINE = InnoDB, PARTITION p201412 VALUES LESS THAN (735964) ENGINE = InnoDB, PARTITION p201501 VALUES LESS THAN (735995) ENGINE = InnoDB, PARTITION p201502 VALUES LESS THAN (736023) ENGINE = InnoDB, PARTITION p201503 VALUES LESS THAN (736054) ENGINE = InnoDB, PARTITION p201504 VALUES LESS THAN (736084) ENGINE = InnoDB, PARTITION p201505 VALUES LESS THAN (736115) ENGINE = InnoDB, PARTITION p201506 VALUES LESS THAN (736145) ENGINE = InnoDB, PARTITION p201507 VALUES LESS THAN (736176) ENGINE = InnoDB, PARTITION p201508 VALUES LESS THAN (736207) ENGINE = InnoDB, PARTITION p201509 VALUES LESS THAN (736237) ENGINE = InnoDB, PARTITION p201510 VALUES LESS THAN (736268) ENGINE = InnoDB, PARTITION p201511 VALUES LESS THAN (736298) ENGINE = InnoDB, PARTITION p201512 VALUES LESS THAN (736329) ENGINE = InnoDB, PARTITION pmax VALUES LESS THAN MAXVALUE ENGINE = InnoDB) */ with the following ``SHOW INDEXES`` output:: +----------------+------------+----------------------------------+--------------+-----------------+-----------+-------------+----------+--------+------+------------+---------+---------------+ | Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment | +----------------+------------+----------------------------------+--------------+-----------------+-----------+-------------+----------+--------+------+------------+---------+---------------+ | IDontKnoo_1203 | 1 | IDontKnoo_time_ix | 1 | time | A | 110576380 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_time_ix | 1 | installation_id | A | 1249450 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_time_ix | 2 | time | A | 221152761 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_sid_time_ix | 1 | installation_id | A | 1348492 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_sid_time_ix | 2 | signal_id | A | 11057638 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_sid_time_ix | 3 | time | A | 221152761 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_sid_zone_time_ix | 1 | installation_id | A | 1626123 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_sid_zone_time_ix | 2 | signal_id | A | 11057638 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_sid_zone_time_ix | 3 | zone | A | 13822047 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_sid_zone_time_ix | 4 | time | A | 221152761 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_zone_time_ix | 1 | installation_id | A | 1182635 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_zone_time_ix | 2 | zone | A | 5026199 | NULL | NULL | | BTREE | | | | IDontKnoo_1203 | 1 | IDontKnoo_insid_zone_time_ix | 3 | time | A | 221152761 | NULL | NULL | | BTREE | | | +----------------+------------+----------------------------------+--------------+-----------------+-----------+-------------+----------+--------+------+------------+---------+---------------+ The Explain shows that ``IDontKnoo_time_ix`` was used, estimating ``70227902`` rows:: +----+-------------+----------------+-------+-------------------------------------------------------------------------------------------------------------------------------------+-------------------+---------+------+----------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+----------------+-------+-------------------------------------------------------------------------------------------------------------------------------------+-------------------+---------+------+----------+-------------+ | 1 | SIMPLE | IDontKnoo_1203 | range | IDontKnoo_time_ix,IDontKnoo_insid_time_ix,IDontKnoo_insid_sid_time_ix,IDontKnoo_insid_sid_zone_time_ix,IDontKnoo_insid_zone_time_ix | IDontKnoo_time_ix | 5 | NULL | 70227902 | Using where | +----+-------------+----------------+-------+-------------------------------------------------------------------------------------------------------------------------------------+-------------------+---------+------+----------+-------------+ How to repeat: But it reads a heck of a lot of rows:: +----------------------------+-----------+ | Variable_name | Value | +----------------------------+-----------+ | Handler_commit | 1 | | Handler_delete | 0 | | Handler_discover | 0 | | Handler_external_lock | 32 | | Handler_mrr_init | 0 | | Handler_prepare | 0 | | Handler_read_first | 0 | | Handler_read_key | 15 | | Handler_read_last | 0 | | Handler_read_next | 133095136 | | Handler_read_prev | 0 | | Handler_read_rnd | 0 | | Handler_read_rnd_next | 0 | | Handler_rollback | 0 | | Handler_savepoint | 0 | | Handler_savepoint_rollback | 0 | | Handler_update | 0 | | Handler_write | 0 | +----------------------------+-----------+ ``EXPLAIN FORMAT=JSON``:: { "query_block": { "select_id": 1, "ordering_operation": { "using_filesort": false, "table": { "table_name": "IDontKnoo_1203", "partitions": [ "p201405", "p201412", "p201501", "p201502", "p201503", "p201504", "p201505", "p201506", "p201507", "p201508", "p201509", "p201510", "p201511", "p201512", "pmax" ], "access_type": "range", "possible_keys": [ "IDontKnoo_time_ix", "IDontKnoo_insid_time_ix", "IDontKnoo_insid_sid_time_ix", "IDontKnoo_insid_sid_zone_time_ix", "IDontKnoo_insid_zone_time_ix" ], "key": "IDontKnoo_time_ix", "used_key_parts": [ "time" ], "key_length": "5", "rows": 70228729, "filtered": 0.2492, "attached_condition": "((`shard09`.`IDontKnoo_1203`.`installation_id` <=> 594100) and ((`shard09`.`IDontKnoo_1203`.`node_id` = 34267405) and (`shard09`.`IDontKnoo_1203`.`time` > '2014-12-13 22:20:59') and ((`shard09`.`IDontKnoo_1203`.`gateway_id` <> 34267405) or (`shard09`.`IDontKnoo_1203`.`relay_gateway_id` <> 34267405)) and (`shard09`.`IDontKnoo_1203`.`signal_id` <> 12) and (`shard09`.`IDontKnoo_1203`.`rec_seqno` >= 0)))" } } } } The optimizer trace is attached in ``optimizer_trace.orig.txt`` in the optimizer trace, the most interesting part that I saw is the following:: "reconsidering_access_paths_for_index_ordering": { "clause": "ORDER BY", "rows_estimation": { "table": "`Stowlen`.`IDontKnoo_1203`", "index": "IDontKnoo_time_ix", "range_analysis": { "table_scan": { "rows": 140474166, "cost": 1.69e8 }, "potential_range_indices": [ { "index": "IDontKnoo_time_ix", "usable": true, "key_parts": [ "time" ] }, { "index": "IDontKnoo_insid_time_ix", "usable": false, "cause": "not_applicable" } Why doesn't it use ``IDontKnoo_insid_time_ix`` as potential solution to when we ``FORCE INDEX(IDontKnoo_insid_time_ix)``, estimated rows drops a lot, still no filesort necessary, much better IMO:: +----+-------------+----------------+-------+-------------------------+-------------------------+---------+------+--------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+----------------+-------+-------------------------+-------------------------+---------+------+--------+-------------+ | 1 | SIMPLE | IDontKnoo_1203 | range | IDontKnoo_insid_time_ix | IDontKnoo_insid_time_ix | 9 | NULL | 224631 | Using where | +----+-------------+----------------+-------+-------------------------+-------------------------+---------+------+--------+-------------+ handler stats look great: +----------------------------+-------+ | Variable_name | Value | +----------------------------+-------+ | Handler_commit | 1 | | Handler_delete | 0 | | Handler_discover | 0 | | Handler_external_lock | 32 | | Handler_mrr_init | 0 | | Handler_prepare | 0 | | Handler_read_first | 0 | | Handler_read_key | 15 | | Handler_read_last | 0 | | Handler_read_next | 45118 | | Handler_read_prev | 0 | | Handler_read_rnd | 0 | | Handler_read_rnd_next | 0 | | Handler_rollback | 0 | | Handler_savepoint | 0 | | Handler_savepoint_rollback | 0 | | Handler_update | 0 | | Handler_write | 0 | +----------------------------+-------+ ``EXPLAIN FORMAT=JSON``:: { "query_block": { "select_id": 1, "ordering_operation": { "using_filesort": false, "table": { "table_name": "IDontKnoo_1203", "partitions": [ "p201405", "p201412", "p201501", "p201502", "p201503", "p201504", "p201505", "p201506", "p201507", "p201508", "p201509", "p201510", "p201511", "p201512", "pmax" ], "access_type": "range", "possible_keys": [ "IDontKnoo_insid_time_ix" ], "key": "IDontKnoo_insid_time_ix", "used_key_parts": [ "installation_id", "time" ], "key_length": "9", "rows": 224636, "filtered": 100, "attached_condition": "((`shard09`.`IDontKnoo_1203`.`node_id` = 34267405) and (`shard09`.`IDontKnoo_1203`.`installation_id` = 594100) and (`shard09`.`IDontKnoo_1203`.`time` > '2014-12-13 22:20:59') and ((`shard09`.`IDontKnoo_1203`.`gateway_id` <> 34267405) or (`shard09`.`IDontKnoo_1203`.`relay_gateway_id` <> 34267405)) and (`shard09`.`IDontKnoo_1203`.`signal_id` <> 12) and (`shard09`.`IDontKnoo_1203`.`rec_seqno` >= 0))" } } } } The optimizer trace is attached in ``optimizer_trace.forced.txt`` Suggested fix: Use the correct index