Slow query on indexed fields (subdocument array of object)
105 views
Skip to first unread message
Jonathan Muller
May 8, 2015, 6:18:03 PM5/8/15
to mongo...@googlegroups.com
Hello,
As you can see the query takes 1.3 second to execute. I have very big trouble troubleshooting this issue because I'm quite new to mongodb + I did find any documentation on many fields in explain like: saveState, restoreState, isEOF, etc.
Can someone give me some insight to troubleshoot this query? I realy don't know where to look.
I'm experiencing very slow query on indexed fields (using compound index on a subdocument array of objects).
Here is my typical document structure:
{
_id: "my-string-id",
property: "property-value",
sdk: [
{ id: "id-sdk-1", createdAt: new Date(), updatedAt: new Date()},
{ id: "id-sdk-2", createdAt: new Date(), updatedAt: new Date()}
]
}Here is my compound index:
{
"v" : 1,
"key" : {
"sdk.id" : 1,
"sdk.createdAt" : 1,
"sdk.updatedAt" : 1
},
"name" : "sdk.id_1_sdk.createdAt_1_sdk.updatedAt_1",
"ns" : "company.MyCollection"
}Here is the query I use:
When I explain that query:
{ "queryPlanner": { "plannerVersion": 1, "namespace": "company.MyCollection", "indexFilterSet": false, "parsedQuery": { "sdk.id": { "$eq": "id-sdk-1" } }, "winningPlan": { "stage": "COUNT", "inputStage": { "stage": "COUNT_SCAN", "keyPattern": { "sdk.id": 1, "sdk.createdAt": 1, "sdk.updatedAt": 1 }, "indexName": "sdk.id_1_sdk.createdAt_1_sdk.updatedAt_1", "isMultiKey": true } }, "rejectedPlans": [] }, "executionStats": { "executionSuccess": true, "nReturned": 0, "executionTimeMillis": 1362, "totalKeysExamined": 585284, "totalDocsExamined": 0, "executionStages": { "stage": "COUNT", "nReturned": 0, "executionTimeMillisEstimate": 1040, "works": 585284, "advanced": 0, "needTime": 585283, "needFetch": 0, "saveState": 4574, "restoreState": 4574, "isEOF": 1, "invalidates": 0, "nCounted": 585282, "nSkipped": 0, "inputStage": { "stage": "COUNT_SCAN", "nReturned": 585282, "executionTimeMillisEstimate": 1010, "works": 585283, "advanced": 585282, "needTime": 1, "needFetch": 0, "saveState": 4574, "restoreState": 4574, "isEOF": 1, "invalidates": 0, "keysExamined": 585284, "keyPattern": { "sdk.id": 1, "sdk.createdAt": 1, "sdk.updatedAt": 1 }, "indexName": "sdk.id_1_sdk.createdAt_1_sdk.updatedAt_1", "isMultiKey": true } }, "allPlansExecution": [] }, "serverInfo": { "host": "replica-set", "port": 27000, "version": "3.0.2", "gitVersion": "6201872043ecbbc0a4cc169b5482dcf385fc464f" }, "ok": 1}As you can see the query takes 1.3 second to execute. I have very big trouble troubleshooting this issue because I'm quite new to mongodb + I did find any documentation on many fields in explain like: saveState, restoreState, isEOF, etc.
About the collection:
{ "ns": "company.MyCollection", "count": 585835, "size": 657065179, "avgObjSize": 1121, "storageSize": 357490688, "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.3240=(addr=\"01d69c81e4f202c3e8d69d84e4c2ae594bd6a184e4bdb3a9c9808080e4154ebfc0e40fed5fc0\",order=3240,time=1431122093,size=267223040,write_gen=5546642)),checkpoint_lsn=(248,22158592),checksum=uncompressed,collator=,columns=,dictionary=0,format=btree,huffman_key=,huffman_value=,id=23,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-20--7574684173707438416", "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": 5532987, "checkpoint size": 267223040, "allocations requiring file extension": 9410, "blocks freed": 5522526, "file magic number": 120897, "file major version number": 1, "minor version number": 0, "file bytes available for reuse": 103497728, "file size in bytes": 357490688 }, "btree": { "btree checkpoint generation": 3304, "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": 662017546, "bytes written from cache": 169229266155, "checkpoint blocked page eviction": 0, "unmodified pages evicted": 0, "page split during eviction deepened the tree": 0, "modified pages evicted": 78, "data source pages selected for eviction unable to be evicted": 2, "hazard pointer blocked page eviction": 2, "internal pages evicted": 0, "pages split during eviction": 6, "in-memory page splits": 66, "overflow values cached in memory": 0, "pages read into cache": 20714, "overflow pages read into cache": 0, "pages written from cache": 5526517 }, "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": 20623, "compressed pages written": 5236314, "page written failed to compress": 0, "page written was too small to compress": 290203 }, "cursor": { "create calls": 1229, "insert calls": 11940053, "bulk-loaded cursor-insert calls": 0, "cursor-insert key and value bytes inserted": 13674961013, "next calls": 1807385, "prev calls": 1, "remove calls": 0, "cursor-remove key bytes removed": 0, "reset calls": 296926914, "search calls": 296095714, "search near calls": 5157, "update calls": 0, "cursor-update value bytes updated": 0 }, "reconciliation": { "dictionary matches": 0, "internal page multi-block writes": 2854, "leaf page multi-block writes": 21991, "maximum blocks required for a page": 133, "internal-page overflow keys": 0, "leaf-page overflow keys": 0, "overflow values written": 0, "pages deleted": 9, "page checksum matches": 199630, "page reconciliation calls": 5504436, "page reconciliation calls for eviction": 59, "leaf page key bytes discarded using prefix compression": 0, "internal page key bytes discarded using suffix compression": 217380 }, "session": { "object compaction": 0, "open cursor count": 1229 }, "transaction": { "update conflicts": 146 } }, "nindexes": 2, "totalIndexSize": 44072960, "indexSizes": { "_id_": 22183936, "sdk.id_1_sdk.createdAt_1_sdk.updatedAt_1": 21889024 }, "ok": 1}Can someone give me some insight to troubleshoot this query? I realy don't know where to look.
Another information that can be usefull: we recently switched to WiredTiger, query was faster but collection got less items (400k documents, now has 580k, should not be a big issue).
Jonathan
Asya Kamsky
May 8, 2015, 8:30:04 PM5/8/15
to mongo...@googlegroups.com
Jonathan:
This group is for discussion about developing mongodb, not developers
*using* mongodb - that would be the MongoDB-user Google Group.
In the example you show the issue is likely related to the number of
entries in the multikey index on sid that match your query: it
appears that 585,282 documents match the predicate passed in and it
looks like 585,284 index keys are examined. Your entire collection
appears to have 585,835 documents, so it seems like all of them but a
few match the predicate.
Normally, using an index to count should be faster, since we would
just need to see how *many* entries are under a particular index
prefix, but for multikey indexes we also must make sure that we count
each document only once (i.e. an array could have a matching value
more than once) so it's going to be less efficient than if this was a
regular indexed non-array field.
Asya
> --
> You received this message because you are subscribed to the Google Groups
> "mongodb-dev" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to mongodb-dev...@googlegroups.com.
> To post to this group, send email to mongo...@googlegroups.com.
> Visit this group at http://groups.google.com/group/mongodb-dev.
> For more options, visit https://groups.google.com/d/optout.
--
MongoDB World is back! June 1-2 in NYC. Use code ASYA for 25% off!
This group is for discussion about developing mongodb, not developers
*using* mongodb - that would be the MongoDB-user Google Group.
In the example you show the issue is likely related to the number of
entries in the multikey index on sid that match your query: it
appears that 585,282 documents match the predicate passed in and it
looks like 585,284 index keys are examined. Your entire collection
appears to have 585,835 documents, so it seems like all of them but a
few match the predicate.
Normally, using an index to count should be faster, since we would
just need to see how *many* entries are under a particular index
prefix, but for multikey indexes we also must make sure that we count
each document only once (i.e. an array could have a matching value
more than once) so it's going to be less efficient than if this was a
regular indexed non-array field.
Asya
> You received this message because you are subscribed to the Google Groups
> "mongodb-dev" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to mongodb-dev...@googlegroups.com.
> To post to this group, send email to mongo...@googlegroups.com.
> Visit this group at http://groups.google.com/group/mongodb-dev.
> For more options, visit https://groups.google.com/d/optout.
--
MongoDB World is back! June 1-2 in NYC. Use code ASYA for 25% off!
Jonathan Muller
May 11, 2015, 4:57:42 AM5/11/15
to mongo...@googlegroups.com
Sorry about that I wasn't aware of the second group, my bad
Thanks for your answer
Reply all
Reply to author
Forward
0 new messages