[ https://issues.apache.org/jira/browse/OAK-8351?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16873151#comment-16873151 ]
Julian Reschke commented on OAK-8351: ------------------------------------- This should be set to "resolved" as it is fixed in trunk. > Long running RGC remove and getmore operations > ---------------------------------------------- > > Key: OAK-8351 > URL: https://issues.apache.org/jira/browse/OAK-8351 > Project: Jackrabbit Oak > Issue Type: Bug > Components: mongomk > Affects Versions: 1.12.0 > Reporter: Stefan Egli > Assignee: Stefan Egli > Priority: Major > Labels: candidate_oak_1_10, candidate_oak_1_8 > Fix For: 1.16.0 > > Attachments: OAK-8351-1.10.patch, OAK-8351-1.8.patch, OAK-8351.patch > > > On a mongodb setup a long running revision garbage collection operation has > been witnessed. The query was running for hours. Doing a > {{planCacheSetFilter}}, which hinted mongodb to use a specific index, > together with killing the running command resolved the situation. > The problem was that mongodb generated a query plan which scored high > (2.0003) but included an index scan through the {{\_id_}} index (and the > collection contained millions of documents). It also generated other, better, > plans, but they all "only" had the same high score, so it seemed legitimate > that mongodb would choose this one. > The reason why this, problematic, query plan resulted in a high score seems > to be that it does indeed find 101 documents after entering the first "or" - > but during query execution it would also enter the other "or" parts where it > has chosen to do a {{\_id_}} index scan. > The query involved was: > {noformat} > { > "_sdType" : { > "$in" : [ > > 50, > > 60, > > 70 > ] > }, > "$or" : [ > { > > "_sdType" : 50 > }, > { > > "_sdType" : 60 > }, > { > > "_sdType" : 70, > > "$or" : [ > > { > > "_id" : /.*-1\/0/ > > }, > > { > > "_id" : /[^-]*/, > > "_path" : /.*-1\/0/ > > } > > ], > > "_sdMaxRevTime" : { > > "$lt" : NumberLong(1551843365) > > } > }, > { > > "_sdType" : 70, > > "$or" : [ > > { > > "_id" : /.*-2\/0/ > > }, > > { > > "_id" : /[^-]*/, > > "_path" : /.*-2\/0/ > > } > > ], > > "_sdMaxRevTime" : { > > "$lt" : NumberLong(1550757370) > > } > } > ], > "_sdMaxRevTime" : { > "$lt" : > NumberLong(1551756965) > } > } > {noformat} > The problematic plan was: > {noformat} > { > "details" : { > "solution" : "(index-tagged expression tree: > tree=Node\n---Node\n------Node\n---------Node\n------------Node\n---------------Leaf > _id_, pos: 0, can combine? 1\n---------------Leaf \n------------Leaf _id_, > pos: 0, can combine? 1\n---------Leaf \n---------Leaf > \n------Node\n---------Node\n------------Node\n---------------Leaf _id_, pos: > 0, can combine? 1\n---------------Leaf \n------------Leaf _id_, pos: 0, can > combine? 1\n---------Leaf \n---------Leaf \n------Leaf > _sdType_1__sdMaxRevTime_1, pos: 0, can combine? 1\n------Leaf > _sdType_1__sdMaxRevTime_1, pos: 0, can combine? 1\n---Leaf Move to 2: > _sdType_1__sdMaxRevTime_1, pos: 1, can combine? 1. Move to 3: > _sdType_1__sdMaxRevTime_1, pos: 1, can combine? 1. \n---Leaf Move to 2: > _sdType_1__sdMaxRevTime_1, pos: 0, can combine? 1. Move to 3: > _sdType_1__sdMaxRevTime_1, pos: 0, can combine? 1. \n)" > }, > "reason" : { > "score" : 2.0003, > "stats" : { > "stage" : "FETCH", > "filter" : { > "$and" : [ > { > "_sdMaxRevTime" > : { > "$lt" : > NumberLong(1551410180) > } > }, > { > "_sdType" : { > "$in" : > [ > > 50, > > 60, > > 70 > ] > } > } > ] > }, > "nReturned" : 101, > "executionTimeMillisEstimate" : 0, > "works" : 101, > "advanced" : 101, > "needTime" : 0, > "needYield" : 0, > "saveState" : 3, > "restoreState" : 3, > "isEOF" : 0, > "invalidates" : 0, > "docsExamined" : 101, > "alreadyHasObj" : 0, > "inputStage" : { > "stage" : "OR", > "nReturned" : 101, > "executionTimeMillisEstimate" : > 0, > "works" : 101, > "advanced" : 101, > "needTime" : 0, > "needYield" : 0, > "saveState" : 3, > "restoreState" : 3, > "isEOF" : 0, > "invalidates" : 0, > "dupsTested" : 101, > "dupsDropped" : 0, > "recordIdsForgotten" : 0, > "inputStages" : [ > { > "stage" : > "IXSCAN", > "nReturned" : > 101, > > "executionTimeMillisEstimate" : 0, > "works" : 101, > "advanced" : > 101, > "needTime" : 0, > "needYield" : 0, > "saveState" : 3, > "restoreState" > : 3, > "isEOF" : 0, > "invalidates" : > 0, > "keyPattern" : { > > "_sdType" : 1, > > "_sdMaxRevTime" : 1 > }, > "indexName" : > "_sdType_1__sdMaxRevTime_1", > "isMultiKey" : > false, > "multiKeyPaths" > : { > > "_sdType" : [ ], > > "_sdMaxRevTime" : [ ] > }, > "isUnique" : > false, > "isSparse" : > true, > "isPartial" : > false, > "indexVersion" > : 2, > "direction" : > "forward", > "indexBounds" : > { > > "_sdType" : [ > > "[50, 50]" > ], > > "_sdMaxRevTime" : [ > > "[-inf.0, 1551410180)" > ] > }, > "keysExamined" > : 101, > "seeks" : 1, > "dupsTested" : > 0, > "dupsDropped" : > 0, > > "seenInvalidated" : 0 > }, > { > "stage" : > "IXSCAN", > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > "works" : 0, > "advanced" : 0, > "needTime" : 0, > "needYield" : 0, > "saveState" : 3, > "restoreState" > : 3, > "isEOF" : 0, > "invalidates" : > 0, > "keyPattern" : { > > "_sdType" : 1, > > "_sdMaxRevTime" : 1 > }, > "indexName" : > "_sdType_1__sdMaxRevTime_1", > "isMultiKey" : > false, > "multiKeyPaths" > : { > > "_sdType" : [ ], > > "_sdMaxRevTime" : [ ] > }, > "isUnique" : > false, > "isSparse" : > true, > "isPartial" : > false, > "indexVersion" > : 2, > "direction" : > "forward", > "indexBounds" : > { > > "_sdType" : [ > > "[60, 60]" > ], > > "_sdMaxRevTime" : [ > > "[-inf.0, 1551410180)" > ] > }, > "keysExamined" > : 0, > "seeks" : 0, > "dupsTested" : > 0, > "dupsDropped" : > 0, > > "seenInvalidated" : 0 > }, > { > "stage" : > "FETCH", > "filter" : { > "$and" > : [ > > { > > "_sdType" : { > > "$eq" : 70 > > } > > }, > > { > > "_sdMaxRevTime" : { > > "$lt" : NumberLong(1551496575) > > } > > } > ] > }, > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > "works" : 0, > "advanced" : 0, > "needTime" : 0, > "needYield" : 0, > "saveState" : 3, > "restoreState" > : 3, > "isEOF" : 0, > "invalidates" : > 0, > "docsExamined" > : 0, > "alreadyHasObj" > : 0, > "inputStage" : { > "stage" > : "OR", > > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > "works" > : 0, > > "advanced" : 0, > > "needTime" : 0, > > "needYield" : 0, > > "saveState" : 3, > > "restoreState" : 3, > "isEOF" > : 0, > > "invalidates" : 0, > > "dupsTested" : 0, > > "dupsDropped" : 0, > > "recordIdsForgotten" : 0, > > "inputStages" : [ > > { > > "stage" : "FETCH", > > "filter" : { > > "_path" : { > > "$regex" : ".*-1/0" > > } > > }, > > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > > "works" : 0, > > "advanced" : 0, > > "needTime" : 0, > > "needYield" : 0, > > "saveState" : 3, > > "restoreState" : 3, > > "isEOF" : 0, > > "invalidates" : 0, > > "docsExamined" : 0, > > "alreadyHasObj" : 0, > > "inputStage" : { > > "stage" : "IXSCAN", > > "filter" : { > > "_id" : { > > "$regex" : "[^-]*" > > } > > }, > > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > > "works" : 0, > > "advanced" : 0, > > "needTime" : 0, > > "needYield" : 0, > > "saveState" : 3, > > "restoreState" : 3, > > "isEOF" : 0, > > "invalidates" : 0, > > "keyPattern" : { > > "_id" : 1 > > }, > > "indexName" : "_id_", > > "isMultiKey" : false, > > "multiKeyPaths" : { > > "_id" : [ ] > > }, > > "isUnique" : true, > > "isSparse" : false, > > "isPartial" : false, > > "indexVersion" : 2, > > "direction" : "forward", > > "indexBounds" : { > > "_id" : [ > > "[\"\", {})", > > "[/[^-]*/, /[^-]*/]" > > ] > > }, > > "keysExamined" : 0, > > "seeks" : 0, > > "dupsTested" : 0, > > "dupsDropped" : 0, > > "seenInvalidated" : 0 > > } > > }, > > { > > "stage" : "IXSCAN", > > "filter" : { > > "$or" : [ > > { > > "_id" : { > > "$regex" : ".*-1/0" > > } > > } > > ] > > }, > > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > > "works" : 0, > > "advanced" : 0, > > "needTime" : 0, > > "needYield" : 0, > > "saveState" : 3, > > "restoreState" : 3, > > "isEOF" : 0, > > "invalidates" : 0, > > "keyPattern" : { > > "_id" : 1 > > }, > > "indexName" : "_id_", > > "isMultiKey" : false, > > "multiKeyPaths" : { > > "_id" : [ ] > > }, > > "isUnique" : true, > > "isSparse" : false, > > "isPartial" : false, > > "indexVersion" : 2, > > "direction" : "forward", > > "indexBounds" : { > > "_id" : [ > > "[\"\", {})", > > "[/.*-1/0/, /.*-1/0/]" > > ] > > }, > > "keysExamined" : 0, > > "seeks" : 0, > > "dupsTested" : 0, > > "dupsDropped" : 0, > > "seenInvalidated" : 0 > > } > ] > } > }, > { > "stage" : > "FETCH", > "filter" : { > "$and" > : [ > > { > > "_sdType" : { > > "$eq" : 70 > > } > > }, > > { > > "_sdMaxRevTime" : { > > "$lt" : NumberLong(1550757370) > > } > > } > ] > }, > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > "works" : 0, > "advanced" : 0, > "needTime" : 0, > "needYield" : 0, > "saveState" : 3, > "restoreState" > : 3, > "isEOF" : 0, > "invalidates" : > 0, > "docsExamined" > : 0, > "alreadyHasObj" > : 0, > "inputStage" : { > "stage" > : "OR", > > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > "works" > : 0, > > "advanced" : 0, > > "needTime" : 0, > > "needYield" : 0, > > "saveState" : 3, > > "restoreState" : 3, > "isEOF" > : 0, > > "invalidates" : 0, > > "dupsTested" : 0, > > "dupsDropped" : 0, > > "recordIdsForgotten" : 0, > > "inputStages" : [ > > { > > "stage" : "FETCH", > > "filter" : { > > "_path" : { > > "$regex" : ".*-2/0" > > } > > }, > > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > > "works" : 0, > > "advanced" : 0, > > "needTime" : 0, > > "needYield" : 0, > > "saveState" : 3, > > "restoreState" : 3, > > "isEOF" : 0, > > "invalidates" : 0, > > "docsExamined" : 0, > > "alreadyHasObj" : 0, > > "inputStage" : { > > "stage" : "IXSCAN", > > "filter" : { > > "_id" : { > > "$regex" : "[^-]*" > > } > > }, > > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > > "works" : 0, > > "advanced" : 0, > > "needTime" : 0, > > "needYield" : 0, > > "saveState" : 3, > > "restoreState" : 3, > > "isEOF" : 0, > > "invalidates" : 0, > > "keyPattern" : { > > "_id" : 1 > > }, > > "indexName" : "_id_", > > "isMultiKey" : false, > > "multiKeyPaths" : { > > "_id" : [ ] > > }, > > "isUnique" : true, > > "isSparse" : false, > > "isPartial" : false, > > "indexVersion" : 2, > > "direction" : "forward", > > "indexBounds" : { > > "_id" : [ > > "[\"\", {})", > > "[/[^-]*/, /[^-]*/]" > > ] > > }, > > "keysExamined" : 0, > > "seeks" : 0, > > "dupsTested" : 0, > > "dupsDropped" : 0, > > "seenInvalidated" : 0 > > } > > }, > > { > > "stage" : "IXSCAN", > > "filter" : { > > "$or" : [ > > { > > "_id" : { > > "$regex" : ".*-2/0" > > } > > } > > ] > > }, > > "nReturned" : 0, > > "executionTimeMillisEstimate" : 0, > > "works" : 0, > > "advanced" : 0, > > "needTime" : 0, > > "needYield" : 0, > > "saveState" : 3, > > "restoreState" : 3, > > "isEOF" : 0, > > "invalidates" : 0, > > "keyPattern" : { > > "_id" : 1 > > }, > > "indexName" : "_id_", > > "isMultiKey" : false, > > "multiKeyPaths" : { > > "_id" : [ ] > > }, > > "isUnique" : true, > > "isSparse" : false, > > "isPartial" : false, > > "indexVersion" : 2, > > "direction" : "forward", > > "indexBounds" : { > > "_id" : [ > > "[\"\", {})", > > "[/.*-2/0/, /.*-2/0/]" > > ] > > }, > > "keysExamined" : 0, > > "seeks" : 0, > > "dupsTested" : 0, > > "dupsDropped" : 0, > > "seenInvalidated" : 0 > > } > ] > } > } > ] > } > } > }, > "feedback" : { > "nfeedback" : 18, > "scores" : [ > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > }, > { > "score" : 2.0003 > } > ] > }, > "filterSet" : false > } > {noformat} -- This message was sent by Atlassian JIRA (v7.6.3#76005)