Details
-
New Feature
-
Resolution: Duplicate
-
Major - P3
-
None
-
2.6.10, 3.0.5
-
None
Description
When we log aggregation operations, we do not log the query plan used (for the $match component). This information would be fairly useful when debugging any performance issues with aggregation queries.
For example, I have the following collection, cats.mycats, containing a single document:
> db.mycats.find()
|
{ "_id" : ObjectId("55bef95c1091b2ef1816b6eb"), "name" : "ernie", "age" : 5 }
|
and a single index (on top of the in-built _id index):
> db.mycats.getIndexes()
|
[
|
{
|
"v" : 1,
|
"key" : {
|
"_id" : 1
|
},
|
"name" : "_id_",
|
"ns" : "cats.mycats"
|
},
|
{
|
"v" : 1,
|
"key" : {
|
"name" : 1
|
},
|
"name" : "name_1",
|
"ns" : "cats.mycats"
|
}
|
]
|
I issue a find query:
> db.mycats.find({name: 'ernie'})
|
{ "_id" : ObjectId("55bef95c1091b2ef1816b6eb"), "name" : "ernie", "age" : 5 }
|
which produces these loglines, telling me that the name: 1 index was used:
2015-08-03T16:52:36.043+1000 I QUERY [conn3] query cats.mycats query: { name: "ernie" } planSummary: IXSCAN { name: 1.0 } ntoreturn:0 ntoskip:0 nscanned:1 nscannedObjects:1 keyUp
|
dates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:71 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 }
|
}, Collection: { acquireCount: { R: 1 } } } 0ms
|
2015-08-03T16:52:36.044+1000 I COMMAND [conn3] command cats.$cmd command: isMaster { isMaster: 1.0, forShell: 1.0 } keyUpdates:0 writeConflicts:0 numYields:0 reslen:178 locks:{} 0m
|
s
|
I then issue an analogous aggregation query:
> db.mycats.aggregate([{$match: {name: 'ernie'}}])
|
{ "_id" : ObjectId("55bef95c1091b2ef1816b6eb"), "name" : "ernie", "age" : 5 }
|
which produces this logline, which does not tell me which query plan was used:
2015-08-03T16:53:35.427+1000 I COMMAND [conn3] command cats.$cmd command: aggregate { aggregate: "mycats", pipeline: [ { $match: { name: "ernie" } } ], cursor: {} } keyUpdates:0 wr
|
iteConflicts:0 numYields:0 reslen:153 locks:{ Global: { acquireCount: { r: 6 } }, MMAPV1Journal: { acquireCount: { r: 3 } }, Database: { acquireCount: { r: 3 } }, Collection: { acqu
|
ireCount: { R: 3 } } } 0ms
|
There is no information about the query plan used.
If I use the explain option for aggregate, I can confirm that an index is being used:
> db.mycats.aggregate([{$match: {name: 'ernie'}}], {explain:true})
|
{
|
"stages" : [
|
{
|
"$cursor" : {
|
"query" : {
|
"name" : "ernie"
|
},
|
"queryPlanner" : {
|
"plannerVersion" : 1,
|
"namespace" : "cats.mycats",
|
"indexFilterSet" : false,
|
"parsedQuery" : {
|
"name" : {
|
"$eq" : "ernie"
|
}
|
},
|
"winningPlan" : {
|
"stage" : "FETCH",
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"name" : 1
|
},
|
"indexName" : "name_1",
|
"isMultiKey" : false,
|
"direction" : "forward",
|
"indexBounds" : {
|
"name" : [
|
"[\"ernie\", \"ernie\"]"
|
]
|
}
|
}
|
},
|
"rejectedPlans" : [ ]
|
}
|
}
|
}
|
],
|
"ok" : 1
|
}
|
However, there is no way to actually find out the query plan used for running aggregation operations in a Production instance of MongoDB.
Attachments
Issue Links
- duplicates
-
SERVER-16847 Diagnostic log output for all query clients should include plan summary string
-
- Closed
-