[SERVER-40460] Wrong index used: date-index is used instead of boolean/date-index Created: 03/Apr/19 Updated: 08/Apr/19 Resolved: 08/Apr/19 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | None |
| Affects Version/s: | 3.6.3, 4.0.3 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Valentin S | Assignee: | Danny Hatcher (Inactive) |
| Resolution: | Done | Votes: | 1 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Attachments: |
|
| Operating System: | ALL |
| Participants: |
| Description |
|
I have documents with the following structure: {{{_id:"asdf", consumed: true, timestamp: ISODate("2018-12-10T11:57:57.960+0000") }}} For querying I have two different (non partial) indices:
When I create a query like find({consumed: false, timestamp: { "$lte" : ISODate("2018-12-10T11:57:57.960+0000")}} the first index is used, which leads to bad performance.
In what case would be for this query the first index better than the second index? Since consumed is a Boolean, using the second index will always look at equal or lower elements - in my case 17.000 instead of 17.000.000 elements.
Attached is a explain('allPlansExecution') query. I added here a limit(400) query, since the evaluation would take several minutes when the first index is used.
I know that i can hint to the second index, but in this case it should be very trivial for mongodb-server to detect that the second index is better than the first index. |
| Comments |
| Comment by Valentin S [ 08/Apr/19 ] | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
I think there is a misunderstanding about what the bug here is. Have you looked at the data structure, query and the indices? Based on the filter and the indices there is no need for a sample. There is always the second index equal or faster on this type of query than the first one. This is clearly a bug, as mongodb is not applying logic but just heuristics on this query. | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Danny Hatcher (Inactive) [ 08/Apr/19 ] | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hello, Thank you for the detailed explains. Unfortunately, what you are experiencing is a scenario in which the sample size we use to generate the plans, 101 documents, does not accurately emulate the data distribution. If the result set is concentrated outside of the sample size, you could experience long queries as you've seen. While you are correct that you currently cannot use hints with updates, you can use Index Filters. An index filter is set server-side to apply to all queries that match a specific query pattern. That way you can override the poor usage of the query planner on this instance. Please note that index filters will not persist through a process restart so will need to be created again in that case. If index filters do not fit your environment, you may wish to think about restructuring your data and/or queries to ensure that you do not run into instances of poor data distribution in the future. I encourage you to reach out to our community by posting on the mongodb-user group or on Stack Overflow with the mongodb tag for help with that. While not an optimal situation, sample sizes inadequately capturing data distribution is a known pain point that we are constantly working on improving. Because this ticket does not show evidence of a bug, I will now close it. Thanks, Danny | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Valentin S [ 08/Apr/19 ] | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hi Danny, I just re-created the index and run the full query again. Note that a third index is now also in place ("consumed_1"), that is now used in production. The query took more than 17 minutes. If the correct index would have been used, it would have took less than 17 milliseconds. Query for file explain-long.json (17 minutes on the winning plan): db.getCollection("...").find({consumed: false, timestamp: { "$lte" : ISODate("2019-08-08T11:57:57.960+0000")).explain("allPlansExecution")}} Query for file explain-with-hint.json (13 milliseconds on the hinted plan): db.getCollection("...").find({consumed: false, timestamp: { "$lte" : ISODate("2019-08-08T11:57:57.960+0000")).hint("consumed_1_timestamp_-1").explain("executionStats")}}
Please note, that since https://jira.mongodb.org/browse/SERVER-1599 is not implemented, this severe bug really makes the whole point of indexing data in this case useless. BR Valentin | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Danny Hatcher (Inactive) [ 04/Apr/19 ] | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hello Valentin, I do see the single field index being used instead of the compound one in the new explain. However, looking at the explain output, both indexes took the same amount of effort to evaluate:
The nreturned, works, advanced, and keysExamined fields are all identical so to the query planner these index usages are identical. You mentioned that you put a limit on this query that isn't normally there in order to test it. Do you have an example without the limit where the executionStats for one index is demonstrably worse than the other? Thanks, Danny | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Valentin S [ 04/Apr/19 ] | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hi Daniel, sorry for uploading the explain.json where the correct index-2 was used. Depending on what timestamp I queried sometimes the correct index 2 was used, but most of the time the wrong index-1 was used. See the attached explain-index-1.json file. | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Danny Hatcher (Inactive) [ 03/Apr/19 ] | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hello Valentin, The explain output that you provided shows that the query is using the second index (the compound) and not the first one. Do you have an explain or log output that shows the first index being chosen instead? Thanks, Danny | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Valentin S [ 03/Apr/19 ] | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Because https://jira.mongodb.org/browse/SERVER-1599 is not yet implemented, an updateMany call to this collection also uses the wrong index, leading to 1000x worse performance than when the correct index would be used. |