[SERVER-12774] "nscanned" not logged anymore for queries Created: 19/Feb/14  Updated: 11/Jul/16  Resolved: 21/Feb/14

Status: Closed
Project: Core Server
Component/s: Logging, Querying
Affects Version/s: None
Fix Version/s: 2.6.0-rc1

Type: Bug Priority: Major - P3
Reporter: Thomas Rueckstiess Assignee: Benety Goh
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File server12774.js    
Issue Links:
Duplicate
is duplicated by SERVER-8912 Metric "document.scanned" is not the ... Closed
Related
Backwards Compatibility: Fully Compatible
Operating System: ALL
Steps To Reproduce:

version : "2.5.6-pre-"
gitVersion : "25c2e4bcb4d25fddf0eb2b214ff9229f26456b89"

Participants:
Linked BF Score: 0

 Description   

Regular collection scans (without index) don't log the "nscanned" value anymore:

2014-02-19T16:01:08.210+1100 [conn15] query test.mgendata query: { class: "something" } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 keyUpdates:0 numYields:7 locks(micros) r:5110987 nreturned:0 reslen:20 2639ms

The same query with .explain() logs the "nscanned" value.

2014-02-19T16:01:13.011+1100 [conn15] query test.mgendata query: { query: { class: "something" }, $explain: true } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:7100000 keyUpdates:0 numYields:5 locks(micros) r:4789802 nreturned:1 reslen:582 2528ms

The "nscanned" value in the log file is important for performance analysis and should always be logged, like in previous versions.



 Comments   
Comment by Githook User [ 26/Feb/14 ]

Author:

{u'username': u'benety', u'name': u'Benety Goh', u'email': u'benety@mongodb.com'}

Message: SERVER-12774 added nscanned and nscannedObjects to slow query log
Branch: master
https://github.com/mongodb/mongo/commit/7766137467a41c02d053d81b65d55349bd865b29

Comment by Githook User [ 22/Feb/14 ]

Author:

{u'username': u'benety', u'name': u'Benety Goh', u'email': u'benety@mongodb.com'}

Message: REVERT 'SERVER-12774 - added nscanned and nscannedObjects to slow query log'
Branch: master
https://github.com/mongodb/mongo/commit/d0135ad0ed90118ad2015283f22b0219c0df3301

Comment by Githook User [ 21/Feb/14 ]

Author:

{u'username': u'benety', u'name': u'Benety Goh', u'email': u'benety@mongodb.com'}

Message: SERVER-12774 added nscannedObjects to OpDebug
Branch: master
https://github.com/mongodb/mongo/commit/d073743e91afaae772385198c7c0819fb40cde20

Comment by Githook User [ 21/Feb/14 ]

Author:

{u'username': u'benety', u'name': u'Benety Goh', u'email': u'benety@mongodb.com'}

Message: SERVER-12774 added nscanned to slow query log
Branch: master
https://github.com/mongodb/mongo/commit/e1fd728336995a52e4b2ef7bf0770fc51586c552

Comment by Benety Goh [ 20/Feb/14 ]

This seems to be an issue in 2.5.5 as well. Can you confirm?

Comment by Thomas Rueckstiess [ 19/Feb/14 ]

Update:

This only affects 2.5.6-pre- (tested on git hash: 25c2e4b). In 2.5.5 the "nscanned" field was still present.

And it also affects indexed queries:

2014-02-20T01:16:01.514+1100 [conn4] query test.mgendata query: { class: "foo" } planSummary: IXSCAN { class: 1.0 } cursorid:25939668101 ntoreturn:0 ntoskip:0 keyUpdates:0 numYields:0 locks(micros) r:1701 nreturned:101 reslen:4666 1ms

Comment by Thomas Rueckstiess [ 19/Feb/14 ]

We used to call it "nscanned" in the log file regardless of indexed or unindexed queries. If we now make a distinction between "nscanned" and "nscannedObjects" that's okay, as long as either one is printed in the query log line. The number is an indication of how much work had to be done, and the ratio between nreturned and nscanned (or nscannedObjects) is an indication on how efficient a query was.

The unindexed query with .explain() prints "nscanned" currently. If "nscannedObjects" is introduced, both cases (with and without explain()) need to print that instead.

Comment by Scott Hernandez (Inactive) [ 19/Feb/14 ]

Thomas, how is the nscanned value import for performance analysis for a query which doesn't use an index?

Do you mean that the "nscannedObjects" would be important but is missing (as well)?

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