[SERVER-16445] Queued updates are showing up as queued reads in mongostat Created: 29/Aug/13  Updated: 18/Dec/14  Resolved: 12/Dec/14

Status: Closed
Project: Core Server
Component/s: Diagnostics
Affects Version/s: None
Fix Version/s: 2.8.0-rc3

Type: Bug Priority: Major - P3
Reporter: Alexander Komyagin Assignee: Kaloian Manassiev
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

MongoDB 2.4.6


Issue Links:
Related
Backwards Compatibility: Minor Change
Operating System: ALL
Participants:

 Description   

I was pumping up updates on my test server and noticed that although updates are waiting for the write lock, in mongostat output I can see them in the 'qr' column instead of the 'qw'. It's non-obvious and confusing.



 Comments   
Comment by Githook User [ 12/Dec/14 ]

Author:

{u'username': u'kaloianm', u'name': u'Kaloian Manassiev', u'email': u'kaloian.manassiev@mongodb.com'}

Message: SERVER-16445 Do not count idle connections as reads
Branch: master
https://github.com/mongodb/mongo/commit/6b6471ea34f384e747eeef83dfdfcaee1b332bd0

Comment by Michael O'Brien [ 05/Dec/14 ]

Just confirmed that this is a server problem, running a bunch of updates in a loop (with no other reads or writes going on):
mongostat output is:

insert query update delete getmore command flushes mapped vsize   res faults     locked db idx miss % qr|qw ar|aw netIn netOut conn     time
    *0    *0    596     *0       0     1|0       0 160.0m  2.8g 36.0m      0   test:179.2%          0   3|0   0|0   94k    45k    6 16:47:00
    *0    *0    581     *0       0     1|0       0 160.0m  2.8g 36.0m      0   test:179.5%          0   2|0   0|1   92k    44k    6 16:47:01
    *0    *0    569     *0       0     1|0       0 160.0m  2.8g 36.0m      0   test:179.5%          0   2|0   0|1   89k    43k    6 16:47:02

checking serverstatus directly on the same mongod (which is where the qr/qw field values come from:
>

{ "total" : 2, "readers" : 2, "writers" : 0 }
Comment by Alexander Komyagin [ 23/Sep/13 ]

Scripts are attached in SERVER-10851

Sample output:

insert  query update delete getmore command flushes mapped  vsize    res faults  locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn set repl       time
    *0     *0   1694     *0       0     1|0       0   378g   378g  5.46g      0 test:95.1%          0       8|0     0|1     1m     2k    10 rs0  PRI   21:42:26
    *0     *0   1690     *0       0     1|0       0   378g   378g  5.46g      0 test:95.1%          0       8|0     0|1     1m     2k    10 rs0  PRI   21:42:27
    *0     *0   1700     *0       0     1|0       0   378g   378g  5.46g      0 test:95.1%          0       8|0     0|1     1m     2k    10 rs0  PRI   21:42:28
    *0     *0   1702     *0       0     1|0       0   378g   378g  5.46g      1 test:95.2%          0       8|0     0|1     1m     2k    10 rs0  PRI   21:42:29
    *0     *0   1685     *0       0     1|0       0   378g   378g  5.47g      1 test:95.3%          0       8|0     0|1     1m     2k    10 rs0  PRI   21:42:30
    *0     *0   1725     *0       0     1|0       0   378g   378g  5.47g      0 test:95.0%          0       8|0     0|1     1m     2k    10 rs0  PRI   21:42:31
    *0     *0   1701     *0       0     1|0       0   378g   378g  5.47g      1 test:95.1%          0       8|0     0|1     1m     2k    10 rs0  PRI   21:42:32

Comment by Daniel Pasette (Inactive) [ 31/Aug/13 ]

Can you attach a test script and attach some sample output?

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