-
Type:
Bug
-
Resolution: Duplicate
-
Priority:
Major - P3
-
None
-
Affects Version/s: 3.4.19
-
Component/s: Index Maintenance, Querying
-
Labels:None
-
ALL
-
I wouldn't really call that a bug, but I just stumbled upon a case in which adding an index actually degraded the performance of a query. So I guessed this might be interesting for you to know about that case.
For your information, the queries below come from the library Agenda (https://github.com/agenda/agenda), which is a job scheduler backed by MongoDB.
I have a collection named "agendaJobs"; each document in this collection has 5 fields:
- name
- nextRunAt
- priority
- lockedAt
- disabled
This collection has the following index:
{{
{"name":1,"nextRunAt":1,"priority":1,"lockedAt":1,"disabled":1}}}
The following query is performed on a regular basis (to "pull" some jobs that need to be executed):
db.agendaJobs.explain("executionStats").findAndModify({
query: { $or: [
{ name: "testJob"},
{lockedAt: null},
{nextRunAt: { $lte: new Date() }},
{disabled: { $ne: true } },
{ name: "testJob"},
{lockedAt: { $exists: false }},
{nextRunAt: { $lte: new Date() }},
{disabled: { $ne: true }},
{ name: "testJob"},
{lockedAt: { $lte: new Date() }},
{disabled: { $ne: true }}
]},
update: {"$set": {fma: 1}},
sort: { nextRunAt: 1, priority: -1 }
})
Whenever I populate my collections with a lot of documents for which nextRunAt < current date, I see that the query is doing a full index scan:
# First, create many document with nextRunAt < current date > var yesterday = Date.now() - 86400000; var bulk = db.agendaJobs.initializeUnorderedBulkOp(); for (var i = 0; i < 100000; i++) {bulk.insert({"name" : "testJob", "data" : {}, "type" : "normal", "priority" : 0, "nextRunAt" : new Date(yesterday + _rand()*10000), "lastModifiedBy" : null });} bulk.execute(); # Then run the query and gets the execution stats > db.agendaJobs.explain("executionStats").findAndModify({query: { $or: [ { name: "testJob", lockedAt: null, nextRunAt: { $lte: new Date() }, disabled: { $ne: true } }, { name: "testJob", lockedAt: { $exists: false }, nextRunAt: { $lte: new Date() }, disabled: { $ne: true } }, { name: "testJob", lockedAt: { $lte: new Date() }, disabled: { $ne: true } } ] }, update: {"$set": {fma: 1}}, sort: { nextRunAt: 1, priority: -1 }}) { "queryPlanner" : { "plannerVersion" : 1, "namespace" : "mg-viking.agendaJobs", "indexFilterSet" : false, "parsedQuery" : { "$or" : [ { "$and" : [ { "lockedAt" : { "$eq" : null } }, { "name" : { "$eq" : "testJob" } }, { "nextRunAt" : { "$lte" : ISODate("2019-09-27T09:29:36.952Z") } }, { "$nor" : [ { "disabled" : { "$eq" : true } } ] } ] }, { "$and" : [ { "name" : { "$eq" : "testJob" } }, { "lockedAt" : { "$lte" : ISODate("2019-09-27T09:29:36.952Z") } }, { "$nor" : [ { "disabled" : { "$eq" : true } } ] } ] }, { "$and" : [ { "name" : { "$eq" : "testJob" } }, { "nextRunAt" : { "$lte" : ISODate("2019-09-27T09:29:36.952Z") } }, { "$nor" : [ { "disabled" : { "$eq" : true } } ] }, { "$nor" : [ { "lockedAt" : { "$exists" : true } } ] } ] } ] }, "winningPlan" : { "stage" : "UPDATE", "inputStage" : { "stage" : "SUBPLAN", "inputStage" : { "stage" : "LIMIT", "limitAmount" : 1, "inputStage" : { "stage" : "FETCH", "inputStage" : { "stage" : "SORT_MERGE", "sortPattern" : { "nextRunAt" : 1, "priority" : -1 }, "inputStages" : [ { "stage" : "FETCH", "filter" : { "lockedAt" : { "$eq" : null } }, "inputStage" : { "stage" : "IXSCAN", "keyPattern" : { "name" : 1, "nextRunAt" : 1, "priority" : -1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "findAndLockNextJobIndex", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "nextRunAt" : [ ], "priority" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "nextRunAt" : [ "(true, new Date(1569576576952)]" ], "priority" : [ "[MaxKey, MinKey]" ], "lockedAt" : [ "[null, null]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] } } }, { "stage" : "IXSCAN", "keyPattern" : { "name" : 1, "nextRunAt" : 1, "priority" : -1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "findAndLockNextJobIndex", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "nextRunAt" : [ ], "priority" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "nextRunAt" : [ "[MinKey, MaxKey]" ], "priority" : [ "[MaxKey, MinKey]" ], "lockedAt" : [ "(true, new Date(1569576576952)]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] } }, { "stage" : "FETCH", "filter" : { "$nor" : [ { "lockedAt" : { "$exists" : true } } ] }, "inputStage" : { "stage" : "IXSCAN", "keyPattern" : { "name" : 1, "nextRunAt" : 1, "priority" : -1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "findAndLockNextJobIndex", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "nextRunAt" : [ ], "priority" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "nextRunAt" : [ "(true, new Date(1569576576952)]" ], "priority" : [ "[MaxKey, MinKey]" ], "lockedAt" : [ "[null, null]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] } } } ] } } } } }, "rejectedPlans" : [ ] }, "executionStats" : { "executionSuccess" : true, "nReturned" : 1, "executionTimeMillis" : 201, "totalKeysExamined" : 10002, "totalDocsExamined" : 4, "executionStages" : { "stage" : "UPDATE", "nReturned" : 1, "executionTimeMillisEstimate" : 205, "works" : 10005, "advanced" : 1, "needTime" : 10003, "needYield" : 0, "saveState" : 81, "restoreState" : 81, "isEOF" : 1, "invalidates" : 0, "nMatched" : 1, "nWouldModify" : 1, "nInvalidateSkips" : 0, "wouldInsert" : false, "fastmodinsert" : false, "inputStage" : { "stage" : "SUBPLAN", "nReturned" : 1, "executionTimeMillisEstimate" : 205, "works" : 10004, "advanced" : 1, "needTime" : 10003, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 1, "invalidates" : 0, "inputStage" : { "stage" : "LIMIT", "nReturned" : 1, "executionTimeMillisEstimate" : 205, "works" : 10004, "advanced" : 1, "needTime" : 10003, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 1, "invalidates" : 0, "limitAmount" : 1, "inputStage" : { "stage" : "FETCH", "nReturned" : 1, "executionTimeMillisEstimate" : 205, "works" : 10004, "advanced" : 1, "needTime" : 10003, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 0, "invalidates" : 0, "docsExamined" : 1, "alreadyHasObj" : 1, "inputStage" : { "stage" : "SORT_MERGE", "nReturned" : 1, "executionTimeMillisEstimate" : 205, "works" : 10004, "advanced" : 1, "needTime" : 10003, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 0, "invalidates" : 0, "sortPattern" : { "nextRunAt" : 1, "priority" : -1 }, "dupsTested" : 3, "dupsDropped" : 1, "inputStages" : [ { "stage" : "FETCH", "filter" : { "lockedAt" : { "$eq" : null } }, "nReturned" : 1, "executionTimeMillisEstimate" : 104, "works" : 1, "advanced" : 1, "needTime" : 0, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 0, "invalidates" : 0, "docsExamined" : 1, "alreadyHasObj" : 0, "inputStage" : { "stage" : "IXSCAN", "nReturned" : 1, "executionTimeMillisEstimate" : 104, "works" : 1, "advanced" : 1, "needTime" : 0, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 0, "invalidates" : 0, "keyPattern" : { "name" : 1, "nextRunAt" : 1, "priority" : -1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "findAndLockNextJobIndex", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "nextRunAt" : [ ], "priority" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "nextRunAt" : [ "(true, new Date(1569576576952)]" ], "priority" : [ "[MaxKey, MinKey]" ], "lockedAt" : [ "[null, null]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] }, "keysExamined" : 1, "seeks" : 1, "dupsTested" : 0, "dupsDropped" : 0, "seenInvalidated" : 0 } }, { "stage" : "IXSCAN", "nReturned" : 0, "executionTimeMillisEstimate" : 101, "works" : 10000, "advanced" : 0, "needTime" : 9999, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 1, "invalidates" : 0, "keyPattern" : { "name" : 1, "nextRunAt" : 1, "priority" : -1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "findAndLockNextJobIndex", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "nextRunAt" : [ ], "priority" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "nextRunAt" : [ "[MinKey, MaxKey]" ], "priority" : [ "[MaxKey, MinKey]" ], "lockedAt" : [ "(true, new Date(1569576576952)]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] }, "keysExamined" : 9999, "seeks" : 10000, "dupsTested" : 0, "dupsDropped" : 0, "seenInvalidated" : 0 }, { "stage" : "FETCH", "filter" : { "$nor" : [ { "lockedAt" : { "$exists" : true } } ] }, "nReturned" : 2, "executionTimeMillisEstimate" : 0, "works" : 2, "advanced" : 2, "needTime" : 0, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 0, "invalidates" : 0, "docsExamined" : 2, "alreadyHasObj" : 0, "inputStage" : { "stage" : "IXSCAN", "nReturned" : 2, "executionTimeMillisEstimate" : 0, "works" : 2, "advanced" : 2, "needTime" : 0, "needYield" : 0, "saveState" : 82, "restoreState" : 82, "isEOF" : 0, "invalidates" : 0, "keyPattern" : { "name" : 1, "nextRunAt" : 1, "priority" : -1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "findAndLockNextJobIndex", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "nextRunAt" : [ ], "priority" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "nextRunAt" : [ "(true, new Date(1569576576952)]" ], "priority" : [ "[MaxKey, MinKey]" ], "lockedAt" : [ "[null, null]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] }, "keysExamined" : 2, "seeks" : 1, "dupsTested" : 0, "dupsDropped" : 0, "seenInvalidated" : 0 } } ] } } } } } }, "serverInfo" : { "host" : "localhost.localdomain", "port" : 27017, "version" : "3.4.19", "gitVersion" : "a2d97db8fe449d15eb8e275bbf318491781472bf" }, "ok" : 1 }
I was trying to work around that. It looks like the third arm of the $or is actually the one that makes the full index scan necessary; if I remove it, the query only scans a couple of index keys.
So I tried to optimize this part by adding the following index:
db.agendaJobs.createIndex({name: 1, lockedAt: 1, disabled: 1})
After that, running the same query gives a completely different execution plans that seems worse (200k documents scanned for this query, while the previous query only scanned 4 documents!):
> db.agendaJobs.explain("executionStats").findAndModify({query: { $or: [ { name: "testJob", lockedAt: null, nextRunAt: { $lte: new Date() }, disabled: { $ne: true } }, { name: "testJob", lockedAt: { $exists: false }, nextRunAt: { $lte: new Date() }, disabled: { $ne: true } }, { name: "testJob", lockedAt: { $lte: new Date() }, disabled: { $ne: true } } ] }, update: {"$set": {fma: 1}}, sort: { nextRunAt: 1, priority: -1 }}) { "queryPlanner" : { "plannerVersion" : 1, "namespace" : "mg-viking.agendaJobs", "indexFilterSet" : false, "parsedQuery" : { "$or" : [ { "$and" : [ { "lockedAt" : { "$eq" : null } }, { "name" : { "$eq" : "testJob" } }, { "nextRunAt" : { "$lte" : ISODate("2019-09-27T09:33:54.221Z") } }, { "$nor" : [ { "disabled" : { "$eq" : true } } ] } ] }, { "$and" : [ { "name" : { "$eq" : "testJob" } }, { "lockedAt" : { "$lte" : ISODate("2019-09-27T09:33:54.221Z") } }, { "$nor" : [ { "disabled" : { "$eq" : true } } ] } ] }, { "$and" : [ { "name" : { "$eq" : "testJob" } }, { "nextRunAt" : { "$lte" : ISODate("2019-09-27T09:33:54.221Z") } }, { "$nor" : [ { "disabled" : { "$eq" : true } } ] }, { "$nor" : [ { "lockedAt" : { "$exists" : true } } ] } ] } ] }, "winningPlan" : { "stage" : "UPDATE", "inputStage" : { "stage" : "SUBPLAN", "inputStage" : { "stage" : "SORT", "sortPattern" : { "nextRunAt" : 1, "priority" : -1 }, "limitAmount" : 1, "inputStage" : { "stage" : "SORT_KEY_GENERATOR", "inputStage" : { "stage" : "FETCH", "inputStage" : { "stage" : "OR", "inputStages" : [ { "stage" : "FETCH", "filter" : { "$or" : [ { "$nor" : [ { "lockedAt" : { "$exists" : true } } ] }, { "lockedAt" : { "$eq" : null } } ] }, "inputStage" : { "stage" : "IXSCAN", "keyPattern" : { "name" : 1, "nextRunAt" : 1, "priority" : -1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "findAndLockNextJobIndex", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "nextRunAt" : [ ], "priority" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "nextRunAt" : [ "(true, new Date(1569576834221)]" ], "priority" : [ "[MaxKey, MinKey]" ], "lockedAt" : [ "[null, null]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] } } }, { "stage" : "IXSCAN", "keyPattern" : { "name" : 1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "name_1_lockedAt_1_disabled_1", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "lockedAt" : [ "(true, new Date(1569576834221)]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] } } ] } } } } } }, "rejectedPlans" : [ ] }, "executionStats" : { "executionSuccess" : true, "nReturned" : 1, "executionTimeMillis" : 496, "totalKeysExamined" : 100000, "totalDocsExamined" : 200000, "executionStages" : { "stage" : "UPDATE", "nReturned" : 1, "executionTimeMillisEstimate" : 381, "works" : 100005, "advanced" : 1, "needTime" : 100003, "needYield" : 0, "saveState" : 798, "restoreState" : 798, "isEOF" : 1, "invalidates" : 0, "nMatched" : 1, "nWouldModify" : 1, "nInvalidateSkips" : 0, "wouldInsert" : false, "fastmodinsert" : false, "inputStage" : { "stage" : "SUBPLAN", "nReturned" : 1, "executionTimeMillisEstimate" : 415, "works" : 100004, "advanced" : 1, "needTime" : 100003, "needYield" : 0, "saveState" : 799, "restoreState" : 799, "isEOF" : 1, "invalidates" : 0, "inputStage" : { "stage" : "SORT", "nReturned" : 1, "executionTimeMillisEstimate" : 370, "works" : 100004, "advanced" : 1, "needTime" : 100003, "needYield" : 0, "saveState" : 794, "restoreState" : 794, "isEOF" : 1, "invalidates" : 0, "sortPattern" : { "nextRunAt" : 1, "priority" : -1 }, "memUsage" : 129, "memLimit" : 33554432, "limitAmount" : 1, "inputStage" : { "stage" : "SORT_KEY_GENERATOR", "nReturned" : 100000, "executionTimeMillisEstimate" : 360, "works" : 100003, "advanced" : 100000, "needTime" : 2, "needYield" : 0, "saveState" : 794, "restoreState" : 794, "isEOF" : 1, "invalidates" : 0, "inputStage" : { "stage" : "FETCH", "nReturned" : 100000, "executionTimeMillisEstimate" : 304, "works" : 100002, "advanced" : 100000, "needTime" : 1, "needYield" : 0, "saveState" : 794, "restoreState" : 794, "isEOF" : 1, "invalidates" : 0, "docsExamined" : 100000, "alreadyHasObj" : 100000, "inputStage" : { "stage" : "OR", "nReturned" : 100000, "executionTimeMillisEstimate" : 259, "works" : 100002, "advanced" : 100000, "needTime" : 1, "needYield" : 0, "saveState" : 794, "restoreState" : 794, "isEOF" : 1, "invalidates" : 0, "dupsTested" : 100000, "dupsDropped" : 0, "recordIdsForgotten" : 0, "inputStages" : [ { "stage" : "FETCH", "filter" : { "$or" : [ { "$nor" : [ { "lockedAt" : { "$exists" : true } } ] }, { "lockedAt" : { "$eq" : null } } ] }, "nReturned" : 100000, "executionTimeMillisEstimate" : 218, "works" : 100001, "advanced" : 100000, "needTime" : 0, "needYield" : 0, "saveState" : 794, "restoreState" : 794, "isEOF" : 1, "invalidates" : 0, "docsExamined" : 100000, "alreadyHasObj" : 0, "inputStage" : { "stage" : "IXSCAN", "nReturned" : 100000, "executionTimeMillisEstimate" : 64, "works" : 100001, "advanced" : 100000, "needTime" : 0, "needYield" : 0, "saveState" : 794, "restoreState" : 794, "isEOF" : 1, "invalidates" : 0, "keyPattern" : { "name" : 1, "nextRunAt" : 1, "priority" : -1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "findAndLockNextJobIndex", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "nextRunAt" : [ ], "priority" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "nextRunAt" : [ "(true, new Date(1569576834221)]" ], "priority" : [ "[MaxKey, MinKey]" ], "lockedAt" : [ "[null, null]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] }, "keysExamined" : 100000, "seeks" : 1, "dupsTested" : 0, "dupsDropped" : 0, "seenInvalidated" : 0 } }, { "stage" : "IXSCAN", "nReturned" : 0, "executionTimeMillisEstimate" : 0, "works" : 1, "advanced" : 0, "needTime" : 0, "needYield" : 0, "saveState" : 794, "restoreState" : 794, "isEOF" : 1, "invalidates" : 0, "keyPattern" : { "name" : 1, "lockedAt" : 1, "disabled" : 1 }, "indexName" : "name_1_lockedAt_1_disabled_1", "isMultiKey" : false, "multiKeyPaths" : { "name" : [ ], "lockedAt" : [ ], "disabled" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "name" : [ "[\"testJob\", \"testJob\"]" ], "lockedAt" : [ "(true, new Date(1569576834221)]" ], "disabled" : [ "[MinKey, true)", "(true, MaxKey]" ] }, "keysExamined" : 0, "seeks" : 1, "dupsTested" : 0, "dupsDropped" : 0, "seenInvalidated" : 0 } ] } } } } } } }, "serverInfo" : { "host" : "localhost.localdomain", "port" : 27017, "version" : "3.4.19", "gitVersion" : "a2d97db8fe449d15eb8e275bbf318491781472bf" }, "ok" : 1 }
I know that query planning is a difficult problem, so I would completely understand if you tell me that this is some kind of edge case, and that I have to live with it 
I just thought it might be interesting to you.
- duplicates
-
-
- Backlog
-