Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-9288

Count command records incorrect number of commands for top stats

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Minor - P4 Minor - P4
    • None
    • Affects Version/s: None
    • Component/s: Diagnostics, Querying
    • Labels:
      None
    • ALL
    • Hide

      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 }
>
      Show
      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 } >
    • Query 2017-01-23

      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.

        1. top.js
          2 kB

            Assignee:
            david.storch@mongodb.com David Storch
            Reporter:
            sverch Shaun Verch
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: