From oak-issues-return-72860-archive-asf-public=cust-asf.ponee.io@jackrabbit.apache.org Wed Jun 26 07:50:03 2019 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [207.244.88.153]) by mx-eu-01.ponee.io (Postfix) with SMTP id 939F918067C for ; Wed, 26 Jun 2019 09:50:02 +0200 (CEST) Received: (qmail 52236 invoked by uid 500); 26 Jun 2019 07:50:02 -0000 Mailing-List: contact oak-issues-help@jackrabbit.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: oak-dev@jackrabbit.apache.org Delivered-To: mailing list oak-issues@jackrabbit.apache.org Received: (qmail 52213 invoked by uid 99); 26 Jun 2019 07:50:02 -0000 Received: from mailrelay1-us-west.apache.org (HELO mailrelay1-us-west.apache.org) (209.188.14.139) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 26 Jun 2019 07:50:01 +0000 Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id EAD95E2E2E for ; Wed, 26 Jun 2019 07:50:00 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 5ADAF25818 for ; Wed, 26 Jun 2019 07:50:00 +0000 (UTC) Date: Wed, 26 Jun 2019 07:50:00 +0000 (UTC) From: "Julian Reschke (JIRA)" To: oak-issues@jackrabbit.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Comment Edited] (OAK-8351) Long running RGC remove and getmore operations MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/OAK-8351?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16873017#comment-16873017 ] Julian Reschke edited comment on OAK-8351 at 6/26/19 7:49 AM: -------------------------------------------------------------- I just checked: r1862044 has one conflict in 1.10, and that's just around import statements and can be easily resolved. 1.8 seems to more complex, probably due to OAK-7645 not being present. was (Author: reschke): I just checked: r1862044 has one conflict in 1.10, and that's just around import statements and can be easily resolved. > 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)