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

Plan summary string in slow query log is wrong if fell back to a non-blocking solution

XMLWordPrintableJSON

    • Query
    • ALL

      The plan summary string is produced before or soon after newRunQuery(...) begins to a run a plan. However, the plan being used may change halfway through query execution. Specifically, if a blocking plan hits its memory limit, then we fall back on a non-blocking solution (the backup solution), but the slow query line will still contain the plan summary for the blocking plan.

      The following script will repro:

      var t = db.stale_plan_summary;
t.drop();

// Slow query lines get logged at logLevel 1.
db.adminCommand({setParameter: 1, logLevel: 1});

var big = new Array( 1000000 ).toString()
t.save( {b:0} );
for(var i = 0; i < 40; ++i) {
    t.save( {a:0,x:big} );
}

t.ensureIndex({a: 1});
t.ensureIndex({b: 1});

// Uses a blocking plan to sort on 'a'.
t.find( {b: 0} ).sort( {a: 1} ).itcount();

// Insert lots of data so that the next invocation of the blocking
// plan will run out of memory.
for(var i = 0; i < 40; ++i) {
    t.save( {b:0,x:big} );
}

// Falls back on an index scan over 'a', but the slow query log
// still has planSummary: IXSCAN { b: 1.0 }
t.find( {b: 0} ).sort( {a: 1} ).itcount();

            Assignee:
            backlog-server-query Backlog - Query Team (Inactive)
            Reporter:
            david.storch@mongodb.com David Storch
            Votes:
            0 Vote for this issue
            Watchers:
            13 Start watching this issue

              Created:
              Updated:
              Resolved: