[SERVER-9288] Count command records incorrect number of commands for top stats Created: 08/Apr/13  Updated: 14/Dec/16  Resolved: 14/Dec/16

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

Type: Bug Priority: Minor - P4
Reporter: Shaun Verch Assignee: David Storch
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File top.js    
Issue Links:
Depends
is depended on by SERVER-7774 Add jstest for db.adminCommand('top') Closed
Related
is related to SERVER-7774 Add jstest for db.adminCommand('top') Closed
Operating System: ALL
Steps To Reproduce:

After dropDatabase:

> db.dropDatabase()
{ "dropped" : "test", "ok" : 1 }
> db.adminCommand("top").totals["test.test"].commands
{ "time" : 0, "count" : 0 }
> db.test.count()
0
> db.adminCommand("top").totals["test.test"].commands
{ "time" : 7, "count" : 2 }
> db.test.count()
0
> db.adminCommand("top").totals["test.test"].commands
{ "time" : 22, "count" : 4 }
>

After drop collection:

> db.test.drop()
true
> db.adminCommand("top").totals["test.test"].commands
Mon Apr  8 15:02:09.264 TypeError: db.adminCommand("top").totals['test.test'] has no properties (shell):1
> db.test.count()
0
> db.adminCommand("top").totals["test.test"].commands
{ "time" : 346, "count" : 1 }
> db.test.count()
0
> db.adminCommand("top").totals["test.test"].commands
{ "time" : 460, "count" : 3 }
>

Sprint: Query 2017-01-23
Participants:

 Description   

In different circumstances count will record a different number of commands. Usually it records two, except after the collection is dropped.

I believe this is because the Client::Context::~Context destructor in client.cpp gets called twice:

dbcommands.cpp 2001 execCommand Client::ReadContext
dbcommands.cpp 1341 CollectionStats.run Client::Context

This causes CurOp::recordGlobalTime to be called twice, which then calls Top::record twice.

Also, the reason that count is only recorded once after a dropped collection because of an explicit check for this in Top::record.



 Comments   
Comment by David Storch [ 14/Dec/16 ]

I can confirm that this has been fixed in master, 3.4, and 3.2, though I haven't tracked down exactly which change contained the fix. Closing as Gone Away.

Comment by Max Hirschhorn [ 14/Dec/16 ]

I'm moving this ticket back into "Needs triage" for the Query team to take a look at. After reviewing the test cases for the "count" command in jstests/core/top.js as part of evaluating whether we could close SERVER-7774, I didn't see any special handling for "count" command being double-counted in the test. I suspect this issue has been resolved.

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