[SERVER-21267] mongod hang during insert into capped collection with WT Created: 03/Nov/15  Updated: 03/Mar/16  Resolved: 03/Nov/15

Status: Closed
Project: Core Server
Component/s: Storage
Affects Version/s: 3.2.0-rc2
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Rui Zhang (Inactive) Assignee: Ramon Fernandez Marina
Resolution: Done Votes: 0
Labels: sys-perf-reg
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Participants:

 Description   

During sys-perf test, observed test hang during insert_capped for all the variants it runs against:

  • standalone
  • 1-node repl
  • 3-node repl

in evergreen log, the tests eventually timed out due to no output for 2 hours.

[2015/11/02 23:04:31.563] >>> insert_capped-wiredTiger : 15783.010987220374 1
[2015/11/03 00:56:25.662] Received abort signal - stopping.

be able to manually verify the issue with latest build of 0899ba98f6



 Comments   
Comment by Rui Zhang (Inactive) [ 03/Nov/15 ]

can reproduce with db3fce5ea2, but cannot reproduce with latest build, close this as gone away

this is mongostats log with db3fce5ea2

insert query update delete getmore command % dirty % used flushes  vsize    res qr|qw ar|aw netIn netOut conn                 time
115744    *0     *0     *0       0     2|0    38.4   42.4       0   7.3G   7.0G   0|0   1|1  120m    17k    3 2015-11-03T18:22:14Z
112128    *0     *0     *0       0     4|0    39.2   43.1       0   7.4G   7.1G   0|0   1|1  116m    17k    3 2015-11-03T18:22:15Z
115744    *0     *0     *0       0     2|0    40.0   43.9       0   7.6G   7.3G   0|0   1|1  120m    17k    3 2015-11-03T18:22:16Z
113384    *0     *0     *0       0     2|0    40.8   44.6       0   7.7G   7.4G   0|0   1|1  117m    17k    3 2015-11-03T18:22:17Z
115384    *0     *0     *0       0     3|0    41.6   45.4       0   7.8G   7.5G   0|0   1|1  119m    17k    3 2015-11-03T18:22:18Z
113744    *0     *0     *0       0     2|0    42.5   46.3       0   7.9G   7.6G   0|0   1|1  118m    17k    3 2015-11-03T18:22:19Z
113616    *0     *0     *0       0     2|0    43.3   47.0       0   8.1G   7.8G   0|0   1|1  118m    17k    3 2015-11-03T18:22:20Z
112320    *0     *0     *0       0     2|0    44.1   47.8       0   8.2G   7.9G   0|0   1|1  116m    17k    3 2015-11-03T18:22:21Z
111936    *0     *0     *0       0     3|0    44.8   48.5       0   8.3G   8.0G   0|0   1|1  116m    17k    3 2015-11-03T18:22:22Z
112616    *0     *0     *0       0     3|0    45.7   49.3       0   8.4G   8.1G   0|0   1|0  117m    17k    3 2015-11-03T18:22:23Z
insert query update delete getmore command % dirty % used flushes  vsize    res qr|qw ar|aw netIn netOut conn                 time
113320    *0     *0     *0       0     2|0    46.5   50.1       0   8.6G   8.3G   0|0   1|1  117m    17k    3 2015-11-03T18:22:24Z
114000    *0     *0     *0       0     2|0    47.2   50.7       0   8.7G   8.4G   0|0   1|1  118m    17k    3 2015-11-03T18:22:25Z
115320    *0     *0     *0       0     2|0    48.1   51.6       0   8.8G   8.5G   0|0   1|1  119m    17k    3 2015-11-03T18:22:26Z
114360    *0     *0     *0       0     2|0    48.9   52.4       0   8.9G   8.6G   0|0   1|1  119m    17k    3 2015-11-03T18:22:27Z
113128    *0     *0     *0       0     3|0    49.7   53.1       0   9.1G   8.8G   0|0   1|1  117m    17k    3 2015-11-03T18:22:28Z
108000    *0     *0     *0       0     2|0    29.8   53.6       1   9.2G   8.9G   0|0   1|1  112m    17k    3 2015-11-03T18:22:29Z
108448    *0     *0     *0       0     3|0     0.7   54.2       0   9.3G   9.0G   0|0   1|1  112m    17k    3 2015-11-03T18:22:30Z
 57808    *0     *0     *0       0     1|0     1.1   53.5       0   9.3G   9.0G   0|0   1|1   60m    17k    3 2015-11-03T18:22:31Z
    64    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:32Z
    *0    *0     *0     *0       0     2|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1  133b    17k    3 2015-11-03T18:22:33Z
insert query update delete getmore command % dirty % used flushes  vsize    res qr|qw ar|aw netIn netOut conn                 time
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:34Z
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:35Z
    64    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:36Z
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:37Z
    *0    *0     *0     *0       0     2|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1  133b    17k    3 2015-11-03T18:22:38Z
    64    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:39Z
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:40Z
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:41Z
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:42Z
    64    *0     *0     *0       0     2|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1  133b    17k    3 2015-11-03T18:22:43Z
insert query update delete getmore command % dirty % used flushes  vsize    res qr|qw ar|aw netIn netOut conn                 time
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:44Z
    *0    *0     *0     *0       0     2|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1  137b    17k    3 2015-11-03T18:22:45Z
    64    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:46Z
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:47Z
    *0    *0     *0     *0       0     2|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1  133b    17k    3 2015-11-03T18:22:48Z
    *0    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:49Z
    64    *0     *0     *0       0     1|0     1.1   51.6       0   9.3G   9.0G   0|0   1|1   79b    17k    3 2015-11-03T18:22:50Z

Comment by Ramon Fernandez Marina [ 03/Nov/15 ]

I wasn't able to repro with 8a3acb42:

$ ./run-workloads.sh  -t localhost
Target server address: localhost
Run test to target server: [localhost] with isSharded=false
Run test insert_capped.js
MongoDB shell version: 3.2.0-rc1-84-g8a3acb4
connecting to: localhost:27017/test
loading file: ./utils/mongoshell.js
loading file: ./workloads/insert_capped.js
Cannot use 'commands' readMode, degrading to 'legacy' mode
Total time to prime the collection: 40.151 seconds
Throughput: 28741.50083435033 ops/sec
>>> initial_load_capped : 28741.50083435033 1
>>> insert_capped : 56649.56007312348 1
>>> insert_capped : 56527.68400079928 8
>>> insert_capped : 56539.99314715249 64
loading file: ./utils/final.js
 
 
Results:
+--------------------------------+----------+--------------+----------+------------------------------+
| "Test"                         | "Thread" | "Throughput" | "Pass?"  | "Comment"                    |
|--------------------------------+----------+--------------+----------+------------------------------|
| "initial_load_capped"          |        1 | 28741.500834 | true     | ""                           |
| "insert_capped"                |        1 | 56649.560073 | true     | ""                           |
| "insert_capped"                |        8 | 56527.684000 | true     | ""                           |
| "insert_capped"                |       64 | 56539.993147 | true     | ""                           |
+--------------------------------+----------+--------------+----------+------------------------------+

Will try with 00899ba98 next.

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