Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-15962

Planner should only add KEEP_MUTATIONS for plans that might flag invalidated results

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 3.3.1
    • Affects Version/s: None
    • Component/s: Querying
    • None
    • Fully Compatible
    • ALL
    • Query F (02/01/16)

      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.
      

            Assignee:
            david.storch@mongodb.com David Storch
            Reporter:
            alex.komyagin@mongodb.com Alexander Komyagin (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: