Uploaded image for project: 'MongoDB Database Tools'
  1. MongoDB Database Tools
  2. TOOLS-911

mongostat overreports throughput when serverStatus is slow

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical - P2
    • Resolution: Fixed
    • Affects Version/s: 3.0.5
    • Fix Version/s: 3.3.0
    • Component/s: mongostat
    • Labels:
      None

      Description

      Following measurements were observed with mongod under heavy load using WT:

      localhost:27017 357519    *0     *0     *0       0  3431|0     1.5    1.9       0 13.1G 1.8G  0|9509 1|128   12m   395k 10568       07:20:45
      localhost:27017 193468    *0     *0     *0       0  2017|0     1.3    1.8       0 13.1G 1.8G  0|9975 2|124    6m   260k 10577       07:20:48
      localhost:27017 193468    *0     *0     *0       0  2017|0     1.3    1.8       0 13.1G 1.8G  0|9975 2|124    6m   260k 10577       07:20:48
      localhost:27017 214120    *0     *0     *0       0  2276|0     1.3    1.8       0 13.1G 1.8G 0|10079 1|123    7m   285k 10587       07:20:50
                      insert query update delete getmore command % dirty % used flushes vsize  res   qr|qw ar|aw netIn netOut  conn time
      localhost:27017 214120    *0     *0     *0       0  2276|0     1.3    1.8       0 13.1G 1.8G 0|10079 1|123    7m   285k 10587       07:20:50
      localhost:27017 214120    *0     *0     *0       0  2276|0     1.3    1.8       0 13.1G 1.8G 0|10079 1|123    7m   285k 10587       07:20:50
      localhost:27017 331873    *0     *0     *0       0  3327|0     1.4    1.9       0 13.1G 1.8G  0|9803 1|128   11m   384k 10597       07:20:53
      localhost:27017 331873    *0     *0     *0       0  3327|0     1.4    1.9       0 13.1G 1.8G  0|9803 1|128   11m   384k 10597       07:20:53
      localhost:27017 109608    *0     *0     *0       0  1014|0     1.4    2.0       0 13.1G 1.8G  0|9620 1|128    4m   148k 10598       07:20:55
      localhost:27017 139772    *0     *0     *0       0  1364|0     1.3    2.0       0 13.2G 1.8G  0|9436 2|128    5m   165k 10607       07:20:57
      localhost:27017 139772    *0     *0     *0       0  1364|0     1.3    2.0       0 13.2G 1.8G  0|9436 2|128    5m   165k 10607       07:20:57
      localhost:27017 139772    *0     *0     *0       0  1364|0     1.3    2.0       0 13.2G 1.8G  0|9436 2|128    5m   165k 10607       07:20:57
      localhost:27017 219708    *0     *0     *0       0  2199|0     1.2    1.9       0 13.2G 1.8G  0|9702 1|128    7m   294k 10617       07:21:00
      localhost:27017 219708    *0     *0     *0       0  2199|0     1.2    1.9       0 13.2G 1.8G  0|9702 1|128    7m   294k 10617       07:21:00
                      insert query update delete getmore command % dirty % used flushes vsize  res   qr|qw ar|aw netIn netOut  conn time
      localhost:27017 219708    *0     *0     *0       0  2199|0     1.2    1.9       0 13.2G 1.8G  0|9702 1|128    7m   294k 10617       07:21:00
      

      Note several groups of identical lines reporting identical timestamps and identical throughput, with gaps of between the timestamps, which should be at 1-second intervals. I know from independent throughput measurement that the actual throughput during this time period was much lower than that reported above, by a factor of 2-3x. So it appears that

      • when serverStatus is slow mongostat repeats the last sample obtained
      • the throughput calculation looks like maybe it's based on the expected 1s between serverStatus samples, not on the actual time between samples?

        Attachments

          Activity

            People

            Assignee:
            judah.schvimer Judah Schvimer
            Reporter:
            bruce.lucas Bruce Lucas
            Votes:
            0 Vote for this issue
            Watchers:
            10 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: