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

Explain helpers report incorrect plan summary and summary statistics when multiple candidate plans generated

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major - P3
    • Resolution: Fixed
    • Affects Version/s: 3.1.6
    • Fix Version/s: 3.2.0-rc0
    • Component/s: Querying
    • Labels:
      None
    • Backwards Compatibility:
      Fully Compatible
    • Operating System:
      ALL
    • Sprint:
      Quint 9 09/18/15, QuInt A (10/12/15)

      Description

      Various explain helpers intending to report summary information about winning plan execution will unintentionally traverse the execution trees of rejected plans. As a result, the diagnostic log (among other consumers of this information) will report an incorrect plan summary and incorrect summary statistics for queries that generate multiple plans.

      This is a regression introduced in 3.1.6 by c832bc75 (SERVER-17364).

      Reproduce with the following:

      db.foo.drop();
      db.foo.ensureIndex({a:1});
      db.foo.ensureIndex({b:1});
      db.foo.insert({a:1,b:1});
      db.foo.find({a:1,b:1}).itcount();
      

      The following line is generated in the diagnostic log for the itcount() statement. Note the incorrect "plan summary", and incorrect nscanned/nscannedObjects count:

      2015-08-25T12:45:44.708-0400 I QUERY    [conn1] query test.foo query: { a: 1.0, b: 1.0 } planSummary: IXSCAN { b: 1.0 }, IXSCAN { a: 1.0 }, IXSCAN { a: 1.0 }, IXSCAN { b: 1.0 } ntoreturn:0 ntoskip:0 nscanned:4 nscannedObjects:3 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:64 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } 0ms
      

      3.1.5 generates the expected output:

      2015-08-25T12:45:28.593-0400 I QUERY    [conn1] query test.foo query: { a: 1.0, b: 1.0 } planSummary: IXSCAN { b: 1.0 } ntoreturn:0 ntoskip:0 nscanned:1 nscannedObjects:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:1 reslen:64 locks:{ Global: { acquireCount: { r: 2 } }, MMAPV1Journal: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { R: 1 } } } 0ms
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              charlie.swanson Charlie Swanson
              Reporter:
              rassi J Rassi
              Participants:
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: