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

Detailed explain does not list rejected plans

    • Type: Icon: Bug Bug
    • Resolution: Duplicate
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 2.7.1, 2.7.2, 2.7.3
    • Component/s: Querying
    • ALL
    • Hide
      db.getSiblingDB("admin").runCommand( { setParameter: 1, logLevel: 3 } )
      db.foo.ensureIndex({a: 1})
      db.foo.ensureIndex({b: 1})
      db.foo.insert({a: 1, b: 3})
      db.foo.insert({a: 2, b: 5})
      db.foo.insert({a: 3, b: 7})
      db.foo.find({a: {$gt: 2}, b: {$gt: 3}}).explain(true)
      

      Result produced:

      {
      	"cursor" : "BtreeCursor a_1",
      	"isMultiKey" : false,
      	"n" : 1,
      	"nscannedObjects" : 1,
      	"nscanned" : 1,
      	"nscannedObjectsAllPlans" : 1,
      	"nscannedAllPlans" : 1,
      	"scanAndOrder" : false,
      	"indexOnly" : false,
      	"nYields" : 0,
      	"nChunkSkips" : 0,
      	"millis" : 0,
      	"indexBounds" : {
      		"a" : [
      			[
      				2,
      				Infinity
      			]
      		]
      	},
      	"allPlans" : [
      		{
      			"cursor" : "BtreeCursor a_1",
      			"isMultiKey" : false,
      			"n" : 1,
      			"nscannedObjects" : 1,
      			"nscanned" : 1,
      			"scanAndOrder" : false,
      			"indexOnly" : false,
      			"nChunkSkips" : 0,
      			"indexBounds" : {
      				"a" : [
      					[
      						2,
      						Infinity
      					]
      				]
      			}
      		}
      	],
      	"server" : "Jonathans-MacBook-Pro.local:27017",
      	"filterSet" : false,
      	"stats" : {
      		"type" : "KEEP_MUTATIONS",
      		"works" : 3,
      		"yields" : 0,
      		"unyields" : 0,
      		"invalidates" : 0,
      		"advanced" : 1,
      		"needTime" : 0,
      		"isEOF" : 1,
      		"children" : [
      			{
      				"type" : "FETCH",
      				"works" : 2,
      				"yields" : 0,
      				"unyields" : 0,
      				"invalidates" : 0,
      				"advanced" : 1,
      				"needTime" : 0,
      				"isEOF" : 1,
      				"alreadyHasObj" : 0,
      				"forcedFetches" : 0,
      				"matchTested" : 1,
      				"children" : [
      					{
      						"type" : "IXSCAN",
      						"works" : 1,
      						"yields" : 0,
      						"unyields" : 0,
      						"invalidates" : 0,
      						"advanced" : 1,
      						"needTime" : 0,
      						"isEOF" : 1,
      						"keyPattern" : "{ a: 1.0 }",
      						"isMultiKey" : 0,
      						"boundsVerbose" : "field #0['a']: (2.0, inf.0]",
      						"yieldMovedCursor" : 0,
      						"dupsTested" : 0,
      						"dupsDropped" : 0,
      						"seenInvalidated" : 0,
      						"matchTested" : 0,
      						"keysExamined" : 1,
      						"children" : [ ]
      					}
      				]
      			}
      		]
      	}
      }
      

      Observed in mongod log:

      2014-07-18T10:27:58.768-0400 [conn1] Running query: query: { a: { $gt: 2.0 }, b: { $gt: 3.0 } } sort: {} projection: {}
      2014-07-18T10:27:58.768-0400 [conn1] Relevant index 0 is kp: { a: 1.0 } io: { v: 1, key: { a: 1.0 }, name: "a_1", ns: "test.foo" }
      2014-07-18T10:27:58.768-0400 [conn1] Relevant index 1 is kp: { b: 1.0 } io: { v: 1, key: { b: 1.0 }, name: "b_1", ns: "test.foo" }
      2014-07-18T10:27:58.768-0400 [conn1] Scoring query plan: IXSCAN { a: 1.0 } planHitEOF=1
      2014-07-18T10:27:58.769-0400 [conn1] score(1.5003) = baseScore(1) + productivity((1 advanced)/(2 works) = 0.5) + tieBreakers(0.0001 noFetchBonus + 0.0001 noSortBonus + 0.0001 noIxisectBonus = 0.0003)
      2014-07-18T10:27:58.769-0400 [conn1] Scoring query plan: IXSCAN { b: 1.0 } planHitEOF=0
      2014-07-18T10:27:58.769-0400 [conn1] score(1.5003) = baseScore(1) + productivity((1 advanced)/(2 works) = 0.5) + tieBreakers(0.0001 noFetchBonus + 0.0001 noSortBonus + 0.0001 noIxisectBonus = 0.0003)
      2014-07-18T10:27:58.769-0400 [conn1] Scoring query plan: IXSCAN { a: 1.0 }, IXSCAN { b: 1.0 } planHitEOF=0
      2014-07-18T10:27:58.769-0400 [conn1] score(1.0002) = baseScore(1) + productivity((0 advanced)/(2 works) = 0) + tieBreakers(0.0001 noFetchBonus + 0.0001 noSortBonus + 0 noIxisectBonus = 0.0002)
      2014-07-18T10:27:58.769-0400 [conn1] Winning plan: IXSCAN { a: 1.0 }
      2014-07-18T10:27:58.769-0400 [conn1] query test.foo query: { query: { a: { $gt: 2.0 }, b: { $gt: 3.0 } }, $explain: true } planSummary: IXSCAN { a: 1.0 } ntoreturn:0 ntoskip:0 nscanned:1 nscannedObjects:1 keyUpdates:0 numYields:0 locks(micros) r:789 nreturned:1 reslen:1214 0ms
      
      Show
      db.getSiblingDB( "admin" ).runCommand( { setParameter: 1, logLevel: 3 } ) db.foo.ensureIndex({a: 1}) db.foo.ensureIndex({b: 1}) db.foo.insert({a: 1, b: 3}) db.foo.insert({a: 2, b: 5}) db.foo.insert({a: 3, b: 7}) db.foo.find({a: {$gt: 2}, b: {$gt: 3}}).explain( true ) Result produced: { "cursor" : "BtreeCursor a_1", "isMultiKey" : false, "n" : 1, "nscannedObjects" : 1, "nscanned" : 1, "nscannedObjectsAllPlans" : 1, "nscannedAllPlans" : 1, "scanAndOrder" : false, "indexOnly" : false, "nYields" : 0, "nChunkSkips" : 0, "millis" : 0, "indexBounds" : { "a" : [ [ 2, Infinity ] ] }, "allPlans" : [ { "cursor" : "BtreeCursor a_1", "isMultiKey" : false, "n" : 1, "nscannedObjects" : 1, "nscanned" : 1, "scanAndOrder" : false, "indexOnly" : false, "nChunkSkips" : 0, "indexBounds" : { "a" : [ [ 2, Infinity ] ] } } ], "server" : "Jonathans-MacBook-Pro.local:27017", "filterSet" : false, "stats" : { "type" : "KEEP_MUTATIONS", "works" : 3, "yields" : 0, "unyields" : 0, "invalidates" : 0, "advanced" : 1, "needTime" : 0, "isEOF" : 1, "children" : [ { "type" : "FETCH", "works" : 2, "yields" : 0, "unyields" : 0, "invalidates" : 0, "advanced" : 1, "needTime" : 0, "isEOF" : 1, "alreadyHasObj" : 0, "forcedFetches" : 0, "matchTested" : 1, "children" : [ { "type" : "IXSCAN", "works" : 1, "yields" : 0, "unyields" : 0, "invalidates" : 0, "advanced" : 1, "needTime" : 0, "isEOF" : 1, "keyPattern" : "{ a: 1.0 }", "isMultiKey" : 0, "boundsVerbose" : "field #0['a']: (2.0, inf.0]", "yieldMovedCursor" : 0, "dupsTested" : 0, "dupsDropped" : 0, "seenInvalidated" : 0, "matchTested" : 0, "keysExamined" : 1, "children" : [ ] } ] } ] } } Observed in mongod log: 2014-07-18T10:27:58.768-0400 [conn1] Running query: query: { a: { $gt: 2.0 }, b: { $gt: 3.0 } } sort: {} projection: {} 2014-07-18T10:27:58.768-0400 [conn1] Relevant index 0 is kp: { a: 1.0 } io: { v: 1, key: { a: 1.0 }, name: "a_1", ns: "test.foo" } 2014-07-18T10:27:58.768-0400 [conn1] Relevant index 1 is kp: { b: 1.0 } io: { v: 1, key: { b: 1.0 }, name: "b_1", ns: "test.foo" } 2014-07-18T10:27:58.768-0400 [conn1] Scoring query plan: IXSCAN { a: 1.0 } planHitEOF=1 2014-07-18T10:27:58.769-0400 [conn1] score(1.5003) = baseScore(1) + productivity((1 advanced)/(2 works) = 0.5) + tieBreakers(0.0001 noFetchBonus + 0.0001 noSortBonus + 0.0001 noIxisectBonus = 0.0003) 2014-07-18T10:27:58.769-0400 [conn1] Scoring query plan: IXSCAN { b: 1.0 } planHitEOF=0 2014-07-18T10:27:58.769-0400 [conn1] score(1.5003) = baseScore(1) + productivity((1 advanced)/(2 works) = 0.5) + tieBreakers(0.0001 noFetchBonus + 0.0001 noSortBonus + 0.0001 noIxisectBonus = 0.0003) 2014-07-18T10:27:58.769-0400 [conn1] Scoring query plan: IXSCAN { a: 1.0 }, IXSCAN { b: 1.0 } planHitEOF=0 2014-07-18T10:27:58.769-0400 [conn1] score(1.0002) = baseScore(1) + productivity((0 advanced)/(2 works) = 0) + tieBreakers(0.0001 noFetchBonus + 0.0001 noSortBonus + 0 noIxisectBonus = 0.0002) 2014-07-18T10:27:58.769-0400 [conn1] Winning plan: IXSCAN { a: 1.0 } 2014-07-18T10:27:58.769-0400 [conn1] query test.foo query: { query: { a: { $gt: 2.0 }, b: { $gt: 3.0 } }, $explain: true } planSummary: IXSCAN { a: 1.0 } ntoreturn:0 ntoskip:0 nscanned:1 nscannedObjects:1 keyUpdates:0 numYields:0 locks(micros) r:789 nreturned:1 reslen:1214 0ms

      A query with explain(true) should list all considered plans. It is only showing the winning plan.

            Assignee:
            Unassigned Unassigned
            Reporter:
            jonathan.abrahams Jonathan Abrahams
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: