Mongo db query time more than expected
anshul jain
I am running standalone mongodb server with version 3.4. I am using following query on my collection which contains around 1.8 million document out of which around 1 million document are in "ARCHIVED" status.
db.tender_listing.find({ "tender_id" : { "$gt" : "d"} , "workflow_status" : { "$in" : [ "ARCHIVED"]}}).limit(4000).sort({tender_id:1}).hint({workflow_status:1, tender_id:1}).explain('executionStats')
Each query stage has executionTimeMillisEstimate of not more than 100ms but the total executionTimeMillis is 30992.
For what operation query is taking this much extra time? Also how can I optimise same?
Following is the output
{
"queryPlanner" : {
"plannerVersion" : 1,
"namespace" : "ofbTenders.tender_listing",
"indexFilterSet" : false,
"parsedQuery" : {
"$and" : [
{
"workflow_status" : {
"$eq" : "ARCHIVED"
}
},
{
"tender_id" : {
"$gt" : "d"
}
}
]
},
"winningPlan" : {
"stage" : "LIMIT",
"limitAmount" : 4000,
"inputStage" : {
"stage" : "FETCH",
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"workflow_status" : 1,
"tender_id" : 1
},
"indexName" : "workflow_status_1_tender_id_1",
"isMultiKey" : false,
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : 1,
"direction" : "forward",
"indexBounds" : {
"workflow_status" : [
"[\"ARCHIVED\", \"ARCHIVED\"]"
],
"tender_id" : [
"(\"d\", {})"
]
}
}
}
},
"rejectedPlans" : [ ]
},
"executionStats" : {
"executionSuccess" : true,
"nReturned" : 4000,
"executionTimeMillis" : 30992,
"totalKeysExamined" : 4000,
"totalDocsExamined" : 4000,
"executionStages" : {
"stage" : "LIMIT",
"nReturned" : 4000,
"executionTimeMillisEstimate" : 90,
"works" : 6129,
"advanced" : 4000,
"needTime" : 0,
"needYield" : 2128,
"saveState" : 2128,
"restoreState" : 2128,
"isEOF" : 1,
"invalidates" : 0,
"limitAmount" : 4000,
"inputStage" : {
"stage" : "FETCH",
"nReturned" : 4000,
"executionTimeMillisEstimate" : 80,
"works" : 6128,
"advanced" : 4000,
"needTime" : 0,
"needYield" : 2128,
"saveState" : 2128,
"restoreState" : 2128,
"isEOF" : 0,
"invalidates" : 0,
"docsExamined" : 4000,
"alreadyHasObj" : 0,
"inputStage" : {
"stage" : "IXSCAN",
"nReturned" : 4000,
"executionTimeMillisEstimate" : 10,
"works" : 4000,
"advanced" : 4000,
"needTime" : 0,
"needYield" : 0,
"saveState" : 2128,
"restoreState" : 2128,
"isEOF" : 0,
"invalidates" : 0,
"keyPattern" : {
"workflow_status" : 1,
"tender_id" : 1
},
"indexName" : "workflow_status_1_tender_id_1",
"isMultiKey" : false,
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : 1,
"direction" : "forward",
"indexBounds" : {
"workflow_status" : [
"[\"ARCHIVED\", \"ARCHIVED\"]"
],
"tender_id" : [
"(\"d\", {})"
]
},
"keysExamined" : 4000,
"seeks" : 1,
"dupsTested" : 0,
"dupsDropped" : 0,
"seenInvalidated" : 0
}
}
}
},
"serverInfo" : {
"host" : "ofb59-Latitude-3450",
"port" : 27017,
"version" : "3.4.4",
"gitVersion" : "888390515874a9debd1b6c5d36559ca86b44babd"
},
"ok" : 1
}
Have asked same question on stackoverflow also.
Kevin Adistambha
Hi
Some numbers of note in the explain output are:
"executionSuccess" : true,
"nReturned" : 4000,
"executionTimeMillis" : 30992,
"totalKeysExamined" : 4000,
"totalDocsExamined" : 4000,
and also:
"needYield" : 2128,
This means that the query examined 4000 index keys, and it also needed to fetch 4000 documents from disk to return. The large number of yields seems to indicate that MongoDB spent a lot of its time waiting for disk access. See Explain results for details on what each of the metric means.
Typically, this poor performance is due to either: small memory, small WiredTiger cache setting, slow disk, or all of them; that is, this is typically a result of asking the hardware to do more than what it can provide. Increasing RAM and using a faster disk should yield an improved performance.
Another reason is that your collection contains 1.8 million documents, with more than half described by a binary index key. This means that the index is not selective enough to provide you with a targeted query. The index/query combination here means that you’re essentially doing a half-collection scan, which is not a performant query by its nature.
If you’re still seeing issues with this, please post:
- Your hardware specification (RAM, CPU, etc.)
- Your MongoDB version and your OS version
- Output of db.stats() and db.collection.stats()
- Output of db.serverCmdLineOpts()
Best regards
Kevin