-
Type:
Bug
-
Resolution: Done
-
Priority:
Critical - P2
-
None
-
Affects Version/s: 2.6.7
-
Component/s: Querying
-
Labels:None
-
Environment:windows server 2008 R2
-
Windows
-
Background
I have a collection that receives a high number of writes (hundreds per second), so the plan cache gets reset a lot. I see in my slow query log inefficient index choices that result in a large number of "nscanned".
I assumed that this was because the plan cache gets reset very often and it's possible that a given query results in 0 documents, so a very simple index choice wins, but as the number of returned documents increases, that simple approach would get slower. So basically, every few thousand queries, I might ask for something that is easily handled by a single index, so that one wins and "infects" the next thousand queries with very slow outcome due to query plan caching.
OK, fine, so I decided to employ an index filter.
It seems to be taking it: after using the index filter if I do find().explain() for the query shape, I get filterSet: true, and it runs in "0" ms.
But I still see slow queries in my log with the poor index choice, so it's ignoring my index filter!!! (see below for details)
The query is pretty complex, but explain seems to figure it out.
Is there any reason why mongo would ignore my query planner? Something to do with blocking vs. non-blocking plans? I'm at a loss.
Details
The Index Filter
db.runCommand({planCacheSetFilter: 'orders',
query: {
"date" : "2015.02.04",
"symbol" : {
"$in" : [
"ESRX"
]
},
"$or" : [
{
"_id" : "20150204-USA-9259-6"
},
{
"initialGateId" : "20150204-USA-9259-6"
},
{
"openChildOrders.id" : "USA-9259-6"
},
{
"intermediateIds" : "USA-9259-6"
}
]
},
indexes: [
{
"_id" : 1
},
{
"initialGateId" : 1
},
{
"openChildOrders.id" : 1
},
{
"intermediateIds" : -1
}
]
});
Explain Output
db.orders.find({ date: "2015.02.04", symbol: { $in: [ "TGE" ] }, $or: [ { _id: "20150204-USA-11455-1263" }, { initialGateId: "20150204-USA-11455-1263" }, { "openChildOrders.id": "USA-11455-1263" }, { intermediateIds: "USA-11455-1263" } ] }).explain()
{
"clauses" : [
{
"cursor" : "BtreeCursor _id_",
"isMultiKey" : false,
"n" : 1,
"nscannedObjects" : 1,
"nscanned" : 1,
"scanAndOrder" : false,
"indexOnly" : false,
"nChunkSkips" : 0,
"indexBounds" : {
"_id" : [
[
"20150204-USA-11455-1263",
"20150204-USA-11455-1263"
]
]
}
},
{
"cursor" : "BtreeCursor intermediateIds_-1",
"isMultiKey" : true,
"n" : 1,
"nscannedObjects" : 1,
"nscanned" : 1,
"scanAndOrder" : false,
"indexOnly" : false,
"nChunkSkips" : 0,
"indexBounds" : {
"intermediateIds" : [
[
"USA-11455-1263",
"USA-11455-1263"
]
]
}
},
{
"cursor" : "BtreeCursor openChildOrders.id_1",
"isMultiKey" : true,
"n" : 0,
"nscannedObjects" : 0,
"nscanned" : 0,
"scanAndOrder" : false,
"indexOnly" : false,
"nChunkSkips" : 0,
"indexBounds" : {
"openChildOrders.id" : [
[
"USA-11455-1263",
"USA-11455-1263"
]
]
}
},
{
"cursor" : "BtreeCursor initialGateId_1",
"isMultiKey" : false,
"n" : 0,
"nscannedObjects" : 0,
"nscanned" : 0,
"scanAndOrder" : false,
"indexOnly" : false,
"nChunkSkips" : 0,
"indexBounds" : {
"initialGateId" : [
[
"20150204-USA-11455-1263",
"20150204-USA-11455-1263"
]
]
}
}
],
"cursor" : "QueryOptimizerCursor",
"n" : 1,
"nscannedObjects" : 2,
"nscanned" : 2,
"nscannedObjectsAllPlans" : 2,
"nscannedAllPlans" : 2,
"scanAndOrder" : false,
"nYields" : 0,
"nChunkSkips" : 0,
"millis" : 0,
"server" : "VM-PRISMUAT-NY:27017",
"filterSet" : true
}
The slow query error
Here you'll see that the plan it uses is an IXSCAN of symbol. If I use a hint that forces this query to use symbol (without the index filter), it runs in about 9ms, but that is still very slow for my application. Using the proper indexes, it runs in "0" ms.
2015-02-04T15:04:43.553-0500 [conn39315] query prism-orders.orders query: { date: "2015.02.04", symbol: { $in: [ "TGE" ] }, $or: [ { _id: "20150204-USA-11455-1263" }, { initialGateId: "20150204-USA-11455-1263" }, { openChildOrders.id: "USA-11455-1263" }, { intermediateIds: "USA-11455-1263" } ] } planSummary: IXSCAN { symbol: 1 } ntoreturn:0 ntoskip:0 nscanned:229 nscannedObjects:229 keyUpdates:0 numYields:11 locks(micros) r:742721 nreturned:1 reslen:82 561ms
- related to
-
SERVER-28116 Consider creating an index filter parameter which modifies how queries are matched
-
- Backlog
-