This is an automated email from the ASF dual-hosted git repository.
daim pushed a commit to branch DetailedGC/OAK-10199
in repository https://gitbox.apache.org/repos/asf/jackrabbit-oak.git
The following commit(s) were added to refs/heads/DetailedGC/OAK-10199 by this
push:
new e02795ed87 Merge pull request #1079 from apache/OAK-10378
e02795ed87 is described below
commit e02795ed878ffdca9703450c325a0f94339d4b27
Author: Rishabh Kumar <[email protected]>
AuthorDate: Fri Sep 1 13:37:25 2023 +0530
Merge pull request #1079 from apache/OAK-10378
OAK-10378 : added metrics to collect detailedGC cycle & deleted properties
data
---
.../document/DetailedRevisionGCStatsCollector.java | 40 ++++++
.../DetailedRevisionGCStatsCollectorImpl.java | 146 +++++++++++++++++++
.../oak/plugins/document/DocumentStore.java | 2 +-
.../plugins/document/VersionGarbageCollector.java | 62 ++++++--
.../document/util/LoggingDocumentStoreWrapper.java | 1 +
.../DetailedRevisionGCStatsCollectorImplTest.java | 160 +++++++++++++++++++++
.../oak/plugins/document/VersionGCStatsTest.java | 22 ++-
.../document/VersionGarbageCollectorIT.java | 63 +++++++-
8 files changed, 465 insertions(+), 31 deletions(-)
diff --git
a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollector.java
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollector.java
new file mode 100644
index 0000000000..151195f3bd
--- /dev/null
+++
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollector.java
@@ -0,0 +1,40 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.apache.jackrabbit.oak.plugins.document;
+
+import
org.apache.jackrabbit.oak.plugins.document.VersionGarbageCollector.VersionGCStats;
+
+/**
+ * Collector interface for {@link DocumentNodeStore} Detailed revision garbage
collection
+ * statistics.
+ */
+public interface DetailedRevisionGCStatsCollector {
+
+ void documentRead();
+
+ void propertiesDeleted(long numProps);
+
+ void documentsUpdated(long numDocs);
+
+ void documentsSkippedUpdation(long numDocs);
+
+ void started();
+
+ void finished(VersionGCStats stats);
+}
diff --git
a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollectorImpl.java
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollectorImpl.java
new file mode 100644
index 0000000000..b400f7401b
--- /dev/null
+++
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollectorImpl.java
@@ -0,0 +1,146 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.apache.jackrabbit.oak.plugins.document;
+
+import
org.apache.jackrabbit.oak.plugins.document.VersionGarbageCollector.VersionGCStats;
+import org.apache.jackrabbit.oak.stats.CounterStats;
+import org.apache.jackrabbit.oak.stats.MeterStats;
+import org.apache.jackrabbit.oak.stats.StatisticsProvider;
+import org.apache.jackrabbit.oak.stats.TimerStats;
+
+import static java.util.concurrent.TimeUnit.MICROSECONDS;
+import static org.apache.jackrabbit.oak.stats.StatsOptions.DEFAULT;
+import static org.apache.jackrabbit.oak.stats.StatsOptions.METRICS_ONLY;
+
+/**
+ * {@link DocumentNodeStore} Detailed revision garbage collection statistics.
+ */
+class DetailedRevisionGCStatsCollectorImpl implements
DetailedRevisionGCStatsCollector {
+
+ static final String DETAILED_GC = "DetailedGC";
+ static final String READ_DOC = "READ_DOC";
+ static final String DELETED_PROPERTY = "DELETED_PROPERTY";
+ static final String UPDATED_DOC = "UPDATED_DOC";
+ static final String SKIPPED_DOC = "SKIPPED_DOC";
+ static final String DETAILED_GC_ACTIVE_TIMER = "DETAILED_GC_ACTIVE_TIMER";
+ static final String DETAILED_GC_TIMER = "DETAILED_GC_TIMER";
+ static final String COLLECT_DETAILED_GARBAGE_TIMER =
"COLLECT_DETAILED_GARBAGE_TIMER";
+ static final String COLLECT_DELETED_PROPS_TIMER =
"COLLECT_DELETED_PROPS_TIMER";
+ static final String COLLECT_DELETED_OLD_REVS_TIMER =
"COLLECT_DELETED_OLD_REVS_TIMER";
+ static final String COLLECT_UNMERGED_BC_TIMER =
"COLLECT_UNMERGED_BC_TIMER";
+ static final String DELETE_DETAILED_GC_DOCS_TIMER =
"DELETE_DETAILED_GC_DOCS_TIMER";
+
+ static final String COUNTER = "COUNTER";
+ static final String FAILURE_COUNTER = "FAILURE";
+
+ private final MeterStats readDoc;
+ private final MeterStats deletedProperty;
+ private final MeterStats updatedDoc;
+ private final MeterStats skippedDoc;
+ private final TimerStats detailedGCActiveTimer;
+ private final TimerStats detailedGCTimer;
+ private final TimerStats collectDetailedGarbageTimer;
+ private final TimerStats collectDeletedPropsTimer;
+ private final TimerStats collectDeletedOldRevsTimer;
+ private final TimerStats collectUnmergedBCTimer;
+ private final TimerStats deleteDetailedGCDocsTimer;
+
+ private final CounterStats counter;
+ private final CounterStats failureCounter;
+
+ DetailedRevisionGCStatsCollectorImpl(StatisticsProvider provider) {
+
+ readDoc = meter(provider, READ_DOC);
+ deletedProperty = meter(provider, DELETED_PROPERTY);
+ updatedDoc = meter(provider, UPDATED_DOC);
+ skippedDoc = meter(provider, SKIPPED_DOC);
+
+ detailedGCActiveTimer = timer(provider, DETAILED_GC_ACTIVE_TIMER);
+ detailedGCTimer = timer(provider, DETAILED_GC_TIMER);
+ collectDetailedGarbageTimer = timer(provider,
COLLECT_DETAILED_GARBAGE_TIMER);
+ collectDeletedPropsTimer = timer(provider,
COLLECT_DELETED_PROPS_TIMER);
+ collectDeletedOldRevsTimer = timer(provider,
COLLECT_DELETED_OLD_REVS_TIMER);
+ collectUnmergedBCTimer = timer(provider, COLLECT_UNMERGED_BC_TIMER);
+ deleteDetailedGCDocsTimer = timer(provider,
DELETE_DETAILED_GC_DOCS_TIMER);
+
+ counter = counter(provider, COUNTER);
+ failureCounter = counter(provider, FAILURE_COUNTER);
+ }
+
+ //---------------------< DetailedRevisionGCStatsCollector
>-------------------------
+
+ @Override
+ public void documentRead() {
+ readDoc.mark();
+ }
+
+ @Override
+ public void propertiesDeleted(long numProps) {
+ deletedProperty.mark(numProps);
+ }
+
+ @Override
+ public void documentsUpdated(long numDocs) {
+ updatedDoc.mark(numDocs);
+ }
+
+ @Override
+ public void documentsSkippedUpdation(long numDocs) {
+ skippedDoc.mark(numDocs);
+ }
+
+ @Override
+ public void started() {
+ counter.inc();
+ }
+
+ @Override
+ public void finished(VersionGCStats stats) {
+ detailedGCActiveTimer.update(stats.detailedGCActiveElapsed,
MICROSECONDS);
+ detailedGCTimer.update(stats.detailedGCDocsElapsed, MICROSECONDS);
+
collectDetailedGarbageTimer.update(stats.collectDetailedGarbageElapsed,
MICROSECONDS);
+ collectDeletedPropsTimer.update(stats.collectDeletedPropsElapsed,
MICROSECONDS);
+ collectDeletedOldRevsTimer.update(stats.collectDeletedOldRevsElapsed,
MICROSECONDS);
+ collectUnmergedBCTimer.update(stats.collectUnmergedBCElapsed,
MICROSECONDS);
+ deleteDetailedGCDocsTimer.update(stats.deleteDetailedGCDocsElapsed,
MICROSECONDS);
+ if (!stats.success) {
+ failureCounter.inc();
+ }
+ }
+
+
+ //----------------------------< internal
>----------------------------------
+
+ private static MeterStats meter(StatisticsProvider provider, String name) {
+ return provider.getMeter(qualifiedName(name), DEFAULT);
+ }
+
+ private static TimerStats timer(StatisticsProvider provider, String name) {
+ return provider.getTimer(qualifiedName(name), METRICS_ONLY);
+ }
+
+ private static CounterStats counter(StatisticsProvider provider, String
name) {
+ return provider.getCounterStats(qualifiedName(name), METRICS_ONLY);
+ }
+
+ private static String qualifiedName(String metricName) {
+ return DETAILED_GC + "." + metricName;
+ }
+
+}
diff --git
a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStore.java
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStore.java
index 28e6b22b1a..8b73a57714 100644
---
a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStore.java
+++
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentStore.java
@@ -546,7 +546,7 @@ public interface DocumentStore {
/**
* Performs a conditional update (e.g. using
* {@link UpdateOp.Condition.Type#EXISTS} and only update the
- * document if the condition is <code>true</code>. The returned documents
are
+ * document(s) if the respective condition is <code>true</code>. The
returned documents are
* immutable.
* <p>
* In case of a {@code DocumentStoreException} (e.g. when a communication
diff --git
a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java
index a32ded6c5b..d20f5683bc 100644
---
a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java
+++
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java
@@ -78,6 +78,7 @@ import static
org.apache.jackrabbit.oak.plugins.document.NodeDocument.MODIFIED_I
import static
org.apache.jackrabbit.oak.plugins.document.NodeDocument.SplitDocType.COMMIT_ROOT_ONLY;
import static
org.apache.jackrabbit.oak.plugins.document.NodeDocument.SplitDocType.DEFAULT_LEAF;
import static
org.apache.jackrabbit.oak.plugins.document.NodeDocument.SplitDocType.DEFAULT_NO_BRANCH;
+import static org.apache.jackrabbit.oak.stats.StatisticsProvider.NOOP;
import static org.slf4j.helpers.MessageFormatter.arrayFormat;
public class VersionGarbageCollector {
@@ -129,7 +130,8 @@ public class VersionGarbageCollector {
private final AtomicReference<GCJob> collector = newReference();
private VersionGCOptions options;
private GCMonitor gcMonitor = GCMonitor.EMPTY;
- private RevisionGCStats gcStats = new
RevisionGCStats(StatisticsProvider.NOOP);
+ private RevisionGCStats gcStats = new RevisionGCStats(NOOP);
+ private DetailedRevisionGCStatsCollector detailedGCStats = new
DetailedRevisionGCStatsCollectorImpl(NOOP);
VersionGarbageCollector(DocumentNodeStore nodeStore,
VersionGCSupport gcSupport,
@@ -143,6 +145,7 @@ public class VersionGarbageCollector {
void setStatisticsProvider(StatisticsProvider provider) {
this.gcStats = new RevisionGCStats(provider);
+ this.detailedGCStats = new
DetailedRevisionGCStatsCollectorImpl(provider);
}
@NotNull
@@ -161,6 +164,9 @@ public class VersionGarbageCollector {
VersionGCStats overall = new VersionGCStats();
overall.active.start();
gcStats.started();
+ if (detailedGCEnabled) {
+ detailedGCStats.started();
+ }
boolean success = false;
try {
long averageDurationMs = 0;
@@ -186,6 +192,9 @@ public class VersionGarbageCollector {
collector.set(null);
overall.success = success;
gcStats.finished(overall);
+ if (detailedGCEnabled) {
+ detailedGCStats.finished(overall);
+ }
if (overall.iterationCount > 1) {
gcMonitor.info("Revision garbage collection finished after
{} iterations - aggregate statistics: {}",
overall.iterationCount, overall);
@@ -289,6 +298,7 @@ public class VersionGarbageCollector {
int deletedPropsGCCount;
final TimeDurationFormatter df = TimeDurationFormatter.forLogging();
final Stopwatch active = Stopwatch.createUnstarted();
+ final Stopwatch detailedGCActive = Stopwatch.createUnstarted();
final Stopwatch collectDeletedDocs = Stopwatch.createUnstarted();
final Stopwatch checkDeletedDocs = Stopwatch.createUnstarted();
final Stopwatch detailedGCDocs = Stopwatch.createUnstarted();
@@ -298,12 +308,14 @@ public class VersionGarbageCollector {
final Stopwatch updateResurrectedDocuments =
Stopwatch.createUnstarted();
final Stopwatch deleteDeletedDocs = Stopwatch.createUnstarted();
final Stopwatch collectAndDeleteSplitDocs =
Stopwatch.createUnstarted();
+ final Stopwatch collectDetailedGarbage = Stopwatch.createUnstarted();
final Stopwatch collectDeletedProps = Stopwatch.createUnstarted();
final Stopwatch collectDeletedOldRevs = Stopwatch.createUnstarted();
final Stopwatch collectUnmergedBC = Stopwatch.createUnstarted();
- long activeElapsed, collectDeletedDocsElapsed,
checkDeletedDocsElapsed, deleteDeletedDocsElapsed,
collectAndDeleteSplitDocsElapsed,
- deleteSplitDocsElapsed, sortDocIdsElapsed,
updateResurrectedDocumentsElapsed, detailedGCDocsElapsed,
collectDeletedPropsElapsed,
- deleteDetailedGCDocsElapsed, collectDeletedOldRevsElapsed,
collectUnmergedBCElapsed;
+ long activeElapsed, detailedGCActiveElapsed,
collectDeletedDocsElapsed, checkDeletedDocsElapsed, deleteDeletedDocsElapsed,
+ collectAndDeleteSplitDocsElapsed, deleteSplitDocsElapsed,
sortDocIdsElapsed, updateResurrectedDocumentsElapsed,
+ detailedGCDocsElapsed, collectDetailedGarbageElapsed,
collectDeletedPropsElapsed, deleteDetailedGCDocsElapsed,
+ collectDeletedOldRevsElapsed, collectUnmergedBCElapsed;
@Override
public String toString() {
@@ -342,6 +354,7 @@ public class VersionGarbageCollector {
df.format(collectAndDeleteSplitDocs.elapsed(MICROSECONDS), MICROSECONDS),
df.format(detailedGCDocs.elapsed(MICROSECONDS),
MICROSECONDS),
df.format(deleteDetailedGCDocs.elapsed(MICROSECONDS),
MICROSECONDS),
+
df.format(collectDetailedGarbage.elapsed(MICROSECONDS), MICROSECONDS),
df.format(collectDeletedProps.elapsed(MICROSECONDS),
MICROSECONDS),
df.format(collectDeletedOldRevs.elapsed(MICROSECONDS),
MICROSECONDS),
df.format(collectUnmergedBC.elapsed(MICROSECONDS),
MICROSECONDS),
@@ -361,6 +374,7 @@ public class VersionGarbageCollector {
", updatedDetailedGCDocsCount=" +
updatedDetailedGCDocsCount +
", deletedPropsGCCount=" + deletedPropsGCCount +
", iterationCount=" + iterationCount +
+ ", timeDetailedGCActive=" +
df.format(detailedGCActiveElapsed, MICROSECONDS) +
", timeActive=" + df.format(activeElapsed, MICROSECONDS) +
", " + timings + "}";
}
@@ -385,6 +399,7 @@ public class VersionGarbageCollector {
if (run.iterationCount > 0) {
// run is cumulative with times in elapsed fields
this.activeElapsed += run.activeElapsed;
+ this.detailedGCActiveElapsed += run.detailedGCActiveElapsed;
this.collectDeletedDocsElapsed +=
run.collectDeletedDocsElapsed;
this.checkDeletedDocsElapsed += run.checkDeletedDocsElapsed;
this.deleteDeletedDocsElapsed += run.deleteDeletedDocsElapsed;
@@ -394,12 +409,14 @@ public class VersionGarbageCollector {
this.updateResurrectedDocumentsElapsed +=
run.updateResurrectedDocumentsElapsed;
this.detailedGCDocsElapsed += run.detailedGCDocsElapsed;
this.deleteDetailedGCDocsElapsed +=
run.deleteDetailedGCDocsElapsed;
+ this.collectDetailedGarbageElapsed +=
run.collectDetailedGarbageElapsed;
this.collectDeletedPropsElapsed +=
run.collectDeletedPropsElapsed;
this.collectDeletedOldRevsElapsed +=
run.collectDeletedOldRevsElapsed;
this.collectUnmergedBCElapsed += run.collectUnmergedBCElapsed;
} else {
// single run -> read from stop watches
this.activeElapsed += run.active.elapsed(MICROSECONDS);
+ this.detailedGCActiveElapsed +=
run.detailedGCActive.elapsed(MICROSECONDS);
this.collectDeletedDocsElapsed +=
run.collectDeletedDocs.elapsed(MICROSECONDS);
this.checkDeletedDocsElapsed +=
run.checkDeletedDocs.elapsed(MICROSECONDS);
this.deleteDeletedDocsElapsed +=
run.deleteDeletedDocs.elapsed(MICROSECONDS);
@@ -409,6 +426,7 @@ public class VersionGarbageCollector {
this.updateResurrectedDocumentsElapsed +=
run.updateResurrectedDocuments.elapsed(MICROSECONDS);
this.detailedGCDocsElapsed +=
run.detailedGCDocs.elapsed(MICROSECONDS);
this.deleteDetailedGCDocsElapsed +=
run.deleteDetailedGCDocs.elapsed(MICROSECONDS);
+ this.collectDetailedGarbageElapsed +=
run.collectDetailedGarbage.elapsed(MICROSECONDS);
this.collectDeletedPropsElapsed +=
run.collectDeletedProps.elapsed(MICROSECONDS);
this.collectDeletedOldRevsElapsed +=
run.collectDeletedOldRevs.elapsed(MICROSECONDS);
this.collectUnmergedBCElapsed +=
run.collectUnmergedBC.elapsed(MICROSECONDS);
@@ -424,6 +442,7 @@ public class VersionGarbageCollector {
SORTING,
SPLITS_CLEANUP,
DETAILED_GC,
+ DETAILED_GC_COLLECT_GARBAGE,
DETAILED_GC_COLLECT_PROPS,
DETAILED_GC_COLLECT_OLD_REVS,
DETAILED_GC_COLLECT_UNMERGED_BC,
@@ -457,6 +476,7 @@ public class VersionGarbageCollector {
this.watches.put(GCPhase.SPLITS_CLEANUP,
stats.collectAndDeleteSplitDocs);
this.watches.put(GCPhase.UPDATING,
stats.updateResurrectedDocuments);
this.watches.put(GCPhase.DETAILED_GC, stats.detailedGCDocs);
+ this.watches.put(GCPhase.DETAILED_GC_COLLECT_GARBAGE,
stats.collectDetailedGarbage);
this.watches.put(GCPhase.DETAILED_GC_COLLECT_PROPS,
stats.collectDeletedProps);
this.watches.put(GCPhase.DETAILED_GC_COLLECT_OLD_REVS,
stats.collectDeletedOldRevs);
this.watches.put(GCPhase.DETAILED_GC_COLLECT_UNMERGED_BC,
stats.collectUnmergedBC);
@@ -586,6 +606,7 @@ public class VersionGarbageCollector {
// now run detailed GC if enabled
if (detailedGCEnabled) {
+ stats.detailedGCActive.start();
if (rec.ignoreDetailedGCDueToCheckPoint) {
phases.stats.ignoredDetailedGCDueToCheckPoint = true;
monitor.skipped("Checkpoint prevented detailed
revision garbage collection");
@@ -610,6 +631,9 @@ public class VersionGarbageCollector {
rec.evaluate(stats);
monitor.info("Revision garbage collection finished in {}. {}",
TimeDurationFormatter.forLogging().format(phases.elapsed.elapsed(MICROSECONDS),
MICROSECONDS), stats);
+ if (detailedGCEnabled) {
+ stats.detailedGCActive.stop();
+ }
stats.active.stop();
return stats;
}
@@ -670,9 +694,9 @@ public class VersionGarbageCollector {
lastDoc = doc;
// collect the data to delete in next step
- if (phases.start(GCPhase.COLLECTING)) {
+ if
(phases.start(GCPhase.DETAILED_GC_COLLECT_GARBAGE)) {
gc.collectGarbage(doc, phases);
- phases.stop(GCPhase.COLLECTING);
+
phases.stop(GCPhase.DETAILED_GC_COLLECT_GARBAGE);
}
final Long modified = lastDoc.getModified();
@@ -697,15 +721,7 @@ public class VersionGarbageCollector {
} finally {
Utils.closeIfCloseable(itr);
phases.stats.oldestModifiedDocTimeStamp =
fromModifiedMs;
- if (fromModifiedMs > oldModifiedMs) {
- // we have moved ahead, now we can reset
oldestModifiedId to min value
- fromId = MIN_ID_VALUE;
- phases.stats.oldestModifiedDocId =
MIN_ID_VALUE;
- } else {
- // there are still documents pending at oldest
Modified timestamp,
- // save the last _id traversed to avoid
re-fetching of ids
- phases.stats.oldestModifiedDocId = fromId;
- }
+ phases.stats.oldestModifiedDocId = fromId;
oldModifiedMs = fromModifiedMs;
}
// if we didn't find any document i.e. either we are
already at last document
@@ -826,6 +842,16 @@ public class VersionGarbageCollector {
private final Stopwatch timer;
private final List<UpdateOp> updateOpList;
+ /**
+ * Map of documentId => total no. of deleted properties.
+ * <p>
+ *
+ * The document can be updated or property might get recreated between
collecting and deletion phases.
+ * This would lead to document not getting deleted (since now modified
date & mod count would have changed)
+ * SO the Bulk API wouldn't update this doc.
+ * <p>
+ * In order to calculate the correct no. of updated documents &
deleted properties, we save them in a map
+ */
private final Map<String, Integer> deletedPropsCountMap;
private int garbageDocsCount;
private int totalGarbageDocsCount;
@@ -841,6 +867,7 @@ public class VersionGarbageCollector {
public void collectGarbage(final NodeDocument doc, final GCPhases
phases) {
+ detailedGCStats.documentRead();
monitor.info("Collecting Detailed Garbage for doc [{}]",
doc.getId());
final UpdateOp op = new UpdateOp(requireNonNull(doc.getId()),
false);
@@ -955,6 +982,11 @@ public class VersionGarbageCollector {
updateOpList.clear();
deletedPropsCountMap.clear();
garbageDocsCount = 0;
+
+ // save stats
+ detailedGCStats.propertiesDeleted(deletedProps);
+ detailedGCStats.documentsUpdated(updatedDocs);
+ detailedGCStats.documentsSkippedUpdation(oldDocs.size() -
updatedDocs);
} finally {
delayOnModifications(timer.stop().elapsed(MILLISECONDS),
cancel);
}
diff --git
a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/util/LoggingDocumentStoreWrapper.java
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/util/LoggingDocumentStoreWrapper.java
index 099eca91de..7cde39cffc 100644
---
a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/util/LoggingDocumentStoreWrapper.java
+++
b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/util/LoggingDocumentStoreWrapper.java
@@ -283,6 +283,7 @@ public class LoggingDocumentStoreWrapper implements
DocumentStore {
}
@Override
+ @NotNull
public <T extends Document> List<T> findAndUpdate(@NotNull Collection<T>
collection, @NotNull List<UpdateOp> updateOps) {
try {
logMethod("findAndUpdate", collection, updateOps);
diff --git
a/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollectorImplTest.java
b/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollectorImplTest.java
new file mode 100644
index 0000000000..b84084d439
--- /dev/null
+++
b/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/DetailedRevisionGCStatsCollectorImplTest.java
@@ -0,0 +1,160 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.apache.jackrabbit.oak.plugins.document;
+
+import com.codahale.metrics.Counter;
+import com.codahale.metrics.Meter;
+import com.codahale.metrics.Timer;
+import org.apache.jackrabbit.oak.commons.concurrent.ExecutorCloser;
+import org.apache.jackrabbit.oak.plugins.metric.MetricStatisticsProvider;
+import org.apache.jackrabbit.oak.stats.MeterStats;
+import org.junit.After;
+import org.junit.Test;
+
+import java.util.concurrent.ScheduledExecutorService;
+
+import static java.lang.management.ManagementFactory.getPlatformMBeanServer;
+import static java.util.concurrent.Executors.newSingleThreadScheduledExecutor;
+import static java.util.concurrent.TimeUnit.MILLISECONDS;
+import static java.util.concurrent.TimeUnit.NANOSECONDS;
+import static org.apache.commons.lang3.reflect.FieldUtils.readField;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.COLLECT_DELETED_OLD_REVS_TIMER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.COLLECT_DELETED_PROPS_TIMER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.COLLECT_DETAILED_GARBAGE_TIMER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.COLLECT_UNMERGED_BC_TIMER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.COUNTER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.DELETED_PROPERTY;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.DELETE_DETAILED_GC_DOCS_TIMER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.DETAILED_GC;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.DETAILED_GC_ACTIVE_TIMER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.DETAILED_GC_TIMER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.FAILURE_COUNTER;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.READ_DOC;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.SKIPPED_DOC;
+import static
org.apache.jackrabbit.oak.plugins.document.DetailedRevisionGCStatsCollectorImpl.UPDATED_DOC;
+import static org.junit.Assert.assertEquals;
+
+/**
+ * Unit Cases for {@link DetailedRevisionGCStatsCollectorImpl}
+ */
+public class DetailedRevisionGCStatsCollectorImplTest {
+
+ private final ScheduledExecutorService executor =
newSingleThreadScheduledExecutor();
+ private final MetricStatisticsProvider statsProvider = new
MetricStatisticsProvider(getPlatformMBeanServer(), executor);
+ private final DetailedRevisionGCStatsCollectorImpl stats = new
DetailedRevisionGCStatsCollectorImpl(statsProvider);
+
+ @After
+ public void shutDown(){
+ statsProvider.close();
+ new ExecutorCloser(executor).close();
+ }
+
+ @Test
+ public void getReadDocCount() throws IllegalAccessException {
+ final Meter m = getMeter(READ_DOC);
+ long count = m.getCount();
+ stats.documentRead();
+ assertEquals(count + 1, m.getCount());
+ assertEquals(count + 1, ((MeterStats) readField(stats, "readDoc",
true)).getCount());
+ }
+
+ @Test
+ public void getDocumentsSkippedUpdationCount() throws
IllegalAccessException {
+ Meter m = getMeter(SKIPPED_DOC);
+ long count = m.getCount();
+ stats.documentsSkippedUpdation(17);
+ assertEquals(count + 17, m.getCount());
+ assertEquals(count + 17, ((MeterStats) readField(stats, "skippedDoc",
true)).getCount());
+ }
+
+ @Test
+ public void getPropertiesDeletedCount() throws IllegalAccessException {
+ Meter m = getMeter(DELETED_PROPERTY);
+ long count = m.getCount();
+ stats.propertiesDeleted(10);
+ assertEquals(count + 10, m.getCount());
+ assertEquals(count + 10, ((MeterStats) readField(stats,
"deletedProperty", true)).getCount());
+ }
+
+ @Test
+ public void getDocumentsUpdatedCount() throws IllegalAccessException {
+ Meter m = getMeter(UPDATED_DOC);
+ long count = m.getCount();
+ stats.documentsUpdated(10);
+ assertEquals(count + 10, m.getCount());
+ assertEquals(count + 10, ((MeterStats) readField(stats, "updatedDoc",
true)).getCount());
+ }
+
+ @Test
+ public void timers() {
+ final VersionGarbageCollector.VersionGCStats vgcs = new
VersionGarbageCollector.VersionGCStats();
+ vgcs.detailedGCActiveElapsed = MILLISECONDS.toMicros(2);
+ vgcs.detailedGCDocsElapsed = MILLISECONDS.toMicros(3);
+ vgcs.collectDetailedGarbageElapsed = MILLISECONDS.toMicros(5);
+ vgcs.collectDeletedPropsElapsed = MILLISECONDS.toMicros(7);
+ vgcs.collectDeletedOldRevsElapsed = MILLISECONDS.toMicros(11);
+ vgcs.collectUnmergedBCElapsed = MILLISECONDS.toMicros(13);
+ vgcs.deleteDetailedGCDocsElapsed = MILLISECONDS.toMicros(15);
+ vgcs.detailedGCActive.start();
+
+ stats.finished(vgcs);
+ assertTimer(2, DETAILED_GC_ACTIVE_TIMER);
+ assertTimer(3, DETAILED_GC_TIMER);
+ assertTimer(5, COLLECT_DETAILED_GARBAGE_TIMER);
+ assertTimer(7, COLLECT_DELETED_PROPS_TIMER);
+ assertTimer(11, COLLECT_DELETED_OLD_REVS_TIMER);
+ assertTimer(13, COLLECT_UNMERGED_BC_TIMER);
+ assertTimer(15, DELETE_DETAILED_GC_DOCS_TIMER);
+ }
+
+ @Test
+ public void counters() {
+ Counter counter = getCounter(COUNTER);
+ Counter failureCounter = getCounter(FAILURE_COUNTER);
+
+ VersionGarbageCollector.VersionGCStats vgcs = new
VersionGarbageCollector.VersionGCStats();
+ stats.started();
+ stats.finished(vgcs);
+ assertEquals(1, counter.getCount());
+ assertEquals(0, failureCounter.getCount());
+
+ vgcs.success = false;
+ stats.started();
+ stats.finished(vgcs);
+ assertEquals(2, counter.getCount());
+ assertEquals(1, failureCounter.getCount());
+ }
+
+ private void assertTimer(long expected, String name) {
+ assertEquals(expected,
NANOSECONDS.toMillis(getTimer(name).getSnapshot().getMax()));
+ }
+
+ private Timer getTimer(String name) {
+ return statsProvider.getRegistry().getTimers().get(DETAILED_GC + "." +
name);
+ }
+
+ private Meter getMeter(String name) {
+ return statsProvider.getRegistry().getMeters().get(DETAILED_GC + "." +
name);
+ }
+
+ private Counter getCounter(String name) {
+ return statsProvider.getRegistry().getCounters().get(DETAILED_GC + "."
+ name);
+ }
+
+}
diff --git
a/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
b/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
index 1515ea9312..a1e889fe18 100644
---
a/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
+++
b/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
@@ -31,21 +31,11 @@ import static org.junit.Assert.assertEquals;
public class VersionGCStatsTest {
- private static final Callable START = new Callable() {
- @Override
- public void call(Stopwatch watch) {
- watch.start();
- }
- };
+ private static final Callable START = Stopwatch::start;
- private static final Callable STOP = new Callable() {
- @Override
- public void call(Stopwatch watch) {
- watch.stop();
- }
- };
+ private static final Callable STOP = Stopwatch::stop;
- private VersionGCStats stats = new VersionGCStats();
+ private final VersionGCStats stats = new VersionGCStats();
@Before
public void before() throws Exception {
@@ -61,6 +51,7 @@ public class VersionGCStatsTest {
VersionGCStats cumulative = new VersionGCStats();
cumulative.addRun(stats);
assertEquals(stats.active.elapsed(MICROSECONDS),
cumulative.activeElapsed);
+ assertEquals(stats.detailedGCActive.elapsed(MICROSECONDS),
cumulative.detailedGCActiveElapsed);
assertEquals(stats.collectDeletedDocs.elapsed(MICROSECONDS),
cumulative.collectDeletedDocsElapsed);
assertEquals(stats.checkDeletedDocs.elapsed(MICROSECONDS),
cumulative.checkDeletedDocsElapsed);
assertEquals(stats.deleteDeletedDocs.elapsed(MICROSECONDS),
cumulative.deleteDeletedDocsElapsed);
@@ -69,6 +60,7 @@ public class VersionGCStatsTest {
assertEquals(stats.updateResurrectedDocuments.elapsed(MICROSECONDS),
cumulative.updateResurrectedDocumentsElapsed);
assertEquals(stats.detailedGCDocs.elapsed(MICROSECONDS),
cumulative.detailedGCDocsElapsed);
assertEquals(stats.deleteDetailedGCDocs.elapsed(MICROSECONDS),
cumulative.deleteDetailedGCDocsElapsed);
+ assertEquals(stats.collectDetailedGarbage.elapsed(MICROSECONDS),
cumulative.collectDetailedGarbageElapsed);
assertEquals(stats.collectDeletedProps.elapsed(MICROSECONDS),
cumulative.collectDeletedPropsElapsed);
assertEquals(stats.collectDeletedOldRevs.elapsed(MICROSECONDS),
cumulative.collectDeletedOldRevsElapsed);
assertEquals(stats.collectUnmergedBC.elapsed(MICROSECONDS),
cumulative.collectUnmergedBCElapsed);
@@ -82,6 +74,7 @@ public class VersionGCStatsTest {
cumulative.addRun(cumulative);
// now the stats must have doubled
assertEquals(stats.active.elapsed(MICROSECONDS) * 2,
cumulative.activeElapsed);
+ assertEquals(stats.detailedGCActive.elapsed(MICROSECONDS) * 2,
cumulative.detailedGCActiveElapsed);
assertEquals(stats.collectDeletedDocs.elapsed(MICROSECONDS) * 2,
cumulative.collectDeletedDocsElapsed);
assertEquals(stats.checkDeletedDocs.elapsed(MICROSECONDS) * 2,
cumulative.checkDeletedDocsElapsed);
assertEquals(stats.deleteDeletedDocs.elapsed(MICROSECONDS) * 2,
cumulative.deleteDeletedDocsElapsed);
@@ -90,6 +83,7 @@ public class VersionGCStatsTest {
assertEquals(stats.updateResurrectedDocuments.elapsed(MICROSECONDS) *
2, cumulative.updateResurrectedDocumentsElapsed);
assertEquals(stats.detailedGCDocs.elapsed(MICROSECONDS) * 2,
cumulative.detailedGCDocsElapsed);
assertEquals(stats.deleteDetailedGCDocs.elapsed(MICROSECONDS) * 2,
cumulative.deleteDetailedGCDocsElapsed);
+ assertEquals(stats.collectDetailedGarbage.elapsed(MICROSECONDS) * 2,
cumulative.collectDetailedGarbageElapsed);
assertEquals(stats.collectDeletedProps.elapsed(MICROSECONDS) * 2,
cumulative.collectDeletedPropsElapsed);
assertEquals(stats.collectDeletedOldRevs.elapsed(MICROSECONDS) * 2,
cumulative.collectDeletedOldRevsElapsed);
assertEquals(stats.collectUnmergedBC.elapsed(MICROSECONDS) * 2,
cumulative.collectUnmergedBCElapsed);
@@ -97,6 +91,7 @@ public class VersionGCStatsTest {
private void forEachStopwatch(VersionGCStats stats, Callable c) {
c.call(stats.active);
+ c.call(stats.detailedGCActive);
c.call(stats.collectDeletedDocs);
c.call(stats.checkDeletedDocs);
c.call(stats.deleteDeletedDocs);
@@ -105,6 +100,7 @@ public class VersionGCStatsTest {
c.call(stats.updateResurrectedDocuments);
c.call(stats.detailedGCDocs);
c.call(stats.deleteDetailedGCDocs);
+ c.call(stats.collectDetailedGarbage);
c.call(stats.collectDeletedProps);
c.call(stats.collectDeletedOldRevs);
c.call(stats.collectUnmergedBC);
diff --git
a/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollectorIT.java
b/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollectorIT.java
index 56f8b3f77b..71af29fe06 100644
---
a/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollectorIT.java
+++
b/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollectorIT.java
@@ -40,6 +40,7 @@ import static java.util.concurrent.TimeUnit.MILLISECONDS;
import static java.util.stream.Collectors.toList;
import static java.util.stream.StreamSupport.stream;
import static org.apache.commons.lang3.reflect.FieldUtils.writeField;
+import static org.apache.jackrabbit.guava.common.base.Strings.repeat;
import static org.apache.jackrabbit.guava.common.collect.Iterables.filter;
import static org.apache.jackrabbit.guava.common.collect.Iterables.size;
import static java.util.concurrent.TimeUnit.HOURS;
@@ -62,6 +63,7 @@ import static
org.apache.jackrabbit.oak.plugins.document.VersionGarbageCollector
import static
org.apache.jackrabbit.oak.plugins.document.VersionGarbageCollector.SETTINGS_COLLECTION_ID;
import static
org.apache.jackrabbit.oak.plugins.document.VersionGarbageCollector.VersionGCStats;
import static
org.apache.jackrabbit.oak.plugins.document.bundlor.DocumentBundlor.META_PROP_PATTERN;
+import static org.apache.jackrabbit.oak.plugins.document.util.Utils.PATH_LONG;
import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertNotEquals;
@@ -73,7 +75,6 @@ import static org.junit.Assume.assumeTrue;
import org.apache.jackrabbit.guava.common.base.Function;
import org.apache.jackrabbit.guava.common.base.Predicate;
-import org.apache.jackrabbit.guava.common.base.Strings;
import org.apache.jackrabbit.guava.common.collect.AbstractIterator;
import org.apache.jackrabbit.guava.common.collect.ImmutableList;
import org.apache.jackrabbit.guava.common.collect.Iterators;
@@ -250,7 +251,7 @@ public class VersionGarbageCollectorIT {
@Test
public void gcLongPathSplitDocs() throws Exception {
- gcSplitDocsInternal(Strings.repeat("sub", 120));
+ gcSplitDocsInternal(repeat("sub", 120));
}
// OAK-10199
@@ -701,6 +702,64 @@ public class VersionGarbageCollectorIT {
assertEquals(0, stats.updatedDetailedGCDocsCount);
}
+ @Test
+ public void testGCDeletedLongPathProps() throws Exception {
+ //1. Create nodes with properties
+ NodeBuilder b1 = store.getRoot().builder();
+ String longPath = repeat("p", PATH_LONG + 1);
+ b1.child(longPath);
+
+ // Add property to node & save
+ for (int i = 0; i < 10; i++) {
+ b1.child(longPath).child("foo").setProperty("test"+i, "t", STRING);
+ }
+ store.merge(b1, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+
+ // enable the detailed gc flag
+ writeField(gc, "detailedGCEnabled", true, true);
+ long maxAge = 1; //hours
+ long delta = MINUTES.toMillis(10);
+ //1. Go past GC age and check no GC done as nothing deleted
+ clock.waitUntil(getCurrentTimestamp() + maxAge);
+ VersionGCStats stats = gc.gc(maxAge, HOURS);
+ assertEquals(0, stats.deletedPropsGCCount);
+ assertEquals(0, stats.updatedDetailedGCDocsCount);
+
+ //Remove property
+ NodeBuilder b2 = store.getRoot().builder();
+ for (int i = 0; i < 10; i++) {
+ b2.child(longPath).child("foo").removeProperty("test"+i);
+ }
+ store.merge(b2, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+
+ store.runBackgroundOperations();
+
+ //2. Check that a deleted property is not collected before maxAge
+ //Clock cannot move back (it moved forward in #1) so double the maxAge
+ clock.waitUntil(clock.getTime() + delta);
+ stats = gc.gc(maxAge*2, HOURS);
+ assertEquals(0, stats.deletedPropsGCCount);
+ assertEquals(0, stats.updatedDetailedGCDocsCount);
+
+ //3. Check that deleted property does get collected post maxAge
+ clock.waitUntil(clock.getTime() + HOURS.toMillis(maxAge*2) + delta);
+
+ stats = gc.gc(maxAge*2, HOURS);
+ assertEquals(10, stats.deletedPropsGCCount);
+
+ //4. Check that a revived property (deleted and created again) does
not get gc
+ NodeBuilder b4 = store.getRoot().builder();
+ for (int i = 0; i < 10; i++) {
+ b4.child(longPath).child("foo").setProperty("test"+i, "t", STRING);
+ }
+ store.merge(b4, EmptyHook.INSTANCE, CommitInfo.EMPTY);
+
+ clock.waitUntil(clock.getTime() + HOURS.toMillis(maxAge*2) + delta);
+ stats = gc.gc(maxAge*2, HOURS);
+ assertEquals(0, stats.deletedPropsGCCount);
+ assertEquals(0, stats.updatedDetailedGCDocsCount);
+ }
+
@Test
public void testGCDeletedNonBundledProps() throws Exception {
