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
- related to
-
SERVER-17364 Idle cursors shouldn't hold storage engine resources
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-