-
Type: Bug
-
Resolution: Duplicate
-
Priority: Minor - P4
-
None
-
Affects Version/s: 2.2.0, 3.0.6
-
Component/s: Querying
-
None
-
ALL
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