[SERVER-21383] Surprisingly slow insertion to mongodb capped collections Created: 10/Nov/15  Updated: 11/Nov/15  Resolved: 10/Nov/15

Status: Closed
Project: Core Server
Component/s: Performance
Affects Version/s: 3.2.0-rc0
Fix Version/s: None

Type: Bug Priority: Minor - P4
Reporter: S S Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Steps To Reproduce:

Run the following script twice in parallel:

import time, pymongo, pandas as pd
DBNAME = 'test5'
COLLNAME = 'abc'
mongo = pymongo.MongoClient()
#mongo[DBNAME].drop_collection(COLLNAME)
if DBNAME not in mongo.database_names():
    coll = mongo[DBNAME].create_collection(COLLNAME,
                                    capped = True, size = 50 * 1024 * 1024, max = 1024 * 1024,
                                    fsync = False,  # no delays please (FYI, journaling is disabled)
                                    #autoIndexId = False,
                                    )
 
tarr = []
for _ in range(1000):
    msg = dict.fromkeys([ 'f%d' % j for j in range(30) ], 'foo')
    t1 = time.time()
    coll.insert(msg)  # <-- INSERT() HERE
    tarr.append(time.time() - t1)
    time.sleep(1./100)  # 100 docs/sec. surely not too much load...
 
print pd.Series(tarr).describe()

OUTPUT:

RUN1:
count    1000.000000
mean        0.001555
std         0.002712
min         0.000654
25%         0.001021
50%         0.001084
75%         0.001151
max         0.065006  <-- 65ms!! 
dtype: float64
 
RUN2:
count    1000.000000
mean        0.001733
std         0.004013
min         0.000717
25%         0.001043
50%         0.001069
75%         0.001120
max         0.084803  <-- 84ms!! 
dtype: float64

Participants:

 Description   

I'm using mongodb's capped collections + tailable cursors as a pubsub engine, using pymongo. (This approach is described here: http://blog.pythonisito.com/2013/04/mongodb-pubsub-with-capped-collections.html). My environment includes several topics, several publishers, and a few dozen subscribers.

This works great, except that every once in a while I encounter insert-operations which take surprisingly long time to complete.

My understanding is that mongodb can support insertion of >10K docs/sec, which is why I am surprised that a single insert operation can take 85ms. (I also observed >1sec a few times in my production environment, but couldn't reproduce it using this SSCCE).

To keep delays to a minimum, journaling is disabled, and I am using the lowest write-concern, which helped, but didn't solve the problem.

What causes this and how can I fix it?

I tried both v3.2.0-rc0 and v3.0.7.

More info:

db version v3.2.0-rc0
git version: bf28bd20fa507c4d8cc5919dfbbe87b7750ae8b0
OpenSSL version: OpenSSL 1.0.1f 6 Jan 2014
allocator: tcmalloc
modules: none
build environment:
    distmod: ubuntu1404
    distarch: x86_64
    target_arch: x86_64
 
"storageEngine" : { "name" : "mmapv1", "supportsCommittedReads" : false }
 
journaling DISABLED
pymongo version = 3.0.3

(I also posted this in StackOverflow: http://stackoverflow.com/q/33521301/2096752 . No answers yet)



 Comments   
Comment by S S [ 11/Nov/15 ]

Ok, thanks @Ramon.
What additional configuration details do you suggest I add?

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

shx2, I'm not able to reproduce these results on my end. Tried on 3.2.0-rc0 with both MMAPv1 and WiredTiger, with and without journal. I even lowered the max number of documents in the collection to 1024 and increased the number of inserts from 1K to 10K to force more deletions, and lowered the max size of the collection too – but no luck.

I then tried removing the time.sleep() call and increase the number of documents to 100K, and I can push mongod over 25K inserts/sec with a max insert time of 12ms.

The results you're getting could be related to machine specs, configuration, hard drive speed, I/O load on your machine (although the output of iostat seems reasonable), or some other factor, but since there's not enough information to point to a bug in the MongoDB server I'm going to close this ticket. I'd recommend you post as many configuration details as you can on StackOverflow to see if anything yields a hint.

Regards,
Ramón.

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