| Steps To Reproduce: |
Here are the explain() results
production-database:PRIMARY> db.clusters.find({ deleted: { $ne: true }, "timestamps.cluster_timestamps.summary_last_updated": { $exists: true }, feed_id: "abcdefg", "timestamps.article_timestamps.first_article_published": { $lte: new Date(1531754990084), $gte: new Date(1531668590084) }, score: { $exists: true } }).explain("executionStats")
|
{
|
"queryPlanner" : {
|
"plannerVersion" : 1,
|
"namespace" : "production.clusters",
|
"indexFilterSet" : false,
|
"parsedQuery" : {
|
"$and" : [
|
{
|
"feed_id" : {
|
"$eq" : "abcdefg"
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
},
|
{
|
"$nor" : [
|
{
|
"deleted" : {
|
"$eq" : true
|
}
|
}
|
]
|
}
|
]
|
},
|
"winningPlan" : {
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1,
|
"timestamps.article_timestamps.first_article_published" : 1,
|
"score" : -1,
|
"timestamps.cluster_timestamps.summary_last_updated" : 1,
|
"deleted" : 1
|
},
|
"indexName" : "feed_id.first_article_published.score-1.summary_last_updated.deleted",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"timestamps.article_timestamps.first_article_published" : [ ],
|
"score" : [ ],
|
"timestamps.cluster_timestamps.summary_last_updated" : [ ],
|
"deleted" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"timestamps.article_timestamps.first_article_published" : [
|
"[new Date(1531668590084), new Date(1531754990084)]"
|
],
|
"score" : [
|
"[MaxKey, MinKey]"
|
],
|
"timestamps.cluster_timestamps.summary_last_updated" : [
|
"[MinKey, MaxKey]"
|
],
|
"deleted" : [
|
"[MinKey, true)",
|
"(true, MaxKey]"
|
]
|
}
|
}
|
},
|
"rejectedPlans" : [
|
{
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
},
|
{
|
"$nor" : [
|
{
|
"deleted" : {
|
"$eq" : true
|
}
|
}
|
]
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1
|
},
|
"indexName" : "feed_id_1",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
]
|
}
|
}
|
},
|
{
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
},
|
{
|
"$nor" : [
|
{
|
"deleted" : {
|
"$eq" : true
|
}
|
}
|
]
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1,
|
"active" : 1
|
},
|
"indexName" : "feed_id_1_active_1",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"active" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"active" : [
|
"[MinKey, MaxKey]"
|
]
|
}
|
}
|
},
|
{
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1,
|
"score" : -1,
|
"timestamps.cluster_timestamps.last_updated" : -1,
|
"deleted" : 1
|
},
|
"indexName" : "feed_id_1_score_-1_timestamps.cluster_timestamps.last_updated_-1_deleted_1",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"score" : [ ],
|
"timestamps.cluster_timestamps.last_updated" : [ ],
|
"deleted" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"score" : [
|
"[MaxKey, MinKey]"
|
],
|
"timestamps.cluster_timestamps.last_updated" : [
|
"[MaxKey, MinKey]"
|
],
|
"deleted" : [
|
"[MinKey, true)",
|
"(true, MaxKey]"
|
]
|
}
|
}
|
},
|
{
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"$nor" : [
|
{
|
"deleted" : {
|
"$eq" : true
|
}
|
}
|
]
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1,
|
"timestamps.cluster_timestamps.summary_last_updated" : -1
|
},
|
"indexName" : "feed_id_1_timestamps.cluster_timestamps.summary_last_updated_-1",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"timestamps.cluster_timestamps.summary_last_updated" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"timestamps.cluster_timestamps.summary_last_updated" : [
|
"[MaxKey, MinKey]"
|
]
|
}
|
}
|
},
|
{
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
},
|
{
|
"$nor" : [
|
{
|
"deleted" : {
|
"$eq" : true
|
}
|
}
|
]
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1,
|
"active" : 1,
|
"_id" : -1
|
},
|
"indexName" : "feed_id_1_active_1__id_-1",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"active" : [ ],
|
"_id" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"active" : [
|
"[MinKey, MaxKey]"
|
],
|
"_id" : [
|
"[MaxKey, MinKey]"
|
]
|
}
|
}
|
},
|
{
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1,
|
"score" : 1,
|
"last_updated_at" : 1,
|
"deleted" : 1
|
},
|
"indexName" : "feed_id_1_score_1_last_updated_at_1_deleted_1",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"score" : [ ],
|
"last_updated_at" : [ ],
|
"deleted" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"score" : [
|
"[MinKey, MaxKey]"
|
],
|
"last_updated_at" : [
|
"[MinKey, MaxKey]"
|
],
|
"deleted" : [
|
"[MinKey, true)",
|
"(true, MaxKey]"
|
]
|
}
|
}
|
},
|
{
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
},
|
{
|
"$nor" : [
|
{
|
"deleted" : {
|
"$eq" : true
|
}
|
}
|
]
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1,
|
"timestamps.cluster_timestamps.created" : 1
|
},
|
"indexName" : "feed_id_1_timestamps.cluster_timestamps.created_1",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"timestamps.cluster_timestamps.created" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"timestamps.cluster_timestamps.created" : [
|
"[MinKey, MaxKey]"
|
]
|
}
|
}
|
},
|
{
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$lte" : ISODate("2018-07-16T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.article_timestamps.first_article_published" : {
|
"$gte" : ISODate("2018-07-15T15:29:50.084Z")
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
}
|
]
|
},
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"keyPattern" : {
|
"feed_id" : 1,
|
"score" : -1,
|
"timestamps.article_timestamps.latest_article_published" : 1,
|
"deleted" : 1
|
},
|
"indexName" : "feed_id_1_score_-1_timestamps.article_timestamps.latest_article_published_1_deleted_1",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"score" : [ ],
|
"timestamps.article_timestamps.latest_article_published" : [ ],
|
"deleted" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"score" : [
|
"[MaxKey, MinKey]"
|
],
|
"timestamps.article_timestamps.latest_article_published" : [
|
"[MinKey, MaxKey]"
|
],
|
"deleted" : [
|
"[MinKey, true)",
|
"(true, MaxKey]"
|
]
|
}
|
}
|
}
|
]
|
},
|
"executionStats" : {
|
"executionSuccess" : true,
|
"nReturned" : 0,
|
"executionTimeMillis" : 77,
|
"totalKeysExamined" : 1,
|
"totalDocsExamined" : 0,
|
"executionStages" : {
|
"stage" : "FETCH",
|
"filter" : {
|
"$and" : [
|
{
|
"score" : {
|
"$exists" : true
|
}
|
},
|
{
|
"timestamps.cluster_timestamps.summary_last_updated" : {
|
"$exists" : true
|
}
|
}
|
]
|
},
|
"nReturned" : 0,
|
"executionTimeMillisEstimate" : 0,
|
"works" : 2,
|
"advanced" : 0,
|
"needTime" : 0,
|
"needYield" : 0,
|
"saveState" : 4,
|
"restoreState" : 4,
|
"isEOF" : 1,
|
"invalidates" : 0,
|
"docsExamined" : 0,
|
"alreadyHasObj" : 0,
|
"inputStage" : {
|
"stage" : "IXSCAN",
|
"nReturned" : 0,
|
"executionTimeMillisEstimate" : 0,
|
"works" : 1,
|
"advanced" : 0,
|
"needTime" : 0,
|
"needYield" : 0,
|
"saveState" : 4,
|
"restoreState" : 4,
|
"isEOF" : 1,
|
"invalidates" : 0,
|
"keyPattern" : {
|
"feed_id" : 1,
|
"timestamps.article_timestamps.first_article_published" : 1,
|
"score" : -1,
|
"timestamps.cluster_timestamps.summary_last_updated" : 1,
|
"deleted" : 1
|
},
|
"indexName" : "feed_id.first_article_published.score-1.summary_last_updated.deleted",
|
"isMultiKey" : false,
|
"multiKeyPaths" : {
|
"feed_id" : [ ],
|
"timestamps.article_timestamps.first_article_published" : [ ],
|
"score" : [ ],
|
"timestamps.cluster_timestamps.summary_last_updated" : [ ],
|
"deleted" : [ ]
|
},
|
"isUnique" : false,
|
"isSparse" : false,
|
"isPartial" : false,
|
"indexVersion" : 2,
|
"direction" : "forward",
|
"indexBounds" : {
|
"feed_id" : [
|
"[\"abcdefg\", \"abcdefg\"]"
|
],
|
"timestamps.article_timestamps.first_article_published" : [
|
"[new Date(1531668590084), new Date(1531754990084)]"
|
],
|
"score" : [
|
"[MaxKey, MinKey]"
|
],
|
"timestamps.cluster_timestamps.summary_last_updated" : [
|
"[MinKey, MaxKey]"
|
],
|
"deleted" : [
|
"[MinKey, true)",
|
"(true, MaxKey]"
|
]
|
},
|
"keysExamined" : 1,
|
"seeks" : 1,
|
"dupsTested" : 0,
|
"dupsDropped" : 0,
|
"seenInvalidated" : 0
|
}
|
}
|
},
|
"serverInfo" : {
|
"host" : "shr0-production-database-1",
|
"port" : 27017,
|
"version" : "3.6.5",
|
"gitVersion" : "a20ecd3e3a174162052ff99913bc2ca9a839d618"
|
},
|
"ok" : 1,
|
"operationTime" : Timestamp(1531755534, 164),
|
"$gleStats" : {
|
"lastOpTime" : Timestamp(0, 0),
|
"electionId" : ObjectId("7fffffff00000000000000f9")
|
},
|
"$clusterTime" : {
|
"clusterTime" : Timestamp(1531755534, 164),
|
"signature" : {
|
"hash" : BinData(0,"2lW4vZhth5rPF7u+DqcD0rS2dxQ="),
|
"keyId" : NumberLong("6526359001347653635")
|
}
|
},
|
"$configServerState" : {
|
"opTime" : {
|
"ts" : Timestamp(1531755530, 3),
|
"t" : NumberLong(28)
|
}
|
}
|
}
|
The actual mongodb log looks like this
2018-07-16T15:44:11.094+0000 I COMMAND [conn1269086] command production.clusters command: find { find: "clusters", filter: { deleted: { $ne: true }, timestamps.cluster_timestamps.summary_last_updated: { $exists: true }, feed_id: "abcdefg", timestamps.article_timestamps.first_article_published: { $lte: new Date(1531755822402), $gte: new Date(1531669422402) }, score: { $exists: true } }, projection: { $sortKey: { $meta: "sortKey" } }, sort: { score: -1 }, limit: 25, shardVersion: [ Timestamp(0, 0), ObjectId('000000000000000000000000') ], $readPreference: { mode: "secondaryPreferred" }, $clusterTime: { clusterTime: Timestamp(1531755822, 9), signature: { hash: BinData(0, 9F6CEB16789530637DD0912EA461E8BC988491F5), keyId: 6526359001347653635 } }, $configServerState: { opTime: { ts: Timestamp(1531755821, 6), t: 28 } }, $db: "production" } planSummary: IXSCAN { feed_id: 1, score: -1, timestamps.cluster_timestamps.last_updated: -1, deleted: 1 } keysExamined:68069 docsExamined:68068 cursorExhausted:1 numYields:1392 nreturned:0 reslen:338 locks:{ Global: { acquireCount: { r: 2786 }, acquireWaitCount: { r: 154 }, timeAcquiringMicros: { r: 750763 } }, Database: { acquireCount: { r: 1393 } }, Collection: { acquireCount: { r: 1393 } } } protocol:op_msg 28161ms
|
You can clearly see that the index actually used by Mongo
{ feed_id: 1, score: -1, timestamps.cluster_timestamps.last_updated: -1, deleted: 1 }
|
doesn't match the winningPlan above
"keyPattern" : { "feed_id" : 1, "timestamps.article_timestamps.first_article_published" : 1, "score" : -1, "timestamps.cluster_timestamps.summary_last_updated" : 1, "deleted" : 1 }, "indexName" : "feed_id.first_article_published.score-1.summary_last_updated.deleted",
|
Also, tried checking cache for plans but it came back empty.
production-database> db.runCommand({planCacheListPlans: 'clusters',query: {find: { deleted: { $ne: true }, "timestamps.cluster_timestamps.summary_last_updated": { $exists: true }, feed_id: "abcdefg", "timestamps.article_timestamps.first_article_published": { $lte: new Date(1531754990084), $gte: new Date(1531668590084) }, score: { $exists: true } },sort: {score: -1}}})
|
{ "plans" : [ ], "ok" : 1, "operationTime" : Timestamp(1531757237, 4), "$gleStats" : { "lastOpTime" : Timestamp(0, 0), "electionId" : ObjectId("000000000000000000000000") }, "$clusterTime" : { "clusterTime" : Timestamp(1531757237, 6), "signature" : { "hash" : BinData(0,"fCM7jQjOEXae3ZanDbYq2YXo0bM="), "keyId" : NumberLong("6526359001347653635") } }, "$configServerState" : { "opTime" : { "ts" : Timestamp(1531757232, 43), "t" : NumberLong(28) } } }
|
|