-
Type:
Bug
-
Resolution: Duplicate
-
Priority:
Major - P3
-
None
-
Affects Version/s: 2.0.4, 2.1.1
-
Component/s: Concurrency
-
Labels:
-
Environment:multiple. have run on my mac and on aws.
-
ALL
client is inserting records as quickly as it can.
seeing the insert rate drop to zero while background flushes happen.
have tested on 2.0.4 and 2.1.1 and see same behavior.
mongostat output:
...
insert query update delete getmore command flushes mapped vsize res locked % idx miss % qr|qw ar|aw netIn netOut conn time
23300 0 0 0 0 1 0 1.8g 6.01g 872m 93.7 0 0|0 0|1 12m 1k 2 15:59:24
22900 0 0 0 0 1 0 1.8g 6.01g 883m 105 0 0|0 0|1 12m 1k 2 15:59:25
23900 0 0 0 0 1 0 1.8g 6.01g 896m 98.7 0 0|0 0|1 12m 1k 2 15:59:26
22100 0 0 0 0 1 0 1.8g 6.01g 910m 96.4 0 0|0 0|1 11m 1k 2 15:59:27
18900 0 0 0 0 1 0 1.8g 6.01g 920m 95.7 0 0|0 0|1 10m 1k 2 15:59:28
16300 0 0 0 0 1 0 1.8g 6.01g 928m 106 0 0|0 0|0 8m 1k 2 15:59:29
17400 0 0 0 0 1 0 1.8g 6.01g 937m 99.2 0 0|0 0|1 9m 1k 2 15:59:30
9500 0 0 0 0 1 0 1.8g 6.01g 944m 52.6 0 0|0 0|1 5m 1k 2 15:59:31
0 0 0 0 0 1 0 1.8g 6.01g 944m 0 0 1|1 0|1 62b 1k 2 15:59:32
0 0 0 0 0 1 0 1.8g 6.01g 944m 0 0 1|1 0|1 62b 1k 2 15:59:33
insert query update delete getmore command flushes mapped vsize res locked % idx miss % qr|qw ar|aw netIn netOut conn time
11600 0 0 0 0 1 1 2.8g 8.01g 949m 345 0 0|0 0|1 6m 1k 2 15:59:34
9300 0 0 0 0 1 0 2.8g 8.01g 956m 95.4 0 0|0 0|1 4m 1k 2 15:59:35
You can see that during the few seconds before the flush happens, inserts drop to zero.
then about a minute later we see it again
16200 0 0 0 0 1 0 2.8g 8.01g 1.25g 93.1 0 0|0 0|1 8m 1k 2 16:00:24
16200 0 0 0 0 1 0 2.8g 8.01g 1.25g 95.3 0 0|0 0|1 8m 1k 2 16:00:25
17900 0 0 0 0 1 0 2.8g 8.01g 1.26g 109 0 0|0 0|1 9m 1k 2 16:00:26
17200 0 0 0 0 1 0 2.8g 8.01g 1.27g 96.9 0 0|0 0|1 9m 1k 2 16:00:27
8100 0 0 0 0 1 0 2.8g 8.01g 1.28g 60.6 0 0|0 0|1 4m 1k 2 16:00:28
0 0 0 0 0 1 0 2.8g 8.01g 1.28g 0 0 0|1 0|1 62b 1k 2 16:00:29
2700 0 0 0 0 1 1 2.8g 8.01g 1.28g 235 0 0|0 0|1 1m 1k 2 16:00:30
16200 0 0 0 0 1 0 2.8g 8.01g 1.29g 91.5 0 0|0 0|1 8m 1k 2 16:00:31
18900 0 0 0 0 1 0 2.8g 8.01g 1.3g 108 0 0|0 0|1 10m 1k 2 16:00:32
I've attached the test program that recreates this.
- related to
-
-
- Closed
-