|
While looking at the QLOG output, I noticed that one of the solutions doesn't have the KEEP_MUTATIONS stage. It seems erroneous, as the code in planner_analysis.cpp doesn't imply any obvious exception for this index.
> db.contact.insert({_id:10,oId:100})
|
WriteResult({ "nInserted" : 1 })
|
> db.contact.insert({_id:11,oId:1234})
|
WriteResult({ "nInserted" : 1 })
|
> db.contact.insert({_id:12,oId:1234})
|
WriteResult({ "nInserted" : 1 })
|
> db.contact.insert({_id:13,oId:100})
|
WriteResult({ "nInserted" : 1 })
|
> db.contact.ensureIndex({ organizationId: 1.0, externalId: 1.0, _id: 1.0 })
|
{
|
"createdCollectionAutomatically" : false,
|
"numIndexesBefore" : 1,
|
"numIndexesAfter" : 2,
|
"ok" : 1
|
}
|
> db.adminCommand({setParameter: 1, verboseQueryLogging: true})
|
{ "was" : false, "ok" : 1 }
|
> db.contact.find({ _id: { $in: [ 11 ] }, organizationId: { $ne: 100 } } )
|
{ "_id" : 11, "oId" : 1234 }
|
QLOG output:
2014-11-04T20:35:25.843-0500 [conn3] build index on: test.contact properties: { v: 1, key: { organizationId: 1.0, externalId: 1.0, _id: 1.0 }, name: "organizationId_1_externalId_1__id_1", ns: "test.contact" }
|
2014-11-04T20:35:25.845-0500 [conn3] building index using bulk method
|
2014-11-04T20:35:25.846-0500 [conn3] build index done. scanned 4 total records. 0.003 secs
|
2014-11-04T20:36:37.769-0500 [clientcursormon] mem (MB) res:10 virt:2826
|
2014-11-04T20:36:37.769-0500 [clientcursormon] mapped (incl journal view):320
|
2014-11-04T20:36:37.769-0500 [clientcursormon] connections:1
|
2014-11-04T20:37:01.897-0500 [conn3] [QLOG] Running query:
|
ns=test.contact limit=0 skip=0
|
Tree: $and
|
$not
|
organizationId == 100.0
|
_id $in [ 11.0 ]
|
Sort: {}
|
Proj: {}
|
2014-11-04T20:37:01.897-0500 [conn3] [QLOG] Beginning planning...
|
=============================
|
Options = INDEX_INTERSECTION KEEP_MUTATIONS
|
Canonical query:
|
ns=test.contact limit=0 skip=0
|
Tree: $and
|
$not
|
organizationId == 100.0
|
_id $in [ 11.0 ]
|
Sort: {}
|
Proj: {}
|
=============================
|
2014-11-04T20:37:01.898-0500 [conn3] [QLOG] Index 0 is kp: { _id: 1 } io: { v: 1, key: { _id: 1 }, name: "_id_", ns: "test.contact" }
|
2014-11-04T20:37:01.898-0500 [conn3] [QLOG] Index 1 is kp: { organizationId: 1.0, externalId: 1.0, _id: 1.0 } io: { v: 1, key: { organizationId: 1.0, externalId: 1.0, _id: 1.0 }, name: "organizationId_1_externalId_1__id_1", ns: "test.contact" }
|
2014-11-04T20:37:01.898-0500 [conn3] [QLOG] Predicate over field 'organizationId'
|
2014-11-04T20:37:01.898-0500 [conn3] [QLOG] Predicate over field '_id'
|
2014-11-04T20:37:01.898-0500 [conn3] [QLOG] Relevant index 0 is kp: { _id: 1 } io: { v: 1, key: { _id: 1 }, name: "_id_", ns: "test.contact" }
|
2014-11-04T20:37:01.898-0500 [conn3] [QLOG] Relevant index 1 is kp: { organizationId: 1.0, externalId: 1.0, _id: 1.0 } io: { v: 1, key: { organizationId: 1.0, externalId: 1.0, _id: 1.0 }, name: "organizationId_1_externalId_1__id_1", ns: "test.contact" }
|
2014-11-04T20:37:01.899-0500 [conn3] [QLOG] Rated tree:
|
$and
|
$not
|
organizationId == 100.0 || First: 1 notFirst: full path: organizationId
|
_id $in [ 11.0 ] || First: 0 notFirst: 1 full path: _id
|
2014-11-04T20:37:01.899-0500 [conn3] [QLOG] Tagging memoID 1
|
2014-11-04T20:37:01.899-0500 [conn3] [QLOG] Enumerator: memo just before moving:
|
2014-11-04T20:37:01.899-0500 [conn3] [QLOG] About to build solntree from tagged tree:
|
$and
|
_id $in [ 11.0 ] || Selected Index #0 pos 0
|
$not
|
organizationId == 100.0
|
2014-11-04T20:37:01.899-0500 [conn3] [QLOG] Planner: adding solution:
|
KEEP_MUTATIONS
|
---filter:
|
$and
|
$not
|
organizationId == 100.0
|
_id $in [ 11.0 ]
|
---fetched = 1
|
---sortedByDiskLoc = 0
|
---getSort = []
|
---Child:
|
------FETCH
|
---------filter:
|
$not
|
organizationId == 100.0
|
---------fetched = 1
|
---------sortedByDiskLoc = 1
|
---------getSort = [{ _id: 1 }, ]
|
---------Child:
|
------------IXSCAN
|
---------------keyPattern = { _id: 1 }
|
---------------direction = 1
|
---------------bounds = field #0['_id']: [11.0, 11.0]
|
---------------fetched = 0
|
---------------sortedByDiskLoc = 1
|
---------------getSort = [{ _id: 1 }, ]
|
2014-11-04T20:37:01.900-0500 [conn3] [QLOG] Tagging memoID 1
|
2014-11-04T20:37:01.900-0500 [conn3] [QLOG] Enumerator: memo just before moving:
|
2014-11-04T20:37:01.900-0500 [conn3] [QLOG] About to build solntree from tagged tree:
|
$and
|
$not
|
organizationId == 100.0 || Selected Index #1 pos 0
|
_id $in [ 11.0 ] || Selected Index #1 pos 2
|
2014-11-04T20:37:01.900-0500 [conn3] [QLOG] Planner: adding solution:
|
FETCH
|
---fetched = 1
|
---sortedByDiskLoc = 0
|
---getSort = [{ organizationId: 1 }, { organizationId: 1, externalId: 1 }, { organizationId: 1, externalId: 1, _id: 1 }, ]
|
---Child:
|
------IXSCAN
|
---------keyPattern = { organizationId: 1.0, externalId: 1.0, _id: 1.0 }
|
---------direction = 1
|
---------bounds = field #0['organizationId']: [MinKey, 100.0), (100.0, MaxKey], field #1['externalId']: [MinKey, MaxKey], field #2['_id']: [11.0, 11.0]
|
---------fetched = 0
|
---------sortedByDiskLoc = 0
|
---------getSort = [{ organizationId: 1 }, { organizationId: 1, externalId: 1 }, { organizationId: 1, externalId: 1, _id: 1 }, ]
|
2014-11-04T20:37:01.900-0500 [conn3] [QLOG] Planner: outputted 2 indexed solutions.
|
2014-11-04T20:37:01.901-0500 [conn3] [QLOG] Scoring plan 0:
|
KEEP_MUTATIONS
|
---filter:
|
$and
|
$not
|
organizationId == 100.0
|
_id $in [ 11.0 ]
|
---fetched = 1
|
---sortedByDiskLoc = 0
|
---getSort = []
|
---Child:
|
------FETCH
|
---------filter:
|
$not
|
organizationId == 100.0
|
---------fetched = 1
|
---------sortedByDiskLoc = 1
|
---------getSort = [{ _id: 1 }, ]
|
---------Child:
|
------------IXSCAN
|
---------------keyPattern = { _id: 1 }
|
---------------direction = 1
|
---------------bounds = field #0['_id']: [11.0, 11.0]
|
---------------fetched = 0
|
---------------sortedByDiskLoc = 1
|
---------------getSort = [{ _id: 1 }, ]
|
Stats:
|
{ "type" : "KEEP_MUTATIONS",
|
"works" : 2,
|
"yields" : 0,
|
"unyields" : 0,
|
"invalidates" : 0,
|
"advanced" : 1,
|
"needTime" : 0,
|
"needFetch" : 0,
|
"isEOF" : 1,
|
"children" : [
|
{ "type" : "FETCH",
|
"works" : 2,
|
"yields" : 0,
|
"unyields" : 0,
|
"invalidates" : 0,
|
"advanced" : 1,
|
"needTime" : 0,
|
"needFetch" : 0,
|
"isEOF" : 1,
|
"alreadyHasObj" : 0,
|
"forcedFetches" : 0,
|
"matchTested" : 1,
|
"children" : [
|
{ "type" : "IXSCAN",
|
"works" : 2,
|
"yields" : 0,
|
"unyields" : 0,
|
"invalidates" : 0,
|
"advanced" : 1,
|
"needTime" : 0,
|
"needFetch" : 0,
|
"isEOF" : 1,
|
"keyPattern" : "{ _id: 1 }",
|
"isMultiKey" : 0,
|
"boundsVerbose" : "field #0['_id']: [11.0, 11.0]",
|
"yieldMovedCursor" : 0,
|
"dupsTested" : 0,
|
"dupsDropped" : 0,
|
"seenInvalidated" : 0,
|
"matchTested" : 0,
|
"keysExamined" : 1,
|
"children" : [] } ] } ] }
|
2014-11-04T20:37:01.901-0500 [conn3] [QLOG] score(1.5003) = baseScore(1) + productivity((1 advanced)/(2 works + 0 needFetch) = 0.5) + tieBreakers(0.0001 noFetchBonus + 0.0001 noSortBonus + 0.0001 noIxisectBonus = 0.0003)
|
2014-11-04T20:37:01.901-0500 [conn3] [QLOG] score = 1.5003
|
2014-11-04T20:37:01.901-0500 [conn3] [QLOG] Adding +1 EOF bonus to score.
|
2014-11-04T20:37:01.902-0500 [conn3] [QLOG] Scoring plan 1:
|
FETCH
|
---fetched = 1
|
---sortedByDiskLoc = 0
|
---getSort = [{ organizationId: 1 }, { organizationId: 1, externalId: 1 }, { organizationId: 1, externalId: 1, _id: 1 }, ]
|
---Child:
|
------IXSCAN
|
---------keyPattern = { organizationId: 1.0, externalId: 1.0, _id: 1.0 }
|
---------direction = 1
|
---------bounds = field #0['organizationId']: [MinKey, 100.0), (100.0, MaxKey], field #1['externalId']: [MinKey, MaxKey], field #2['_id']: [11.0, 11.0]
|
---------fetched = 0
|
---------sortedByDiskLoc = 0
|
---------getSort = [{ organizationId: 1 }, { organizationId: 1, externalId: 1 }, { organizationId: 1, externalId: 1, _id: 1 }, ]
|
Stats:
|
{ "type" : "FETCH",
|
"works" : 2,
|
"yields" : 0,
|
"unyields" : 0,
|
"invalidates" : 0,
|
"advanced" : 1,
|
"needTime" : 1,
|
"needFetch" : 0,
|
"isEOF" : 0,
|
"alreadyHasObj" : 0,
|
"forcedFetches" : 0,
|
"matchTested" : 0,
|
"children" : [
|
{ "type" : "IXSCAN",
|
"works" : 2,
|
"yields" : 0,
|
"unyields" : 0,
|
"invalidates" : 0,
|
"advanced" : 1,
|
"needTime" : 1,
|
"needFetch" : 0,
|
"isEOF" : 0,
|
"keyPattern" : "{ organizationId: 1.0, externalId: 1.0, _id: 1.0 }",
|
"isMultiKey" : 0,
|
"boundsVerbose" : "field #0['organizationId']: [MinKey, 100.0), (100.0, MaxKey], field #1['externalId']: [MinKey, MaxKey], field #2['_id']: [11.0, 11.0]",
|
"yieldMovedCursor" : 0,
|
"dupsTested" : 0,
|
"dupsDropped" : 0,
|
"seenInvalidated" : 0,
|
"matchTested" : 0,
|
"keysExamined" : 2,
|
"children" : [] } ] }
|
2014-11-04T20:37:01.902-0500 [conn3] [QLOG] score(1.5003) = baseScore(1) + productivity((1 advanced)/(2 works + 0 needFetch) = 0.5) + tieBreakers(0.0001 noFetchBonus + 0.0001 noSortBonus + 0.0001 noIxisectBonus = 0.0003)
|
2014-11-04T20:37:01.902-0500 [conn3] [QLOG] score = 1.5003
|
2014-11-04T20:37:01.902-0500 [conn3] [QLOG] Winning solution:
|
KEEP_MUTATIONS
|
---filter:
|
$and
|
$not
|
organizationId == 100.0
|
_id $in [ 11.0 ]
|
---fetched = 1
|
---sortedByDiskLoc = 0
|
---getSort = []
|
---Child:
|
------FETCH
|
---------filter:
|
$not
|
organizationId == 100.0
|
---------fetched = 1
|
---------sortedByDiskLoc = 1
|
---------getSort = [{ _id: 1 }, ]
|
---------Child:
|
------------IXSCAN
|
---------------keyPattern = { _id: 1 }
|
---------------direction = 1
|
---------------bounds = field #0['_id']: [11.0, 11.0]
|
---------------fetched = 0
|
---------------sortedByDiskLoc = 1
|
---------------getSort = [{ _id: 1 }, ]
|
|
2014-11-04T20:37:01.902-0500 [conn3] [QLOG] Not caching runner but returning 1 results.
|
|