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

Explain "allPlansExecution" section reports "saveState"/"restoreState" counts incorrectly for the rejected plans

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Minor - P4 Minor - P4
    • 3.3.2
    • Affects Version/s: 3.0.7, 3.2.0-rc2
    • Component/s: Querying
    • None
    • Fully Compatible
    • ALL
    • QuInt E (01/11/16), Query F (02/01/16)
    • None
    • 0
    • None
    • None
    • None
    • None
    • None
    • None

      Repro as follows:

      db.c.drop();
      for (var i = 0; i < 10000; ++i) { db.c.insert({_id: i, a: i, b: i}); }
      db.c.ensureIndex({a: 1});
      db.c.ensureIndex({b: 1});
      db.c.find({a: {$gte: 0}, b: {$gte: 0}}).explain('allPlansExecution');
      

      The "allPlansExecution" section of the explain should look something like this:

      		"allPlansExecution" : [
      			{
      				"nReturned" : 101,
      				"executionTimeMillisEstimate" : 10,
      				"totalKeysExamined" : 101,
      				"totalDocsExamined" : 101,
      				"executionStages" : {
      					"stage" : "FETCH",
      					"filter" : {
      						"b" : {
      							"$gte" : 0
      						}
      					},
      					"nReturned" : 101,
      					"executionTimeMillisEstimate" : 10,
      					"works" : 101,
      					"advanced" : 101,
      					"needTime" : 0,
      					"needYield" : 0,
      					"saveState" : 79,
      					"restoreState" : 79,
      					"isEOF" : 0,
      					"invalidates" : 0,
      					"docsExamined" : 101,
      					"alreadyHasObj" : 0,
      					"inputStage" : {
      						"stage" : "IXSCAN",
      						"nReturned" : 101,
      						"executionTimeMillisEstimate" : 0,
      						"works" : 101,
      						"advanced" : 101,
      						"needTime" : 0,
      						"needYield" : 0,
      						"saveState" : 79,
      						"restoreState" : 79,
      						"isEOF" : 0,
      						"invalidates" : 0,
      						"keyPattern" : {
      							"a" : 1
      						},
      						"indexName" : "a_1",
      						"isMultiKey" : false,
      						"isUnique" : false,
      						"isSparse" : false,
      						"isPartial" : false,
      						"indexVersion" : 1,
      						"direction" : "forward",
      						"indexBounds" : {
      							"a" : [
      								"[0.0, inf.0]"
      							]
      						},
      						"keysExamined" : 101,
      						"dupsTested" : 0,
      						"dupsDropped" : 0,
      						"seenInvalidated" : 0
      					}
      				}
      			},
      			{
      				"nReturned" : 101,
      				"executionTimeMillisEstimate" : 0,
      				"totalKeysExamined" : 101,
      				"totalDocsExamined" : 101,
      				"executionStages" : {
      					"stage" : "FETCH",
      					"filter" : {
      						"a" : {
      							"$gte" : 0
      						}
      					},
      					"nReturned" : 101,
      					"executionTimeMillisEstimate" : 0,
      					"works" : 101,
      					"advanced" : 101,
      					"needTime" : 0,
      					"needYield" : 0,
      					"saveState" : 1,
      					"restoreState" : 1,
      					"isEOF" : 0,
      					"invalidates" : 0,
      					"docsExamined" : 101,
      					"alreadyHasObj" : 0,
      					"inputStage" : {
      						"stage" : "IXSCAN",
      						"nReturned" : 101,
      						"executionTimeMillisEstimate" : 0,
      						"works" : 101,
      						"advanced" : 101,
      						"needTime" : 0,
      						"needYield" : 0,
      						"saveState" : 1,
      						"restoreState" : 1,
      						"isEOF" : 0,
      						"invalidates" : 0,
      						"keyPattern" : {
      							"b" : 1
      						},
      						"indexName" : "b_1",
      						"isMultiKey" : false,
      						"isUnique" : false,
      						"isSparse" : false,
      						"isPartial" : false,
      						"indexVersion" : 1,
      						"direction" : "forward",
      						"indexBounds" : {
      							"b" : [
      								"[0.0, inf.0]"
      							]
      						},
      						"keysExamined" : 101,
      						"dupsTested" : 0,
      						"dupsDropped" : 0,
      						"seenInvalidated" : 0
      					}
      				}
      			}
      		]
      

      Note that the second plan in the "allPlansExecution" array has saveState/restoreState counts of 1, whereas the first plan has saveState/restoreState counts of 79. The value of 79 is incorrect: it counts the number of times that the query yielded during its complete execution. However, this should report only the number of times that the candidate yielded during the plan ranking trial period. Although the rejected plans are saved and restored while the winning plan is executed (after being rejected by the plan ranker), these save/restore pairs should not be reported in the allPlansExecution output.

            Assignee:
            charlie.swanson@mongodb.com Charlie Swanson
            Reporter:
            david.storch@mongodb.com David Storch
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: