[SERVER-9458] Very slow page faulting on windows on find() - performance regression Created: 25/Apr/13  Updated: 10/Dec/14  Resolved: 30/Apr/13

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

Type: Bug Priority: Critical - P2
Reporter: Gregor Macadam Assignee: Tad Marshall
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Windows 2008 R2 SP1, 3.5GB RAM, 2 Cores, Azure
2.2.4 2008+ vs 2.4.3 2008+


Issue Links:
Depends
Duplicate
duplicates SERVER-9242 serverStatus workingSet and indexCoun... Closed
Related
related to SERVER-9455 mongodump'ing on Windows: performance... Closed
Operating System: ALL
Steps To Reproduce:

Collection details

> db.test.stats()
{
        "ns" : "test.test",
        "count" : 11235,
        "size" : 15639072,
        "avgObjSize" : 1391.995727636849,
        "storageSize" : 16875520,
        "numExtents" : 6,
        "nindexes" : 1,
        "lastExtentSize" : 8495104,
        "paddingFactor" : 1,
        "systemFlags" : 1,
        "userFlags" : 0,
        "totalIndexSize" : 376096,
        "indexSizes" : {
                "_id_" : 376096
        },
        "ok" : 1
}

1. Restart mongodb
2. Run db.test.find() from (python) client.

Mongostat output for version 2.2.4 2008+

connected to: 127.0.0.1
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      0      0       0       1       0     0m    95m    35m      6 local:0.0%          0       0|0     0|0    62b     1k     1   09:54:20 
     0      0      0      0       0       1       0     0m    95m    35m      0 local:0.0%          0       0|0     0|0    62b     1k     1   09:54:21 
     0      0      0      0       0       1       0     0m    95m    35m      0 local:0.0%          0       0|0     0|0    62b     1k     1   09:54:22 
     0      1      0      0       3       1       0    80m   258m    65m  11008     .:0.5%          0       0|0     0|0   231b    12m     2   09:54:23 
     0      0      0      0       1       1       0    80m   258m    67m    966  test:0.0%          0       0|0     0|0   104b     1m     2   09:54:24 
     0      0      0      0       0       1       0    80m   258m    67m      0  test:0.0%          0       0|0     0|0    62b     1k     2   09:54:25 

Mongostat output from version 2.4.3 2008+

connected to: 127.0.0.1
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     *0     *0       0     1|0       0    80m   300m    38m      2 local:0.0%          0       0|0     0|0    62b     2k     1   09:54:52 
    *0     *0     *0     *0       0     1|0       0    80m   300m    38m      0 local:0.0%          0       0|0     0|0    62b     2k     1   09:54:53 
    *0      1     *0     *0       1     1|0       0   160m   465m    40m    444     .:0.2%          0       0|0     0|0   105b   134k     2   09:54:54 
    *0     *0     *0     *0       0     1|0       0   160m   465m    41m    123     .:1.5%          0       0|0     0|0    62b     2k     2   09:54:55 
    *0     *0     *0     *0       0     1|0       0   160m   465m    41m    132     .:1.6%          0       0|0     0|0    62b     2k     2   09:54:56 
    *0     *0     *0     *0       0     1|0       0   160m   465m    42m    125     .:1.6%          0       0|0     0|0    62b     2k     2   09:54:57 
    *0     *0     *0     *0       0     1|0       0   160m   465m    42m    125  test:0.0%          0       0|0     0|0    62b     2k     2   09:54:58 
    *0     *0     *0     *0       0     1|0       0   160m   465m    43m    123     .:2.5%          0       0|0     0|0    62b     2k     2   09:54:59 
    *0     *0     *0     *0       0     1|0       0   160m   465m    43m    124     .:0.9%          0       0|0     0|0    62b     2k     2   09:55:00 
    *0     *0     *0     *0       0     1|0       0   160m   465m    44m    123  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:01 
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     *0     *0       0     1|0       0   160m   465m    44m    133     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:02 
    *0     *0     *0     *0       0     1|0       0   160m   465m    45m    123     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:03 
    *0     *0     *0     *0       0     1|0       0   160m   465m    45m    124  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:04 
    *0     *0     *0     *0       0     1|0       0   160m   465m    46m    133     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:05 
    *0     *0     *0     *0       0     1|0       0   160m   465m    46m    124     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:06 
    *0     *0     *0     *0       0     1|0       0   160m   465m    47m    124     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:07 
    *0     *0     *0     *0       0     1|0       0   160m   465m    47m    124  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:08 
    *0     *0     *0     *0       0     1|0       0   160m   465m    48m    127     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:09 
    *0     *0     *0     *0       0     1|0       0   160m   465m    48m    123     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:10 
    *0     *0     *0     *0       0     1|0       0   160m   461m    44m    116  test:0.0%          0       0|0     0|0   104b     4m     2   09:55:11 
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     *0     *0       1     1|0       0   160m   465m    45m    103  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:12 
    *0     *0     *0     *0       0     1|0       0   160m   465m    45m    123     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:13 
    *0     *0     *0     *0       0     1|0       0   160m   465m    46m    125  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:14 
    *0     *0     *0     *0       0     1|0       0   160m   465m    46m    122     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:15 
    *0     *0     *0     *0       0     1|0       0   160m   465m    47m    114     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:16 
    *0     *0     *0     *0       0     1|0       0   160m   465m    47m    123     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:17 
    *0     *0     *0     *0       0     1|0       0   160m   465m    48m    124  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:18 
    *0     *0     *0     *0       0     1|0       0   160m   465m    48m    122     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:19 
    *0     *0     *0     *0       0     1|0       0   160m   465m    49m    122     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:20 
    *0     *0     *0     *0       0     1|0       0   160m   465m    49m    124  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:21 
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     *0     *0       0     1|0       0   160m   465m    50m    122     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:22 
    *0     *0     *0     *0       0     1|0       0   160m   465m    50m    123     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:23 
    *0     *0     *0     *0       0     1|0       0   160m   465m    51m    123     .:0.9%          0       0|0     0|0    62b     2k     2   09:55:24 
    *0     *0     *0     *0       0     1|0       0   160m   465m    51m    118  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:25 
    *0     *0     *0     *0       0     1|0       0   160m   465m    52m    127     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:26 
    *0     *0     *0     *0       0     1|0       0   160m   465m    52m    122     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:27 
    *0     *0     *0     *0       0     1|0       0   160m   465m    53m    123  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:28 
    *0     *0     *0     *0       1     1|0       0   160m   465m    49m     93     .:1.5%          0       0|0     0|0   104b     4m     2   09:55:29 
    *0     *0     *0     *0       0     1|0       0   160m   465m    49m    124     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:30 
    *0     *0     *0     *0       0     1|0       0   160m   465m    50m    128  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:31 
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     *0     *0       0     1|0       0   160m   465m    50m    124     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:32 
    *0     *0     *0     *0       0     1|0       0   160m   465m    51m    124     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:33 
    *0     *0     *0     *0       0     1|0       0   160m   465m    51m    123     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:34 
    *0     *0     *0     *0       0     1|0       0   160m   465m    52m    125  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:35 
    *0     *0     *0     *0       0     1|0       0   160m   465m    52m    123     .:1.2%          0       0|0     0|0    62b     2k     2   09:55:36 
    *0     *0     *0     *0       0     1|0       0   160m   465m    53m    124     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:37 
    *0     *0     *0     *0       0     1|0       0   160m   465m    53m    124  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:38 
    *0     *0     *0     *0       0     1|0       0   160m   465m    54m    125     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:39 
    *0     *0     *0     *0       0     1|0       1   160m   465m    54m    126     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:40 
    *0      2     *0     *0       0     1|0       0   160m   465m    56m    394  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:41 
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     *0     *0       0     1|0       0   160m   465m    56m    124     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:42 
    *0     *0     *0     *0       0     1|0       0   160m   465m    57m    124     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:43 
    *0     *0     *0     *0       0     1|0       0   160m   465m    57m    119     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:44 
    *0     *0     *0     *0       0     1|0       0   160m   465m    58m    133  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:45 
    *0     *0     *0     *0       0     1|0       0   160m   465m    58m    123     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:46 
    *0     *0     *0     *0       1     1|0       0   160m   465m    54m     75     .:1.7%          0       0|0     0|0   104b     4m     2   09:55:47 
    *0     *0     *0     *0       0     1|0       0   160m   465m    55m    124  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:48 
    *0     *0     *0     *0       0     1|0       0   160m   465m    55m    123     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:49 
    *0     *0     *0     *0       0     1|0       0   160m   465m    56m    122     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:50 
    *0     *0     *0     *0       0     1|0       0   160m   465m    56m    123  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:51 
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     *0     *0       0     1|0       0   160m   465m    57m    123     .:2.6%          0       0|0     0|0    62b     2k     2   09:55:52 
    *0     *0     *0     *0       0     1|0       0   160m   465m    57m    122     .:1.5%          0       0|0     0|0    62b     2k     2   09:55:53 
    *0     *0     *0     *0       0     1|0       0   160m   465m    58m    122     .:1.6%          0       0|0     0|0    62b     2k     2   09:55:54 
    *0     *0     *0     *0       0     1|0       0   160m   461m    56m     36  test:0.0%          0       0|0     0|0   104b     1m     2   09:55:55 
    *0     *0     *0     *0       0     1|0       0   160m   461m    56m      0     .:0.0%          0       0|0     0|0    62b     2k     2   09:55:56 
    *0     *0     *0     *0       0     1|0       0   160m   461m    56m      0  test:0.0%          0       0|0     0|0    62b     2k     2   09:55:57 

Participants:

 Description   

When doing a db.collection.find() after restarting mongodb on a collection of 15MB, this takes 2 seconds in 2.2.4 and 60 seconds in 2.4.3.



 Comments   
Comment by Daniel Pasette (Inactive) [ 30/Apr/13 ]

This is a duplicate of SERVER-9242 which will be included in 2.4.4

Comment by Tad Marshall [ 25/Apr/13 ]

I tested current master (commit 5ae15577b9b341ec782459c975e2f6e8cdf8caf7), commit 7d96d614c9b91a668a65992115c12b3ede51faea (which includes the fix for SERVER-9242) and commit 85d5487e2e40b7351566b914f8df4d454beb5835 (the commit before 7d96d614c9b91a668a65992115c12b3ede51faea).

All tests were on the same dataset: native Windows (not virtualized) on 16 GB RAM, Samsung 840 Pro 512 GB SSD:

> db.test.stats();
{
        "ns" : "test.test",
        "count" : 11235,
        "size" : 57342560,
        "avgObjSize" : 5103.9216733422345,
        "storageSize" : 77438976,
        "numExtents" : 9,
        "nindexes" : 1,
        "lastExtentSize" : 23519232,
        "paddingFactor" : 1,
        "systemFlags" : 1,
        "userFlags" : 0,
        "totalIndexSize" : 376096,
        "indexSizes" : {
                "_id_" : 376096
        },
        "ok" : 1
}

Mongostat output for current master (commit 5ae15577b9b341ec782459c975e2f6e8cdf8caf7):

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     *0     *0       0     1|0       0   288m   722m    44m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:31:20
    *0     *0     *0     *0       0     1|0       0   288m   722m    44m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:31:21
    *0     *0     *0     *0       0     1|0       0   288m   722m    44m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:31:22
    *0     *0     *0     *0       0     1|0       0   288m   722m    44m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:31:23
    *0      1     *0     *0      13     1|0       0   288m   726m    96m  37961  test:0.0%          0       0|0     1|0   609b    50m     2   13:31:25  <<== peak 50 MB/s
    *0     *0     *0     *0       1     2|0       0   288m   722m    99m   3041  test:0.0%          0       0|0     0|0   234b     4m     2   13:31:26
    *0     *0     *0     *0       0     1|0       0   288m   722m    99m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:31:27
    *0     *0     *0     *0       0     1|0       0   288m   722m    99m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:31:28

Mongostat output for fix for SERVER-9242 (commit 7d96d614c9b91a668a65992115c12b3ede51faea):

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     *0     *0       0     1|0       0    80m   309m    41m      0 local:0.0%          0       0|0     0|0    62b     2k     2   13:46:16
    *0     *0     *0     *0       0     1|0       0    80m   309m    41m      0 local:0.0%          0       0|0     0|0    62b     2k     2   13:46:17
    *0     *0     *0     *0       0     1|0       0    80m   309m    41m      0 local:0.0%          0       0|0     0|0    62b     2k     2   13:46:18
    *0     *0     *0     *0       0     1|0       0    80m   309m    41m      1     .:0.1%          0       0|0     0|0    62b     2k     2   13:46:19
    *0      1     *0     *0       0     2|0       1    80m   309m    42m    288 local:0.0%          0       0|0     0|0   150b     2k     2   13:46:20
    *0      1     *0     *0       2     1|0       0   288m   729m    57m   5682     .:0.2%          0       0|0     1|0   147b     4m     2   13:46:21
    *0     *0     *0     *0      12     2|0       0   288m   725m    99m  35656  test:0.0%          0       0|0     0|0   696b    50m     2   13:46:22  <<== peak 50 MB/s
    *0     *0     *0     *0       0     1|0       0   288m   725m    99m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:46:23
    *0     *0     *0     *0       0     1|0       0   288m   725m    99m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:46:24
    *0     *0     *0     *0       0     1|0       0   288m   725m    99m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:46:25

Mongostat output for code just before the fix for SERVER-9242 (commit 85d5487e2e40b7351566b914f8df4d454beb5835):

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     *0     *0       0     1|0       0    80m   306m    41m      5 local:0.0%          0       0|0     0|0    62b     2k     2   13:56:34
    *0     *0     *0     *0       0     1|0       0    80m   306m    41m      0 local:0.0%          0       0|0     0|0    62b     2k     2   13:56:35
    *0     *0     *0     *0       0     1|0       0    80m   306m    41m      0 local:0.0%          0       0|0     0|0    62b     2k     2   13:56:36
    *0     *0     *0     *0       0     1|0       0    80m   306m    41m      0 local:0.0%          0       0|0     0|0    62b     2k     2   13:56:37
    *0     *0     *0     *0       0     1|0       0    80m   306m    41m      1 local:0.0%          0       0|0     0|0    62b     2k     2   13:56:38
    *0     *0     *0     *0       0     2|0       0    80m   306m    41m      0 local:0.0%          0       0|0     0|0   150b     2k     2   13:56:39
    *0      1     *0     *0       1     1|0       0   288m   726m    43m    708     .:0.2%          0       0|0     0|0   105b   499k     2   13:56:40
    *0     *0     *0     *0       1     1|0       0   288m   726m    49m   3432  test:0.1%          0       0|0     0|0   104b     4m     2   13:56:41  <<== no peak above 8 MB/s
    *0     *0     *0     *0       1     1|0       0   288m   726m    54m   3436  test:0.1%          0       0|0     0|0   104b     4m     2   13:56:42  <<
    *0     *0     *0     *0       1     1|0       0   288m   726m    60m   3449  test:0.1%          0       0|0     0|0   104b     4m     2   13:56:43  <<
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     *0     *0       1     1|0       0   288m   726m    65m   3433  test:0.1%          0       0|0     0|0   104b     4m     2   13:56:44  <<
    *0     *0     *0     *0       1     1|0       0   288m   726m    71m   3475  test:0.1%          0       0|0     0|0   104b     4m     2   13:56:45  <<
    *0     *0     *0     *0       1     1|0       0   288m   726m    76m   3418  test:0.0%          0       0|0     0|0   104b     4m     2   13:56:46  <<
    *0     *0     *0     *0       2     1|0       0   288m   726m    77m   4379  test:0.0%          0       0|0     0|0   146b     8m     2   13:56:47  <<
    *0     *0     *0     *0       1     1|0       0   288m   726m    82m   3405  test:0.1%          0       0|0     0|0   104b     4m     2   13:56:48  <<
    *0     *0     *0     *0       1     1|0       0   288m   726m    88m   3446  test:0.0%          0       0|0     0|0   104b     4m     2   13:56:49  <<
    *0     *0     *0     *0       1     1|0       0   288m   726m    92m   3402  test:0.1%          0       0|0     0|0   104b     4m     2   13:56:50  <<
    *0     *0     *0     *0       1     1|0       0   288m   726m    97m   3437  test:0.1%          0       0|0     0|0   104b     4m     2   13:56:51  <<
    *0     *0     *0     *0       1     2|0       0   288m   725m    97m   1972  test:0.0%          0       0|0     0|0   234b     4m     2   13:56:52  <<
    *0     *0     *0     *0       0     1|0       0   288m   725m    97m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:56:53
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     *0     *0       0     1|0       0   288m   725m    97m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:56:54
    *0     *0     *0     *0       0     1|0       0   288m   725m    97m     33  test:0.0%          0       0|0     0|0    62b     2k     2   13:56:55
    *0     *0     *0     *0       0     1|0       0   288m   725m    97m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:56:56
    *0     *0     *0     *0       0     1|0       0   288m   725m    97m      0  test:0.0%          0       0|0     0|0    62b     2k     2   13:56:57

Mongostat output for 2.4.3 (Windows 64-bit, not 2008R2+) (commit fe1743177a5ea03e91e0052fb5e2cb2945f6d95f):

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     *0     *0       0     1|0       0    80m   304m    40m      3 local:0.0%          0       0|0     0|0    62b     2k     2   14:14:14
    *0     *0     *0     *0       0     1|0       0    80m   304m    40m      0 local:0.0%          0       0|0     0|0    62b     2k     2   14:14:15
    *0     *0     *0     *0       0     1|0       0    80m   304m    40m      0 local:0.0%          0       0|0     0|0    62b     2k     2   14:14:16
    *0     *0     *0     *0       0     2|0       0    80m   304m    40m      0 local:0.0%          0       0|0     0|0   150b     2k     2   14:14:17
    *0      1     *0     *0       1     1|0       0   288m   724m    45m   1227     .:0.2%          0       0|0     0|0   105b   499k     2   14:14:18
    *0     *0     *0     *0       1     1|0       0   288m   724m    49m   3436  test:0.0%          0       0|0     0|0   104b     4m     2   14:14:19  <<== no peak above 8 MB/s
    *0     *0     *0     *0       1     1|0       0   288m   724m    55m   3444  test:0.1%          0       0|0     0|0   104b     4m     2   14:14:21  <<
    *0     *0     *0     *0       1     1|0       0   288m   724m    60m   3465  test:0.0%          0       0|0     0|0   104b     4m     2   14:14:22  <<
    *0     *0     *0     *0       1     1|0       0   288m   724m    65m   3431  test:0.0%          0       0|0     0|0   104b     4m     2   14:14:23  <<
    *0     *0     *0     *0       1     1|0       0   288m   720m    67m   4399  test:0.1%          0       0|0     0|0   146b     8m     2   14:14:24  <<
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     *0     *0       2     1|0       0   288m   724m    72m   3385  test:0.0%          0       0|0     0|0   104b     4m     2   14:14:25  <<
    *0     *0     *0     *0       1     1|0       0   288m   724m    77m   3481  test:0.0%          0       0|0     0|0   104b     4m     2   14:14:26  <<
    *0     *0     *0     *0       1     1|0       0   288m   724m    83m   3448  test:0.0%          0       0|0     0|0   104b     4m     2   14:14:27  <<
    *0     *0     *0     *0       1     1|0       0   288m   724m    88m   3448  test:0.0%          0       0|0     0|0   104b     4m     2   14:14:28  <<
    *0     *0     *0     *0       1     1|0       0   288m   724m    94m   3434  test:0.1%          0       0|0     0|0   104b     4m     2   14:14:29  <<
    *0     *0     *0     *0       1     1|0       0   288m   724m    99m   3461  test:0.0%          0       0|0     0|0   104b     4m     2   14:14:30  <<
    *0     *0     *0     *0       1     2|0       0   288m   720m    96m   1311  test:0.0%          0       0|0     0|0   234b     4m     2   14:14:31  <<
    *0     *0     *0     *0       0     1|0       0   288m   720m    96m      0  test:0.0%          0       0|0     0|0    62b     2k     2   14:14:32
    *0     *0     *0     *0       0     1|0       0   288m   720m    96m      0  test:0.0%          0       0|0     0|0    62b     2k     2   14:14:33
    *0     *0     *0     *0       0     1|0       0   288m   720m    96m      0  test:0.0%          0       0|0     0|0    62b     2k     2   14:14:34

Mongostat output for 2.2.4 (Windows 64-bit, not 2008R2+) (commit a2880030d3cec10c850c6850efa7a51b628b8822):

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      0      0       0       1       0     0m    97m    36m      3 local:0.0%          0       0|0     0|0    62b     1k     2   14:23:13
     0      0      0      0       0       1       0     0m    97m    36m      0 local:0.0%          0       0|0     0|0    62b     1k     2   14:23:14
     0      0      0      0       0       1       0     0m    97m    36m      0 local:0.0%          0       0|0     0|0    62b     1k     2   14:23:15
     0      0      0      0       0       1       0     0m    97m    36m     16 local:0.0%          0       0|0     0|0    62b     1k     2   14:23:16
     0      0      0      0       0       1       0     0m    97m    36m      0 local:0.0%          0       0|0     0|0    62b     1k     2   14:23:17
     0      0      0      0       0       2       0     0m    97m    36m      8 local:0.0%          0       0|0     0|0   150b     1k     2   14:23:18
     0      1      0      0       1       1       0   208m   515m    58m  12565     .:0.4%          0       0|0     0|0   147b     4m     2   14:23:19
     0      0      0      0      13       2       0   208m   515m   108m  37600  test:0.0%          0       0|0     0|0   696b    50m     2   14:23:20  <<== peak 50 MB/s
     0      0      0      0       0       1       0   208m   515m   108m      0  test:0.0%          0       0|0     0|0    62b     1k     2   14:23:21
     0      0      0      0       0       1       0   208m   515m   108m      0  test:0.0%          0       0|0     0|0    62b     1k     2   14:23:22

Mongostat output for 2.0.9 (Windows 64-bit, not 2008R2+) (commit 7e34cb36a6ae64d527c0b0da81fa967606c55433):

insert  query update delete getmore command flushes mapped  vsize    res faults locked % idx miss %     qr|qw   ar|aw  netIn netOut  conn       time
     0      0      0      0       0       1       0     0m    75m    21m      8        0          0       0|0     0|0    62b     1k     2   14:33:33
     0      0      0      0       0       1       0     0m    75m    21m      0        0          0       0|0     0|0    62b     1k     2   14:33:34
     0      0      0      0       0       1       0     0m    75m    21m      8        0          0       0|0     0|0    62b     1k     2   14:33:35
     0      0      0      0       0       3       0     0m    75m    21m      4        0          0       0|0     0|0   218b     1k     2   14:33:36
     0      0      0      0       0       1       0     0m    75m    21m      0        0          0       0|0     0|0    62b     1k     2   14:33:37
     0      1      0      0      13       1       0   208m   525m    92m  45164      0.4          0       0|0     0|0   651b    55m     2   14:33:38  <<== peak 55 MB/s (!)
     0      0      0      0       1       3       0   208m   525m    92m    115        0          0       0|0     0|0   260b   222k     2   14:33:40
     0      0      0      0       0       1       0   208m   525m    92m      0        0          0       0|0     0|0    62b     1k     2   14:33:41
     0      0      0      0       0       1       0   208m   525m    92m      0        0          0       0|0     0|0    62b     1k     2   14:33:42

I am pretty confident that this fix (commit 7d96d614c9b91a668a65992115c12b3ede51faea) is what you are looking for.

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