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

planSummary field incorrect when backup plan is used

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Investigating
    • Priority: Major - P3
    • Resolution: Unresolved
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: None
    • Labels:
      None
    • Operating System:
      ALL
    • Sprint:
      Query Execution 2021-03-22, Query Execution 2021-04-05, Query Execution 2021-04-19, Query Execution 2021-05-03
    • Case:

      Description

      Consider the following result from planning a query (on 4.2.11):

      2021-01-19T15:23:11.369-0600 D2 QUERY    [conn3] Winning plan: IXSCAN { field: 1 }
      2021-01-19T15:23:11.370-0600 D5 QUERY    [conn3] Winner has blocking stage, looking for backup plan...
      2021-01-19T15:23:11.371-0600 D5 QUERY    [conn3] Candidate 1 is backup child
       
      2021-01-19T15:23:11.373-0600 D5 QUERY    [conn3] Best plan errored out switching to backup

      The (standard verbosity) log entry recorded at the conclusion of the operation is:

      2021-01-19T15:23:13.459-0600 I  COMMAND  [conn3] command test.foo appName: "MongoDB Shell" command: find { find: "foo", filter: { field: 123.0 }, skip: 40000.0, limit: 10.0, singleBatch: false, sort: { _id: 1.0 }, lsid: { id: UUID("7e16439f-e7b6-4c0f-a615-3185d1a06143") }, $db: "test" } planSummary: IXSCAN { field: 1 } keysExamined:1040009 docsExamined:1040009 fromMultiPlanner:1 cursorExhausted:1 numYields:8369 nreturned:10 queryHash:62C53BBA planCacheKey:72D6FFD0 reslen:10807 locks:{ ReplicationStateTransition: { acquireCount: { w: 8370 } }, Global: { acquireCount: { r: 8370 } }, Database: { acquireCount: { r: 8370 } }, Collection: { acquireCount: { r: 8370 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 3367ms

      Note here that the winning plan from the selection process was the one that used the { field: 1 } index.  That plan ended up failing (as it exceeded the sort memory threshold) which resulted in the database switching to using the backup plan (a scan of the { _id: 1 } index to support the sort in a non-blocking manner).  The final log entry reports the winning plan from the selection process as the planSummary but the database actually ended up using a different index/plan for the successful execution of the operation.  

      The log entry should reflect the plan that was ultimately used (similar to what is normally done for replanned entries currently).  Indication that it was a backup plan was used may also be helpful.  

        Attachments

          Activity

            People

            Assignee:
            bernard.gorman Bernard Gorman
            Reporter:
            christopher.harris Christopher Harris
            Participants:
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Dates

              Created:
              Updated: