[SERVER-20111] Explain helpers report incorrect plan summary and summary statistics when multiple candidate plans generated Created: 25/Aug/15  Updated: 01/Feb/16  Resolved: 08/Oct/15

Status: Closed
Project: Core Server
Component/s: Querying
Affects Version/s: 3.1.6
Fix Version/s: 3.2.0-rc0

Type: Bug Priority: Major - P3
Reporter: J Rassi Assignee: Charlie Swanson
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
related to SERVER-17364 Idle cursors shouldn't hold storage e... Closed
related to SERVER-21376 Explain in "queryPlanner" or "executi... Closed
related to SERVER-22425 execStats in system.profile reports w... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Sprint: Quint 9 09/18/15, QuInt A (10/12/15)
Participants:

 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



 Comments   
Comment by Githook User [ 08/Oct/15 ]

Author:

{u'username': u'cswanson310', u'name': u'Charlie Swanson', u'email': u'charlie.swanson@mongodb.com'}

Message: SERVER-20111 Plan summary should only include the winning plan
Branch: master
https://github.com/mongodb/mongo/commit/5aefcdd1e32f411c35c4c3add6e67dcd9ccbee54

Generated at Thu Feb 08 03:53:11 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.