[SERVER-9298] When logging slow queries, either log the name of the index used or indicate that it was a table scan Created: 09/Apr/13  Updated: 09/Apr/13  Resolved: 09/Apr/13

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: New Feature Priority: Major - P3
Reporter: Michael O'Brien Assignee: Unassigned
Resolution: Duplicate Votes: 1
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates SERVER-7754 add index/query plan to currentOp and... Closed
Participants:

 Description   

For example, the log message for a slow query might look something like

Sun Apr  7 06:53:36 [conn42787593] query blahblah_production.posts query: { app_id: ObjectId('50d2a13fdf52405ff40ffcfa') } ntoreturn:0 ntoskip:0 nscanned:19869 index:TABLESCAN keyUpdates:0 numYields: 1 locks(micros) r:216562 nreturned:0 reslen:20 113ms

Having this info in the log would be useful because:

1) it distinguishes between incidents where a query was slow because it just used an index with poor selectivity, versus when it had no index at all.
2) it becomes easier to locate when the application is missing indexes without needing to rely on the invasive "--notablescan" option, which is often not acceptable in production environments.
3) the logs become greppable to find which indexes are involved in the most slow queries, which helps with optimization.
4) nscanned/nscannedobj is often misunderstood or ignored by users. This would help to clarify the relationship between nscanned/nscannedobj and the index that is chosen.



 Comments   
Comment by Scott Hernandez (Inactive) [ 09/Apr/13 ]

Dup of SERVER-7754

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