I have a local mongo running on my machine and a mongodb running on an ec2 container using m5.large with ebs storage.
I’m aware that there will always be some difference (networking) etc when it comes to making a request locally vs making a request externally in the cloud to a production mongo.
However im finding with this particularly trivial query (assuming) its taking much longer than i expected.
node.js mongo query
let query = {
date: {
$gte: from,
},
game_id: gameId,
};
let documents = await gameStreams.find(query).toArray();
I am using node.js to make a query to mongodb. This code is ran locally against local (my laptop) and production (ec2) version of mongo
**local:**: time_taken 4003.124ms
**production**: time_taken 71187.316ms
Locally it takes around 4-9 seconds but when making the same query to production its taking 70-80 seconds. Why would there be such a huge difference here?
Note: i am using toArray() and the number of documents returned is 300,000.
db.getCollection(‘gamestreams’).stats()
{
"ns" : "gaming.gamestreams",
"size" : 4138284702.0,
"count" : 14011415,
"avgObjSize" : 295,
"storageSize" : 900091904,
"freeStorageSize" : 671744,
"capped" : false,
"wiredTiger" : {
"metadata" : {
"formatVersion" : 1
},
"creationString" : "access_pattern_hint=none,allocation_size=4KB,app_metadata=(formatVersion=1),assert=(commit_timestamp=none,durable_timestamp=none,read_timestamp=none),block_allocation=best,block_compressor=snappy,cache_resident=false,checksum=on,colgroups=,collator=,columns=,dictionary=0,encryption=(keyid=,name=),exclusive=false,extractor=,format=btree,huffman_key=,huffman_value=,ignore_in_memory_cache_size=false,immutable=false,internal_item_max=0,internal_key_max=0,internal_key_truncate=true,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=64MB,log=(enabled=false),lsm=(auto_throttle=true,bloom=true,bloom_bit_count=16,bloom_config=,bloom_hash_count=8,bloom_oldest=false,chunk_count_limit=0,chunk_max=5GB,chunk_size=10MB,merge_custom=(prefix=,start_generation=0,suffix=),merge_max=15,merge_min=0),memory_page_image_max=0,memory_page_max=10m,os_cache_dirty_max=0,os_cache_max=0,prefix_compression=false,prefix_compression_min=4,source=,split_deepen_min_child=0,split_deepen_per_child=0,split_pct=90,type=file,value_format=u",
"type" : "file",
"uri" : "statistics:table:collection-0--7606124955649373726",
"LSM" : {
"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,
"bloom filters in the LSM tree" : 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 checkpoint throttle" : 0,
"sleep for LSM merge throttle" : 0,
"total size of bloom filters" : 0
},
"block-manager" : {
"allocations requiring file extension" : 51772,
"blocks allocated" : 58597,
"blocks freed" : 7000,
"checkpoint size" : 899403776,
"file allocation unit size" : 4096,
"file bytes available for reuse" : 671744,
"file magic number" : 120897,
"file major version number" : 1,
"file size in bytes" : 900091904,
"minor version number" : 0
},
"btree" : {
"btree checkpoint generation" : 5456,
"btree clean tree checkpoint expiration time" : NumberLong(9223372036854775807),
"column-store fixed-size leaf pages" : 0,
"column-store internal pages" : 0,
"column-store variable-size RLE encoded values" : 0,
"column-store variable-size deleted values" : 0,
"column-store variable-size leaf pages" : 0,
"fixed-record size" : 0,
"maximum internal page key size" : 368,
"maximum internal page size" : 4096,
"maximum leaf page key size" : 2867,
"maximum leaf page size" : 32768,
"maximum leaf page value size" : 67108864,
"maximum tree depth" : 4,
"number of key/value pairs" : 0,
"overflow pages" : 0,
"pages rewritten by compaction" : 0,
"row-store empty values" : 0,
"row-store internal pages" : 0,
"row-store leaf pages" : 0
},
"cache" : {
"bytes currently in the cache" : 2587594533.0,
"bytes dirty in the cache cumulative" : 1180911380.0,
"bytes read into cache" : 11221545998.0,
"bytes written from cache" : 4664026027.0,
"checkpoint blocked page eviction" : 0,
"data source pages selected for eviction unable to be evicted" : 339,
"eviction walk passes of a file" : 13253,
"eviction walk target pages histogram - 0-9" : 3513,
"eviction walk target pages histogram - 10-31" : 4855,
"eviction walk target pages histogram - 128 and higher" : 0,
"eviction walk target pages histogram - 32-63" : 2504,
"eviction walk target pages histogram - 64-128" : 2381,
"eviction walks abandoned" : 539,
"eviction walks gave up because they restarted their walk twice" : 145,
"eviction walks gave up because they saw too many pages and found no candidates" : 4738,
"eviction walks gave up because they saw too many pages and found too few candidates" : 2980,
"eviction walks reached end of tree" : 7126,
"eviction walks started from root of tree" : 8404,
"eviction walks started from saved location in tree" : 4849,
"hazard pointer blocked page eviction" : 14,
"history store table reads" : 0,
"in-memory page passed criteria to be split" : 669,
"in-memory page splits" : 338,
"internal pages evicted" : 383,
"internal pages split during eviction" : 5,
"leaf pages split during eviction" : 1012,
"modified pages evicted" : 1398,
"overflow pages read into cache" : 0,
"page split during eviction deepened the tree" : 1,
"page written requiring history store records" : 1180,
"pages read into cache" : 125966,
"pages read into cache after truncate" : 1,
"pages read into cache after truncate in prepare state" : 0,
"pages requested from the cache" : 33299436,
"pages seen by eviction walk" : 14244088,
"pages written from cache" : 57731,
"pages written requiring in-memory restoration" : 45,
"tracked dirty bytes in the cache" : 0,
"unmodified pages evicted" : 147454
},
"cache_walk" : {
"Average difference between current eviction generation when the page was last considered" : 0,
"Average on-disk page image size seen" : 0,
"Average time in cache for pages that have been visited by the eviction server" : 0,
"Average time in cache for pages that have not been visited by the eviction server" : 0,
"Clean pages currently in cache" : 0,
"Current eviction generation" : 0,
"Dirty pages currently in cache" : 0,
"Entries in the root page" : 0,
"Internal pages currently in cache" : 0,
"Leaf pages currently in cache" : 0,
"Maximum difference between current eviction generation when the page was last considered" : 0,
"Maximum page size seen" : 0,
"Minimum on-disk page image size seen" : 0,
"Number of pages never visited by eviction server" : 0,
"On-disk page image sizes smaller than a single allocation unit" : 0,
"Pages created in memory and never written" : 0,
"Pages currently queued for eviction" : 0,
"Pages that could not be queued for eviction" : 0,
"Refs skipped during cache traversal" : 0,
"Size of the root page" : 0,
"Total number of pages currently in cache" : 0
},
"checkpoint-cleanup" : {
"pages added for eviction" : 3,
"pages removed" : 0,
"pages skipped during tree walk" : 1992915,
"pages visited" : 4892576
},
"compression" : {
"compressed page maximum internal page size prior to compression" : 4096,
"compressed page maximum leaf page size prior to compression " : 131072,
"compressed pages read" : 125583,
"compressed pages written" : 55619,
"page written failed to compress" : 0,
"page written was too small to compress" : 2112
},
"cursor" : {
"Total number of entries skipped by cursor next calls" : 0,
"Total number of entries skipped by cursor prev calls" : 0,
"Total number of entries skipped to position the history store cursor" : 0,
"bulk loaded cursor insert calls" : 0,
"cache cursors reuse count" : 72908,
"close calls that result in cache" : 0,
"create calls" : 305,
"cursor next calls that skip greater than or equal to 100 entries" : 0,
"cursor next calls that skip less than 100 entries" : 14756445,
"cursor prev calls that skip greater than or equal to 100 entries" : 0,
"cursor prev calls that skip less than 100 entries" : 1,
"insert calls" : 14072870,
"insert key and value bytes" : 4212628410.0,
"modify" : 0,
"modify key and value bytes affected" : 0,
"modify value bytes modified" : 0,
"next calls" : 14756445,
"open cursor count" : 0,
"operation restarted" : 109,
"prev calls" : 1,
"remove calls" : 0,
"remove key bytes removed" : 0,
"reserve calls" : 0,
"reset calls" : 224078,
"search calls" : 13128942,
"search history store calls" : 0,
"search near calls" : 14772,
"truncate calls" : 0,
"update calls" : 0,
"update key and value bytes" : 0,
"update value size change" : 0
},
"reconciliation" : {
"approximate byte size of timestamps in pages written" : 84197280,
"approximate byte size of transaction IDs in pages written" : 77480,
"dictionary matches" : 0,
"fast-path pages deleted" : 0,
"internal page key bytes discarded using suffix compression" : 91023,
"internal page multi-block writes" : 747,
"internal-page overflow keys" : 0,
"leaf page key bytes discarded using prefix compression" : 0,
"leaf page multi-block writes" : 1368,
"leaf-page overflow keys" : 0,
"maximum blocks required for a page" : 1,
"overflow values written" : 0,
"page checksum matches" : 23657,
"page reconciliation calls" : 3073,
"page reconciliation calls for eviction" : 999,
"pages deleted" : 3,
"pages written including an aggregated newest start durable timestamp " : 1173,
"pages written including an aggregated newest stop durable timestamp " : 0,
"pages written including an aggregated newest stop timestamp " : 0,
"pages written including an aggregated newest stop transaction ID" : 0,
"pages written including an aggregated oldest start timestamp " : 1065,
"pages written including an aggregated oldest start transaction ID " : 19,
"pages written including an aggregated prepare" : 0,
"pages written including at least one prepare" : 0,
"pages written including at least one start durable timestamp" : 31568,
"pages written including at least one start timestamp" : 31568,
"pages written including at least one start transaction ID" : 63,
"pages written including at least one stop durable timestamp" : 0,
"pages written including at least one stop timestamp" : 0,
"pages written including at least one stop transaction ID" : 0,
"records written including a prepare" : 0,
"records written including a start durable timestamp" : 5262330,
"records written including a start timestamp" : 5262330,
"records written including a start transaction ID" : 9685,
"records written including a stop durable timestamp" : 0,
"records written including a stop timestamp" : 0,
"records written including a stop transaction ID" : 0
},
"session" : {
"object compaction" : 0
},
"transaction" : {
"race to read prepared update retry" : 0,
"update conflicts" : 0
}
},
"nindexes" : 8,
"indexBuilds" : [],
"totalIndexSize" : 2627395584.0,
"totalSize" : 3527487488.0,
"indexSizes" : {
"_id_" : 270036992,
"service_id_1" : 303837184,
"service_type_1" : 249204736,
"name_1" : 245424128,
"date_1" : 226025472,
"game_id_1" : 247881728,
"service_id_1_service_type_1_name_1_date_1_game_id_1" : 996036608,
"game_id_1_date_1" : 88948736
},
"scaleFactor" : 1,
"ok" : 1.0,
"$clusterTime" : {
"clusterTime" : Timestamp(1607345809, 1),
"signature" : {
"hash" : { "$binary" : "CP8MT7YsL4t+raZn62AZhZdmTFg=", "$type" : "00" },
"keyId" : NumberLong(6855964983600087045)
}
},
"operationTime" : Timestamp(1607345809, 1)
}
db.getCollection(‘gamestreams’).find({ date: { $gte: new Date(‘2019-07-03T23:59:59.999Z’) }, game_id: ‘24024’ }).explain()
{
"queryPlanner" : {
"plannerVersion" : 1,
"namespace" : "gaming.gamestreams",
"indexFilterSet" : false,
"parsedQuery" : {
"$and" : [
{
"game_id" : {
"$eq" : "24024"
}
},
{
"date" : {
"$gte" : ISODate("2019-07-03T23:59:59.999Z")
}
}
]
},
"queryHash" : "FCE2088F",
"planCacheKey" : "A564EAFA",
"winningPlan" : {
"stage" : "FETCH",
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"game_id" : 1.0,
"date" : 1.0
},
"indexName" : "game_id_1_date_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"game_id" : [],
"date" : []
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : 2,
"direction" : "forward",
"indexBounds" : {
"game_id" : [
"[\"24024\", \"24024\"]"
],
"date" : [
"[new Date(1562198399999), new Date(9223372036854775807)]"
]
}
}
},
"rejectedPlans" : [
{
"stage" : "FETCH",
"filter" : {
"game_id" : {
"$eq" : "24024"
}
},
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"date" : 1
},
"indexName" : "date_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"date" : []
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : 2,
"direction" : "forward",
"indexBounds" : {
"date" : [
"[new Date(1562198399999), new Date(9223372036854775807)]"
]
}
}
},
{
"stage" : "FETCH",
"filter" : {
"date" : {
"$gte" : ISODate("2019-07-03T23:59:59.999Z")
}
},
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"game_id" : 1
},
"indexName" : "game_id_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"game_id" : []
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : 2,
"direction" : "forward",
"indexBounds" : {
"game_id" : [
"[\"24024\", \"24024\"]"
]
}
}
}
]
},
"serverInfo" : {
"host" : "mongo-prod-mongodb-0",
"port" : 27017,
"version" : "4.4.1",
"gitVersion" : "ad91a93a5a31e175f5cbf8c69561e788bbc55ce1"
},
"ok" : 1.0,
"$clusterTime" : {
"clusterTime" : Timestamp(1607346119, 1),
"signature" : {
"hash" : { "$binary" : "XMuLYE5NVhHktX9wZ79LteksXFs=", "$type" : "00" },
"keyId" : NumberLong(6855964983600087045)
}
},
"operationTime" : Timestamp(1607346119, 1)
}
Stats above are taken from production mongo, if there is any other information you need me to provide please let me know.
Note: using the cursor with a batchSize(10000) helps a little, reducing time taken on production to around 40 seconds But it still does not seem quite right compared to performance i get locally.