jackrabbit-oak-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Stefan Egli (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (OAK-8351) Long running RGC remove and getmore operations
Date Tue, 04 Jun 2019 09:25:00 GMT

    [ https://issues.apache.org/jira/browse/OAK-8351?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16855496#comment-16855496
] 

Stefan Egli commented on OAK-8351:
----------------------------------

The reason as to why the unfortunate plan was generated in the first place is still unclear.

However once it was generated the reason why it won is likely related to https://jira.mongodb.org/browse/SERVER-20616

Potential solutions include:
* splitting up the query into 2 (one for the simple splitDocTypes Default_Leaf(50 and Commit_Root_Only(60),
and one for the more complex Default_No_Branch(70))
* providing an index filter before running the find/deleteMany: the problem here is that Oak
might not know when mongod did a restart, thus would have to set the index filter regularly
and even then there might be a time window where no index filter would be set yet)
* providing a hint: the problem here is that MongoDB doesn't take a hint for deleteMany due
to https://jira.mongodb.org/browse/SERVER-1599 - and we'd need it for both find() and deleteMany().


> 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)

Mime
View raw message