-
Type:
Bug
-
Resolution: Duplicate
-
Priority:
Major - P3
-
None
-
Affects Version/s: 3.2.19, 3.6.4
-
Component/s: Querying
-
None
-
ALL
Hi All
Our MongoDB had poor perfomance when this query appear,this query like this:
db.files.find({"operation.sha1Code":"acca33867df96b97a05bdbd81f2aee13axxxxxxx","operation.is_prefix":true,"operation.des_url":"sh/"})
this collection have some indexes：
{
"v" : 1,
"key" : {
"operation.is_prefix" : 1
},
"name" : "operation.is_prefix_1",
"ns" : "fs.files",
"background" : true
},
{
"v" : 1,
"key" : {
"operation.des_url" : 1
},
"name" : "operation.des_url_1",
"ns" : "fs.files",
"background" : true
},
{
"v" : 1,
"key" : {
"operation.sha1Code" : 1
},
"name" : "operation.sha1Code_1",
"ns" : "fs.files",
"background" : true
}
and every columns filter result count：
db.files.find({"operation.sha1Code":"acca33867df96b97a05bdbd81f2aee13axxxxxxx"}).count()
539408
db.files.find({"operation.is_prefix":true}).count()
463885621
db.files.find({"operation.des_url":"sh/"}).count()
*{color:#d04437}180999{color}*
this collection has 553055549 records.
So MongoDB choose the operation.des_url_1 index and it's perfect.but we saw many slow query after this query,such as :
2018-02-26T14:39:11.049+0800 I COMMAND [conn3959231] command fs.files command: find { find: "files", filter: { operation.sha1Code: "e635838088b717ccfba83586375711c0axxxxxxx", operation.is_prefix: true, operation.des_url: "astro/" }, limit: 1, singleBatch: true } planSummary: IXSCAN { operation.des_url: 1.0 } keysExamined:21366 docsExamined:21366 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:1146 nreturned:1 reslen:768 locks:{ Global: { acquireCount: { r: 2294 }, acquireWaitCount: { r: 1135 }, timeAcquiringMicros: { r: 21004892 } }, Database: { acquireCount: { r: 1147 } }, Collection: { acquireCount: { r: 1147 } } } protocol:op_query 50414ms
2018-02-26T14:40:08.200+0800 I COMMAND [conn3935510] command fs.files command: find { find: "files", filter: { operation.sha1Code: "46cdc6924ad8fc298f2cac0b3e8536985xxxxxxx", operation.is_prefix: true, operation.des_url: "hebei/" }, limit: 1, singleBatch: true } planSummary: IXSCAN { operation.des_url: 1.0 } keysExamined:80967 docsExamined:80967 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:2807 nreturned:0 reslen:114 locks:{ Global: { acquireCount: { r: 5616 }, acquireWaitCount: { r: 2712 }, timeAcquiringMicros: { r: 53894897 } }, Database: { acquireCount: { r: 2808 } }, Collection: { acquireCount: { r: 2808 } } } protocol:op_query 127659ms
I learned about the plan cache mechanism by reading the MongoDB source code,MongoDB continue uses operation.des_url_1 Index scan internalQueryCacheEvictionRatio *works times for every similar queries, execute the replan mechanism if it exceeds 101 times advanced status. Otherwise, use the plan in the cache.If operation.des_url filter result count is less than 180999*10 will return IS_EOF status, will directly use the plan in the cache.
So after this query, we need to scan 180999*10 times for every similar queries,But all queries operation.des_url filter result count is less than 180999*10.so all queries get IS_EOF status,and directly use the plan in the cache.
All similar queries are used operation.des_url_1 index,But it needs to scan hundreds of thousands of times,Actually using operation.sha1Code_1 The index only needs to scan several times.
The operation.sha1Code filter result count:
db.files.find({"operation.sha1Code": "e635838088b717ccfba83586375711c0axxxxxxx"}).count()
1
db.files.find({"operation.sha1Code": "46cdc6924ad8fc298f2cac0b3e8536985xxxxxxx"}).count()
4
I think this is the main reason for our large number of slow queries,The mechanism to determine whether to use the plan in the cache is too simple,In some scenarios it may cause poor performance.
- duplicates
-
SERVER-32452 Replanning may not occur when a plan with an extremely high 'works' value is cached
-
- Closed
-