Menu
I have 2700 records in MongoDB. Each document has a size of approximately 320KB. The engine I use is wiredTiger and the total size of collection is about 885MB.
My MongoDB config is as below:
systemLog:
destination: file
path: /usr/local/var/log/mongodb/mongo.log
logAppend: true
storage:
dbPath: /usr/local/var/mongodb
engine: wiredTiger
wiredTiger:
engineConfig:
cacheSizeGB: 1
statisticsLogDelaySecs: 0
journalCompressor: snappy
collectionConfig:
blockCompressor: snappy
indexConfig:
prefixCompression: false
net:
bindIp: 127.0.0.1
My connection is via socket:
mongo_client = MongoClient('/tmp/mongodb-27017.sock')
And collection stats reveal this result:
db.mycol.stats()
{
"ns" : "bi.mycol",
"count" : 2776,
"size" : 885388544,
"avgObjSize" : 318944,
"storageSize" : 972476416,
"capped" : false,
"wiredTiger" : {
"metadata" : {
"formatVersion" : 1
},
"creationString" : "allocation_size=4KB,app_metadata=(formatVersion=1),block_allocation=best,block_compressor=snappy,cache_resident=0,checkpoint=(WiredTigerCheckpoint.9=(addr=\"01e30275da81e4b9e99f78e30275db81e4c61d1e01e30275dc81e40fab67d5808080e439f6afc0e41e80bfc0\",order=9,time=1444566832,size=511762432,write_gen=13289)),checkpoint_lsn=(24,52054144),checksum=uncompressed,collator=,columns=,dictionary=0,format=btree,huffman_key=,huffman_value=,id=5,internal_item_max=0,internal_key_max=0,internal_key_truncate=,internal_page_max=4KB,key_format=q,key_gap=10,leaf_item_max=0,leaf_key_max=0,leaf_page_max=32KB,leaf_value_max=1MB,memory_page_max=10m,os_cache_dirty_max=0,os_cache_max=0,prefix_compression=0,prefix_compression_min=4,split_deepen_min_child=0,split_deepen_per_child=0,split_pct=90,value_format=u,version=(major=1,minor=1)",
"type" : "file",
"uri" : "statistics:table:collection-0-6630292038312816605",
"LSM" : {
"bloom filters in the LSM tree" : 0,
"bloom filter false positives" : 0,
"bloom filter hits" : 0,
"bloom filter misses" : 0,
"bloom filter pages evicted from cache" : 0,
"bloom filter pages read into cache" : 0,
"total size of bloom filters" : 0,
"sleep for LSM checkpoint throttle" : 0,
"chunks in the LSM tree" : 0,
"highest merge generation in the LSM tree" : 0,
"queries that could have benefited from a Bloom filter that did not exist" : 0,
"sleep for LSM merge throttle" : 0
},
"block-manager" : {
"file allocation unit size" : 4096,
"blocks allocated" : 0,
"checkpoint size" : 511762432,
"allocations requiring file extension" : 0,
"blocks freed" : 0,
"file magic number" : 120897,
"file major version number" : 1,
"minor version number" : 0,
"file bytes available for reuse" : 460734464,
"file size in bytes" : 972476416
},
"btree" : {
"column-store variable-size deleted values" : 0,
"column-store fixed-size leaf pages" : 0,
"column-store internal pages" : 0,
"column-store variable-size leaf pages" : 0,
"pages rewritten by compaction" : 0,
"number of key/value pairs" : 0,
"fixed-record size" : 0,
"maximum tree depth" : 4,
"maximum internal page key size" : 368,
"maximum internal page size" : 4096,
"maximum leaf page key size" : 3276,
"maximum leaf page size" : 32768,
"maximum leaf page value size" : 1048576,
"overflow pages" : 0,
"row-store internal pages" : 0,
"row-store leaf pages" : 0
},
"cache" : {
"bytes read into cache" : 3351066029,
"bytes written from cache" : 0,
"checkpoint blocked page eviction" : 0,
"unmodified pages evicted" : 8039,
"page split during eviction deepened the tree" : 0,
"modified pages evicted" : 0,
"data source pages selected for eviction unable to be evicted" : 1,
"hazard pointer blocked page eviction" : 1,
"internal pages evicted" : 0,
"pages split during eviction" : 0,
"in-memory page splits" : 0,
"overflow values cached in memory" : 0,
"pages read into cache" : 10519,
"overflow pages read into cache" : 0,
"pages written from cache" : 0
},
"compression" : {
"raw compression call failed, no additional data available" : 0,
"raw compression call failed, additional data available" : 0,
"raw compression call succeeded" : 0,
"compressed pages read" : 10505,
"compressed pages written" : 0,
"page written failed to compress" : 0,
"page written was too small to compress" : 0
},
"cursor" : {
"create calls" : 7,
"insert calls" : 0,
"bulk-loaded cursor-insert calls" : 0,
"cursor-insert key and value bytes inserted" : 0,
"next calls" : 0,
"prev calls" : 2777,
"remove calls" : 0,
"cursor-remove key bytes removed" : 0,
"reset calls" : 16657,
"search calls" : 16656,
"search near calls" : 0,
"update calls" : 0,
"cursor-update value bytes updated" : 0
},
"reconciliation" : {
"dictionary matches" : 0,
"internal page multi-block writes" : 0,
"leaf page multi-block writes" : 0,
"maximum blocks required for a page" : 0,
"internal-page overflow keys" : 0,
"leaf-page overflow keys" : 0,
"overflow values written" : 0,
"pages deleted" : 0,
"page checksum matches" : 0,
"page reconciliation calls" : 0,
"page reconciliation calls for eviction" : 0,
"leaf page key bytes discarded using prefix compression" : 0,
"internal page key bytes discarded using suffix compression" : 0
},
"session" : {
"object compaction" : 0,
"open cursor count" : 7
},
"transaction" : {
"update conflicts" : 0
}
},
"nindexes" : 2,
"totalIndexSize" : 208896,
"indexSizes" : {
"_id_" : 143360,
"date_1" : 65536
},
"ok" : 1
}
How can I understand that MongoDB uses swap? How to infer where exactly is the bottleneck?
EDIT:
The way I fetch data in python is:
for doc in mycol.find({'date': {"$lte": '2016-12-12', '$gte': '2012-09-09'}}, {'_id': False}):
doc['uids'] = set(doc['uids'])
records.append(doc)
date field is indexed.
EDIT 2: These are the result when fetching data:
CPU core1: ~65%
CPU core2: ~65%
CPU core3: ~65%
CPU core4: ~65%
RAM: 7190/8190MB
swap: 1140/2048MB
EDIT 3:
MongoDB log is:
2015-10-11T17:25:08.317+0330 I NETWORK [initandlisten] connection accepted from anonymous unix socket #18 (2 connections now open)
2015-10-11T17:25:08.321+0330 I NETWORK [initandlisten] connection accepted from anonymous unix socket #19 (3 connections now open)
2015-10-11T17:25:36.501+0330 I QUERY [conn19] getmore bi.mycol cursorid:10267473126 ntoreturn:0 keyUpdates:0 writeConflicts:0 numYields:3 nreturned:14 reslen:4464998 locks:{} 199ms
2015-10-11T17:25:37.665+0330 I QUERY [conn19] getmore bi.mycol cursorid:10267473126 ntoreturn:0 keyUpdates:0 writeConflicts:0 numYields:5 nreturned:14 reslen:4464998 locks:{} 281ms
2015-10-11T17:25:50.331+0330 I NETWORK [conn19] end connection anonymous unix socket (2 connections now open)
2015-10-11T17:25:50.363+0330 I NETWORK [conn18] end connection anonymous unix socket (1 connection now open)
EDIT 4:
Sample data is:
{"date": "2012-09-12", "uids": [1,2,3,4,...,30000]}
NB: I have 30k UIDs inside of uids field.
EDIT 5:
Explaining query display that it has used IXSCAN stage:
$ db.mycol.find({'date': {"$lte": '2018-11-27', '$gte': '2011-04-23'}}, {'_id': 0}).explain("executionStats")
{
"queryPlanner" : {
"plannerVersion" : 1,
"namespace" : "bi.mycol",
"indexFilterSet" : false,
"parsedQuery" : {
"$and" : [
{
"date" : {
"$lte" : "2018-11-27"
}
},
{
"date" : {
"$gte" : "2011-04-23"
}
}
]
},
"winningPlan" : {
"stage" : "PROJECTION",
"transformBy" : {
"_id" : 0
},
"inputStage" : {
"stage" : "FETCH",
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"date" : 1
},
"indexName" : "date_1",
"isMultiKey" : false,
"direction" : "forward",
"indexBounds" : {
"date" : [
"[\"2011-04-23\", \"2018-11-27\"]"
]
}
}
}
},
"rejectedPlans" : [ ]
},
"executionStats" : {
"executionSuccess" : true,
"nReturned" : 2776,
"executionTimeMillis" : 2312,
"totalKeysExamined" : 2776,
"totalDocsExamined" : 2776,
"executionStages" : {
"stage" : "PROJECTION",
"nReturned" : 2776,
"executionTimeMillisEstimate" : 540,
"works" : 2777,
"advanced" : 2776,
"needTime" : 0,
"needFetch" : 0,
"saveState" : 31,
"restoreState" : 31,
"isEOF" : 1,
"invalidates" : 0,
"transformBy" : {
"_id" : 0
},
"inputStage" : {
"stage" : "FETCH",
"nReturned" : 2776,
"executionTimeMillisEstimate" : 470,
"works" : 2777,
"advanced" : 2776,
"needTime" : 0,
"needFetch" : 0,
"saveState" : 31,
"restoreState" : 31,
"isEOF" : 1,
"invalidates" : 0,
"docsExamined" : 2776,
"alreadyHasObj" : 0,
"inputStage" : {
"stage" : "IXSCAN",
"nReturned" : 2776,
"executionTimeMillisEstimate" : 0,
"works" : 2776,
"advanced" : 2776,
"needTime" : 0,
"needFetch" : 0,
"saveState" : 31,
"restoreState" : 31,
"isEOF" : 1,
"invalidates" : 0,
"keyPattern" : {
"date" : 1
},
"indexName" : "date_1",
"isMultiKey" : false,
"direction" : "forward",
"indexBounds" : {
"date" : [
"[\"2011-04-23\", \"2018-11-27\"]"
]
},
"keysExamined" : 2776,
"dupsTested" : 0,
"dupsDropped" : 0,
"seenInvalidated" : 0,
"matchTested" : 0
}
}
}
},
"serverInfo" : {
"host" : "MySys.local",
"port" : 27017,
"version" : "3.0.0",
"gitVersion" : "nogitversion"
},
"ok" : 1
}
EDIT 6:
OS: Mac osX Yosemite
MongoDB version: 3.0.0
Total RAM: 8G
Filesystem: Mac OS Extended (Journaled)
479
The methods I used to improve performance:
First of all instead of using for loop to traverse query and fetch data, I give the cursor to Pandas rather than creating a large list object in python:
cursor = mycol.find({'date': {"$lte": end_date, '$gte': start_date}}, {'_id': False})
df = pandas.DataFrame(list(cursor))
Performance got much better it now takes 10 seconds at most rather than 30 seconds.
Instead of using doc['uids'] = set(doc['uids']) which take around 6 seconds I didn't change default list to set and handled duplicates with dataframe itself.
167
You have two problems here:
Use isodate instead of string date for faster index lookups, as string dates do a lexographic string comparison, whereas isodates does a numeric one. Since your total records are low, the type of index should not be a big problem, the problem might be size of documents and their network transfer plus deserialization.
Try a query with not selecting the uid field i.e.
for doc in mycol.find({'date': {"$lte": '2016-12-12', '$gte': '2012-09-09'}}, {'_id': False,'uid':False}):
Your query time will improve by a huge margin.You will then need to investigate the transfer times between your application and mongodb servers, and also benchmark for single document fetching using find_one() to see how much time deserializations are taking.
3
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With
