接業務需求，有一個MongoDB的簡單查詢，太耗時了，執行了 70S 左右，嚴重影響用戶的體驗。。 查詢代碼主要如下： 此集合在欄位OPTime上有索引idx_OPTime；在"Tags"數組中的內嵌欄位"SN"有索引idx_TSN；兩者都是獨立的索引。此集合存放的是執行Log，相對Size較大。 ...
接業務需求，有一個MongoDB的簡單查詢，太耗時了，執行了 70S 左右，嚴重影響用戶的體驗。。
查詢代碼主要如下：
db.duoduologmodel.find({"Tags.SN": "QZ435698245"}) .projection({}) .sort({OPTime: -1})
.limit(20)
此集合在欄位OPTime上有索引idx_OPTime；在"Tags"數組中的內嵌欄位"SN"有索引idx_TSN；兩者都是獨立的索引。此集合存放的是執行Log，相對Size較大。
查看此查詢對應的慢查詢日誌，如下：
2019-08-13T15:07:16.767+0800 I COMMAND [conn536359] command shqq_zp.duoduologmodel command: find { find: "duoduologmodel", filter: { Tags.SN: "QZ435698245" }, sort: { OPTime: -1 }, projection: {}, limit: 20, $db: "shqq_zp", $clusterTime: { clusterTime: Timestamp(1565679737, 71), signature: { hash: BinData(0, E7B0A887E83BAD0AA0A72016A39C677B53ABDBE2), keyId: 6658116868433248258 } }, lsid: { id: UUID("0f22409b-f122-41e9-a094-46ccf04e44c7") } } planSummary: IXSCAN { OPTime: 1 } cursorid:61603998663 keysExamined:12145431 docsExamined:12145431 fromMultiPlanner:1 replanned:1 numYields:97720 nreturned:14 reslen:16772198 locks:{ Global: { acquireCount: { r: 97721 } }, Database: { acquireCount: { r: 97721 } }, Collection: { acquireCount: { r: 97721 } } } protocol:op_msg 692537ms
查看此查詢的執行計劃，執行代碼
db.duoduologmodel.find({"Tags.SN": "QZ435698245"}) .projection({}) .sort({OPTime: -1}) .explain()
主要反饋信息
"queryPlanner" : { "plannerVersion" : 1, "namespace" : "shqq_zp.duoduologmodel", "indexFilterSet" : false, "parsedQuery" : { "Tags.SN" : { "$eq" : "QZ435698245" } }, "winningPlan" : { "stage" : "SORT", "sortPattern" : { "OPTime" : -1 }, "inputStage" : { "stage" : "SORT_KEY_GENERATOR", "inputStage" : { "stage" : "FETCH", "inputStage" : { "stage" : "IXSCAN", "keyPattern" : { "Tags.SN" : 1 }, "indexName" : "idx_TSN", "isMultiKey" : true, "multiKeyPaths" : { "Tags.SN" : [ "Tags" ] }, "isUnique" : false, "isSparse" : true, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "Tags.SN" : [ "[\"QZ435698245\", \"QZ435698245\"]" ] } } } } }, "rejectedPlans" : [ { "stage" : "FETCH", "filter" : { "Tags.SN" : { "$eq" : "QZ435698245" } }, "inputStage" : { "stage" : "IXSCAN", "keyPattern" : { "OPTime" : 1 }, "indexName" : "idx_OPTime", "isMultiKey" : false, "multiKeyPaths" : { "OPTime" : [ ] }, "isUnique" : false, "isSparse" : false, "isPartial" : false, "indexVersion" : 2, "direction" : "backward", "indexBounds" : { "OPTime" : [ "[MaxKey, MinKey]" ] } } } ] }
假如不用排序，刪除 .sort({OperationTime: -1})，其執行計劃
"queryPlanner" : { "plannerVersion" : 1, "namespace" : "shqq_zp.duoduologmodel", "indexFilterSet" : false, "parsedQuery" : { "Tags.SN" : { "$eq" : "QZ435698245" } }, "winningPlan" : { "stage" : "FETCH", "inputStage" : { "stage" : "IXSCAN", "keyPattern" : { "Tags.SN" : 1 }, "indexName" : "idx_TSN", "isMultiKey" : true, "multiKeyPaths" : { "Tags.SN" : [ "Tags" ] }, "isUnique" : false, "isSparse" : true, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "Tags.SN" : [ "[\"QZ435698245\", \"QZ435698245\"]" ] } } }, "rejectedPlans" : [ ] }
此時，執行查詢確實變快了很多，在2S以內執行完畢。
刪除OPTime欄位索引後的執行計劃
"queryPlanner" : { "plannerVersion" : 1, "namespace" : "shqq_zp.duoduologmodel", "indexFilterSet" : false, "parsedQuery" : { "Tags.SN" : { "$eq" : "QZ435698245" } }, "winningPlan" : { "stage" : "SORT", "sortPattern" : { "OPTime" : -1 }, "inputStage" : { "stage" : "SORT_KEY_GENERATOR", "inputStage" : { "stage" : "FETCH", "inputStage" : { "stage" : "IXSCAN", "keyPattern" : { "Tags.SN" : 1 }, "indexName" : "idx_TSN", "isMultiKey" : true, "multiKeyPaths" : { "Tags.SN" : [ "Tags" ] }, "isUnique" : false, "isSparse" : true, "isPartial" : false, "indexVersion" : 2, "direction" : "forward", "indexBounds" : { "Tags.SN" : [ "[\"QZ435698245\", \"QZ435698245\"]" ] } } } } }, "rejectedPlans" : [ ] }
刪除這個索引後，查看報錯
{ "message" : "Executor error during find command :: caused by :: Sort operation used more than the maximum 33554432 bytes of RAM. Add an index, or specify a smaller limit.", "OPTime" : "Timestamp(1565681389, 1)", "ok" : 0, "code" : 96, "codeName" : "OperationFailed", "$clusterTime" : { "clusterTime" : "Timestamp(1565681389, 1)", "signature" : { "hash" : "vODWe0BCzyihrRVM08wPSFIMvo0=", "keyId" : "6658116868433248258" } }, "name" : "MongoError" }
原因比較明確：Sort operation used more than the maximum 33554432 bytes of RAM.，33554432 bytes算下來正好是32Mb，而Mongodb的sort操作是把數據拿到記憶體中再進行排序的，為了節約記憶體，預設給sort操作限制了最大記憶體為32Mb，當數據量越來越大直到超過32Mb的時候就自然拋出異常了！
因這個查看功能執行不多，併發不高。將系統排序記憶體由預設的32M調整到64M。
（此操作需謹慎，一般不建議修改，需要結合業務的使用情況，比如併發，數據量的大小；應優先考慮通過調整索引或集合的設計、甚至前端的設計來實現優化。）
db.adminCommand({setParameter:1, internalQueryExecMaxBlockingSortBytes:64554432})
（註意;這個設置在重啟MongoDB服務就會失效，重新變成預設的32M了）。
再次執行查詢查看，不再報錯。並且快速返回結果（2S）
因為還有其他需求，會根據OPTime欄位查看，重新添加這個索引。
再次執行，也可以比較迅速的返回結果（2S）。
從以上分析我們可以推斷;
（1）explain()查看的執行計劃，有時候還是有偏差的。
（2）Sort排序情況會影響索引的選擇。即當internalQueryExecMaxBlockingSortBytes不足以支持先查詢（by tag.sn）後排序(by optime)時，系統自動選擇了一個已排序好的索引（by optime），進行查看。
知識補充：
queryPlanner.namespace:該值返回的是該query所查詢的表；
queryPlanner.indexFilterSet:針對該query是否有indexfilter；
queryPlanner.winningPlan:查詢優化器針對該query所返回的最優執行計劃的詳細內容；
queryPlanner.rejectedPlans：其他執行計劃（非最優而被查詢優化器reject的）的詳細返回。
本文版權歸作者所有，未經作者同意不得轉載,謝謝配合！！！
本文版權歸作者所有，未經作者同意不得轉載,謝謝配合！！！
本文版權歸作者所有，未經作者同意不得轉載,謝謝配合！！！
