-
Type:
Bug
-
Resolution: Duplicate
-
Priority:
Minor - P4
-
None
-
Affects Version/s: 2.2.0, 3.0.6
-
Component/s: Querying
-
None
-
ALL
-
None
-
0
-
None
-
None
-
None
-
None
-
None
-
None
We have recently moved from a (single instance) MongoDB server 2.2.0 on Linux to a (single instance) MongoDB server 3.0.6 on Windows for a specific project. We have a collection that contains ~1.3 million documents.
The following query to find messages for a specific 24h period performs perfectly fine on 2.2.0:
db.MyCollection.find({ query: {
$and: [
{ "Messages.Message.Header.TimeStamp": { $gte: ISODate("2015-10-12T22:00:00Z") }},
{ "Messages.Message.Header.TimeStamp": { $lt: ISODate("2015-10-13T22:00:00Z") }}
]
}, $explain: 1});
Explain:
{
"cursor": "BtreeCursor Messages.Message.Header.TimeStamp_1",
"isMultiKey": true,
"n": 7854,
"nscannedObjects": 7854,
"nscanned": 7854,
"nscannedObjectsAllPlans": 7854,
"nscannedAllPlans": 7854,
"scanAndOrder": false,
"indexOnly": false,
"nYields": 0,
"nChunkSkips": 0,
"millis": 31,
"indexBounds": {
"Messages.Message.Header.TimeStamp": [
[
"2015-10-12T22:00:00Z",
"292278995-01--2147483647T07:12:56.808Z"
]
]
},
"allPlans": [
{
"cursor": "BtreeCursor Messages.Message.Header.TimeStamp_1",
"n": 7854,
"nscannedObjects": 7854,
"nscanned": 7854,
"indexBounds": {
"Messages.Message.Header.TimeStamp": [
[
"2015-10-12T22:00:00Z",
"292278995-01--2147483647T07:12:56.808Z"
]
]
}
}
],
"oldPlan": {
"cursor": "BtreeCursor Messages.Message.Header.TimeStamp_1",
"indexBounds": {
"Messages.Message.Header.TimeStamp": [
[
"2015-10-12T22:00:00Z",
"292278995-01--2147483647T07:12:56.808Z"
]
]
}
},
"server": "myserver:27017"
}
(Though I don't know what's going on with the weird
""292278995-01--2147483647T07:12:56.808Z"
value...?)
We copied the collection to the new 3.0 (windows) server. And ran the same query; this took over 9 minutes to complete. I have re-created the index but that didn't help.
The explain on this (win, 3.0.6) host looks like this:
{
"queryPlanner": {
"plannerVersion": 1,
"namespace": "MyDB.MyCollection",
"indexFilterSet": false,
"parsedQuery": {
"$and": [
{
"Messages.Message.Header.TimeStamp": {
"$lt": "2015-10-13T22:00:00Z"
}
},
{
"Messages.Message.Header.TimeStamp": {
"$gte": "2015-10-12T22:00:00Z"
}
}
]
},
"winningPlan": {
"stage": "KEEP_MUTATIONS",
"inputStage": {
"stage": "FETCH",
"filter": {
"Messages.Message.Header.TimeStamp": {
"$gte": "2015-10-12T22:00:00Z"
}
},
"inputStage": {
"stage": "IXSCAN",
"keyPattern": {
"Messages.Message.Header.TimeStamp": 1
},
"indexName": "Messages.Message.Header.TimeStamp_1",
"isMultiKey": true,
"direction": "forward",
"indexBounds": {
"Messages.Message.Header.TimeStamp": [
"(true, new Date(1444773600000))"
]
}
}
}
},
"rejectedPlans": []
},
"executionStats": {
"executionSuccess": true,
"nReturned": 8033,
"executionTimeMillis": 118350,
"totalKeysExamined": 1383287,
"totalDocsExamined": 1383199,
"executionStages": {
"stage": "KEEP_MUTATIONS",
"nReturned": 8033,
"executionTimeMillisEstimate": 112792,
"works": 1383353,
"advanced": 8033,
"needTime": 1375254,
"needFetch": 65,
"saveState": 11048,
"restoreState": 11048,
"isEOF": 1,
"invalidates": 0,
"inputStage": {
"stage": "FETCH",
"filter": {
"Messages.Message.Header.TimeStamp": {
"$gte": "2015-10-12T22:00:00Z"
}
},
"nReturned": 8033,
"executionTimeMillisEstimate": 112652,
"works": 1383353,
"advanced": 8033,
"needTime": 1375254,
"needFetch": 65,
"saveState": 11048,
"restoreState": 11048,
"isEOF": 1,
"invalidates": 0,
"docsExamined": 1383199,
"alreadyHasObj": 0,
"inputStage": {
"stage": "IXSCAN",
"nReturned": 1383199,
"executionTimeMillisEstimate": 104092,
"works": 1383287,
"advanced": 1383199,
"needTime": 88,
"needFetch": 0,
"saveState": 11048,
"restoreState": 11048,
"isEOF": 1,
"invalidates": 0,
"keyPattern": {
"Messages.Message.Header.TimeStamp": 1
},
"indexName": "Messages.Message.Header.TimeStamp_1",
"isMultiKey": true,
"direction": "forward",
"indexBounds": {
"Messages.Message.Header.TimeStamp": [
"(true, new Date(1444773600000))"
]
},
"keysExamined": 1383287,
"dupsTested": 1383287,
"dupsDropped": 88,
"seenInvalidated": 0,
"matchTested": 0
}
}
},
"allPlansExecution": []
},
"serverInfo": {
"host": "myserver2",
"port": 27017,
"version": "3.0.6",
"gitVersion": "1ef45a23a4c5e3480ac919b28afcba3c615488f2"
}
}
If I change the query to 'greaterorequal than date X' instead of 'greaterorequal than date X and less than date Y' the query performs fine:
db.Conversations.find({ query: {
"Messages.Message.Header.TimeStamp": { $gte: ISODate("2015-10-12T22:00:00Z") }
}, $explain: 1});
Explain:
{
"queryPlanner": {
"plannerVersion": 1,
"namespace": "MyDB.MyCollection",
"indexFilterSet": false,
"parsedQuery": {
"Messages.Message.Header.TimeStamp": {
"$gte": "2015-10-12T22:00:00Z"
}
},
"winningPlan": {
"stage": "FETCH",
"inputStage": {
"stage": "IXSCAN",
"keyPattern": {
"Messages.Message.Header.TimeStamp": 1
},
"indexName": "Messages.Message.Header.TimeStamp_1",
"isMultiKey": true,
"direction": "forward",
"indexBounds": {
"Messages.Message.Header.TimeStamp": [
"[new Date(1444687200000), new Date(9223372036854775807)]"
]
}
}
},
"rejectedPlans": []
},
"executionStats": {
"executionSuccess": true,
"nReturned": 11081,
"executionTimeMillis": 359,
"totalKeysExamined": 11081,
"totalDocsExamined": 11081,
"executionStages": {
"stage": "FETCH",
"nReturned": 11081,
"executionTimeMillisEstimate": 330,
"works": 11631,
"advanced": 11081,
"needTime": 0,
"needFetch": 549,
"saveState": 558,
"restoreState": 558,
"isEOF": 1,
"invalidates": 0,
"docsExamined": 11081,
"alreadyHasObj": 0,
"inputStage": {
"stage": "IXSCAN",
"nReturned": 11081,
"executionTimeMillisEstimate": 270,
"works": 11081,
"advanced": 11081,
"needTime": 0,
"needFetch": 0,
"saveState": 558,
"restoreState": 558,
"isEOF": 1,
"invalidates": 0,
"keyPattern": {
"Messages.Message.Header.TimeStamp": 1
},
"indexName": "Messages.Message.Header.TimeStamp_1",
"isMultiKey": true,
"direction": "forward",
"indexBounds": {
"Messages.Message.Header.TimeStamp": [
"[new Date(1444687200000), new Date(9223372036854775807)]"
]
},
"keysExamined": 11081,
"dupsTested": 11081,
"dupsDropped": 0,
"seenInvalidated": 0,
"matchTested": 0
}
},
"allPlansExecution": []
},
"serverInfo": {
"host": "myserver2",
"port": 27017,
"version": "3.0.6",
"gitVersion": "1ef45a23a4c5e3480ac919b28afcba3c615488f2"
}
}
It seems that a range query "X => date1 X $and X < date2" somehow trips the queryplanner into not using the index whereas "X >= date1" is fine.
If there's anything I can to to help or provide more information then please let me know.
- duplicates
-
SERVER-16042 Optimise $all/$and to select smallest subset as initial index bounds
-
- Closed
-