[
https://issues.apache.org/jira/browse/OAK-8351?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16862175#comment-16862175
]
Stefan Egli commented on OAK-8351:
----------------------------------
+1, agree, I'll look into that next
> 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
>
> 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)
