-
Type: Bug
-
Resolution: Done
-
Priority: Major - P3
-
None
-
Affects Version/s: 2.4.14
-
Component/s: MMAPv1, Performance
-
None
-
ALL
-
Looks like optimizer choose improper index or doing full scan sometimes.
There's a lot of disk read(page faults) when this case happen (Normal status there's only a few hundreds of disk read, but suddenly disk reads is going up to 10k).
But I am not sure what execution plan optimizer choose, because looks like there's no way to distinguish execution plan of current running query.
But execution plan is good when I execute this query manually. But looks like sometimes query running different way. Weird thing is that I can not find documents which is matching "creator_id" even during this pattern of query is running.
Is there any way to tell the execution plan this query choose?
- Linux version : 2.6.32-358.6.2.el6.x86_64
- Total disk data size : 1.3TB (total index size is about 1/3)
- Total memory : 390GB
- Indexes
db01:PRIMARY> db.system.indexes.find().pretty() { "v" : 1, "key" : { "_id" : 1 }, "ns" : "db1.coll1", "name" : "_id_" } { "v" : 1, "key" : { "creator_id" : 1, "fd1" : 1, "fd2" : 1, "fd3" : 1, "fd4" : -1 }, "ns" : "db1.coll1", "name" : "creator_id_1_fd1_1_fd2_1_fd3_1_fd4_-1" } { "v" : 1, "key" : { "creator_id" : 1, "fd5" : 1, "fd6" : 1, "_id" : -1 }, "ns" : "db1.coll1", "name" : "creator_id_1_fd5_1_fd6_1__id_-1" } { "v" : 1, "key" : { "creator_id" : "hashed" }, "ns" : "db1.coll1", "name" : "creator_id_hashed" }
- Slow query profiling
db01:PRIMARY> db.system.profile.find().limit(1).pretty() { "op" : "getmore", "ns" : "db1.coll1", "query" : { "$comment" : "{\"cmt\": []}", "$query" : { "_id" : { "$gt" : ObjectId("51c161965ddbb86926acf403"), "$lt" : ObjectId("ffffffffffffffffffffffff") }, "creator_id" : ObjectId("51c1601bb14bd287915f6f76") }, "$orderby" : { "_id" : 1 } }, "cursorid" : NumberLong("7719472921984034942"), "ntoreturn" : 50, "keyUpdates" : 0, "numYield" : 847485, "lockStats" : { "timeLockedMicros" : { "r" : NumberLong("41763789634"), "w" : NumberLong(0) }, "timeAcquiringMicros" : { "r" : NumberLong("21953017915"), "w" : NumberLong(7) } }, "nreturned" : 6, "responseLength" : 152, "millis" : 21953838, "ts" : ISODate("2015-07-16T00:58:03.175Z"), "client" : "127.0.0.10", "allUsers" : [ ], "user" : "" }
- MongoDB Log
... getmore db1.coll1 query: { $comment: "{"cmt": []}", $query: { _id: { $gt: ObjectId('51c161965ddbb86926acf403'), $lt: ObjectId('ffffffffffffffffffffffff') }, creator_id: ObjectId('51c1601bb14bd287915f6f76') }, $orderby: { _id: 1 } } cursorid:7327170102889815944 ntoreturn:50 keyUpdates:0 numYields: 899085 locks(micros) r:48861004385 nreturned:12 reslen:284 25602157ms ```