[SERVER-21178] Super slow query and increased memory usage on inefficient range queries Created: 28/Oct/15 Updated: 17/Nov/15 Resolved: 17/Nov/15 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Querying |
| Affects Version/s: | 3.0.5 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Hoyt Ren | Assignee: | David Storch |
| Resolution: | Duplicate | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Attachments: |
|
||||||||||||||||
| Issue Links: |
|
||||||||||||||||
| Operating System: | ALL | ||||||||||||||||
| Steps To Reproduce: | 1.insert same data as the structure. |
||||||||||||||||
| Participants: | |||||||||||||||||
| Description |
|
It costs more than 20 mins to query 1 hour's data, which is about 10,000 doucuments, and the server's 100GB memory can be used up by these queries. Details:
I have a collection named 'orders'. The documents look like:
I built an index:
then I run this query:
I get:
I guess this means scan all data before '2015-10-28T03:00:00Z', which is more than 40GB data. after I change the query to
I get:
This looks better and runs much faster (finished within a second), but how can I get my original query work? |
| Comments |
| Comment by David Storch [ 17/Nov/15 ] | ||||||||||||||||||
|
Hi Hoyt Ren, Thanks for the additional output. The information contained in the explain makes it clear why the slower plan is being selected by the query engine: this is a variation of SERVER-20616. The way that the plan ranker samples from the data during its trial execution period misleads the engine by making it look like the "(new Date(1447750800000), true)" index bounds are more selective. Fixes for either SERVER-20616 or
On the client side, you will then need to filter out any results where "update_time" exceeds the $lt upper bound. I am closing this ticket as a duplicate of SERVER-20616, since that is the underlying problem causing the engine to choose the slower plan. Best, | ||||||||||||||||||
| Comment by Hoyt Ren [ 17/Nov/15 ] | ||||||||||||||||||
|
Hi David, Thanks for teaching me about the 'allPlansExecution' option. I attached the output as 'mongo_query_explain.txt'. It cost about 20min to generate this output, surely the problem is still there. Sorry for making a writen-mistake in earlier comment that ISODate('2015-09-12T17:00:00+08')", should be ISODate('2015-11-12T17:00:00+08'), hope this doesn't confuse you. | ||||||||||||||||||
| Comment by David Storch [ 16/Nov/15 ] | ||||||||||||||||||
|
Hi Hoyt Ren, In order to help me diagnose, can you please post the full explain output from both queries you mention above? Please use the allPlansExecution explain mode in order to ensure that all relevant diagnostic information is included. The syntax is
I will put this ticket into the "waiting" state pending the requested additional information. Best, | ||||||||||||||||||
| Comment by Hoyt Ren [ 12/Nov/15 ] | ||||||||||||||||||
|
After I upgrade my server to 3.0.7, follow https://docs.mongodb.org/manual/tutorial/upgrade-revision/#upgrade-sharded-cluster
I get:
I change the query to:
I get:
when I issue: db.version() I get: 3.0.7 It seems that on the production server, the patch don't work. I haven't rebuild the index because I can't interrupt the service. Any suggestions, what I can try? | ||||||||||||||||||
| Comment by Ramon Fernandez Marina [ 29/Oct/15 ] | ||||||||||||||||||
|
Thanks for the update on 3.0.7, glad to hear it performs better for your use case. I'm going to close this ticket as a duplicate of Regards, | ||||||||||||||||||
| Comment by Hoyt Ren [ 29/Oct/15 ] | ||||||||||||||||||
|
The detailed output of the test attached as 'mongo_index_bound_test.txt'. | ||||||||||||||||||
| Comment by Hoyt Ren [ 29/Oct/15 ] | ||||||||||||||||||
|
Hello Ramon Fernandez, Thank you for the working solution and quick help. Now I understand this is an old story and talked frequently these days. However we haven't completely resolve it, we can always make hotfix. As I tested 3.0.7, it's much better. When I built index ASC, mongo automatically got right direction of the bounds according to the amount of records, and the query become much faster. However when I built index DESC, it seems always scan from largest, even if scan from smallest should be much faster. This doesn't bother me becasue I usually expect mongo scan from largest, however mongo's behavior is still weird. I guess [new Date(9223372036854775807)] and [true] are same thing here. I attached my testing details. I removed irrelative lines of the output. For the test, the all data range is from "2015-10-28T16:00:00Z" to "2015-10-29T08:00:00Z". Hope this could help. I will upgrade my production servers as soon as possible, and expected you guys could completely fix this problem later, good work. | ||||||||||||||||||
| Comment by Ramon Fernandez Marina [ 28/Oct/15 ] | ||||||||||||||||||
|
Hoyt Ren, unfortunately the behavior with index bounds that your observing is a known limitation with multikey indices described in However we've made some recent improvements in 3.0.7 that may help with your specific case: Thanks, |