Author: mreutegg
Date: Wed Aug 9 10:01:41 2017
New Revision: 1804500
URL: http://svn.apache.org/viewvc?rev=1804500&view=rev
Log:
OAK-6536: Periodic log message from continuous RGC
Added:
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
(with props)
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreService.java
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreService.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreService.java?rev=1804500&r1=1804499&r2=1804500&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreService.java
(original)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/DocumentNodeStoreService.java
Wed Aug 9 10:01:41 2017
@@ -73,6 +73,8 @@ import org.apache.jackrabbit.oak.api.jmx
import org.apache.jackrabbit.oak.api.jmx.PersistentCacheStatsMBean;
import org.apache.jackrabbit.oak.cache.CacheStats;
import org.apache.jackrabbit.oak.commons.PropertiesUtil;
+import
org.apache.jackrabbit.oak.plugins.document.VersionGarbageCollector.VersionGCStats;
+import org.apache.jackrabbit.oak.plugins.document.util.Utils;
import org.apache.jackrabbit.oak.spi.commit.ObserverTracker;
import org.apache.jackrabbit.oak.osgi.OsgiWhiteboard;
import org.apache.jackrabbit.oak.plugins.blob.BlobGC;
@@ -929,7 +931,7 @@ public class DocumentNodeStoreService {
BlobGCMBean.TYPE, "Document node store blob garbage
collection"));
}
- Runnable startGC = new RevisionGCJob(store, versionGcMaxAgeInSecs,
log);
+ Runnable startGC = new RevisionGCJob(store, versionGcMaxAgeInSecs);
Runnable cancelGC = new Runnable() {
@Override
public void run() {
@@ -1003,7 +1005,7 @@ public class DocumentNodeStoreService {
if (isContinuousRevisionGC()) {
final long versionGcMaxAgeInSecs =
toLong(prop(PROP_VER_GC_MAX_AGE), DEFAULT_VER_GC_MAX_AGE);
addRegistration(WhiteboardUtils.scheduleWithFixedDelay(whiteboard,
- new RevisionGCJob(nodeStore, versionGcMaxAgeInSecs, log),
+ new RevisionGCJob(nodeStore, versionGcMaxAgeInSecs),
MODIFIED_IN_SECS_RESOLUTION, true, true));
}
}
@@ -1074,27 +1076,37 @@ public class DocumentNodeStoreService {
static final class RevisionGCJob implements Runnable, Supplier<String> {
+ // log as VersionGarbageCollector
+ private static final Logger LOGGER =
LoggerFactory.getLogger(VersionGarbageCollector.class);
+
+ // log every hour
+ private static final long LOG_INTERVAL = TimeUnit.HOURS.toMillis(1);
+
private final DocumentNodeStore nodeStore;
private final long versionGcMaxAgeInSecs;
- private final Logger log;
private volatile Object lastResult = "";
+ private long lastLogTime;
+ private VersionGCStats stats;
RevisionGCJob(DocumentNodeStore ns,
- long versionGcMaxAgeInSecs,
- Logger log) {
+ long versionGcMaxAgeInSecs) {
this.nodeStore = ns;
this.versionGcMaxAgeInSecs = versionGcMaxAgeInSecs;
- this.log = log;
+ resetStats();
}
@Override
public void run() {
VersionGarbageCollector gc =
nodeStore.getVersionGarbageCollector();
try {
- lastResult = gc.gc(versionGcMaxAgeInSecs,
TimeUnit.SECONDS).toString();
+ VersionGCStats s = gc.gc(versionGcMaxAgeInSecs,
TimeUnit.SECONDS);
+ stats.addRun(s);
+ lastResult = s.toString();
} catch (Exception e) {
lastResult = e;
- log.warn("Error occurred while executing the Version Garbage
Collector", e);
+ LOGGER.warn("Error occurred while executing the Version
Garbage Collector", e);
+ } finally {
+ maybeLogStats();
}
}
@@ -1112,5 +1124,18 @@ public class DocumentNodeStoreService {
}
return String.valueOf(lastResult);
}
+
+ private void resetStats() {
+ lastLogTime = nodeStore.getClock().getTime();
+ stats = new VersionGCStats();
+ }
+
+ private void maybeLogStats() {
+ if (nodeStore.getClock().getTime() > lastLogTime + LOG_INTERVAL) {
+ LOGGER.info("Garbage collector stats since {}: {}",
+ Utils.timestampToString(lastLogTime), stats);
+ resetStats();
+ }
+ }
}
}
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java?rev=1804500&r1=1804499&r2=1804500&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java
(original)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/document/VersionGarbageCollector.java
Wed Aug 9 10:01:41 2017
@@ -310,12 +310,23 @@ public class VersionGarbageCollector {
this.splitDocGCCount += run.splitDocGCCount;
this.intermediateSplitDocGCCount +=
run.intermediateSplitDocGCCount;
this.updateResurrectedGCCount += run.updateResurrectedGCCount;
- this.collectDeletedDocsElapsed +=
run.collectDeletedDocs.elapsed(MICROSECONDS);
- this.checkDeletedDocsElapsed +=
run.checkDeletedDocs.elapsed(MICROSECONDS);
- this.deleteDeletedDocsElapsed +=
run.deleteDeletedDocs.elapsed(MICROSECONDS);
- this.collectAndDeleteSplitDocsElapsed +=
run.collectAndDeleteSplitDocs.elapsed(MICROSECONDS);
- this.sortDocIdsElapsed += run.sortDocIds.elapsed(MICROSECONDS);
- this.updateResurrectedDocumentsElapsed +=
run.updateResurrectedDocuments.elapsed(MICROSECONDS);
+ if (run.iterationCount > 0) {
+ // run is cumulative with times in elapsed fields
+ this.collectDeletedDocsElapsed +=
run.collectDeletedDocsElapsed;
+ this.checkDeletedDocsElapsed += run.checkDeletedDocsElapsed;
+ this.deleteDeletedDocsElapsed += run.deleteDeletedDocsElapsed;
+ this.collectAndDeleteSplitDocsElapsed +=
run.collectAndDeleteSplitDocsElapsed;
+ this.sortDocIdsElapsed += run.sortDocIdsElapsed;
+ this.updateResurrectedDocumentsElapsed +=
run.updateResurrectedDocumentsElapsed;
+ } else {
+ // single run -> read from stop watches
+ this.collectDeletedDocsElapsed +=
run.collectDeletedDocs.elapsed(MICROSECONDS);
+ this.checkDeletedDocsElapsed +=
run.checkDeletedDocs.elapsed(MICROSECONDS);
+ this.deleteDeletedDocsElapsed +=
run.deleteDeletedDocs.elapsed(MICROSECONDS);
+ this.collectAndDeleteSplitDocsElapsed +=
run.collectAndDeleteSplitDocs.elapsed(MICROSECONDS);
+ this.sortDocIdsElapsed += run.sortDocIds.elapsed(MICROSECONDS);
+ this.updateResurrectedDocumentsElapsed +=
run.updateResurrectedDocuments.elapsed(MICROSECONDS);
+ }
}
}
Added:
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java?rev=1804500&view=auto
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
(added)
+++
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
Wed Aug 9 10:01:41 2017
@@ -0,0 +1,100 @@
+/*
+ * 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 java.util.concurrent.TimeUnit;
+
+import com.google.common.base.Stopwatch;
+
+import
org.apache.jackrabbit.oak.plugins.document.VersionGarbageCollector.VersionGCStats;
+import org.junit.Before;
+import org.junit.Test;
+
+import static java.util.concurrent.TimeUnit.MICROSECONDS;
+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 STOP = new Callable() {
+ @Override
+ public void call(Stopwatch watch) {
+ watch.stop();
+ }
+ };
+
+ private VersionGCStats stats = new VersionGCStats();
+
+ @Before
+ public void before() throws Exception {
+ forEachStopwatch(stats, START);
+ while (stats.updateResurrectedDocuments.elapsed(TimeUnit.MILLISECONDS)
< 10) {
+ Thread.sleep(1);
+ }
+ forEachStopwatch(stats, STOP);
+ }
+
+ @Test
+ public void addRun() {
+ VersionGCStats cumulative = new VersionGCStats();
+ cumulative.addRun(stats);
+ assertEquals(stats.collectDeletedDocs.elapsed(MICROSECONDS),
cumulative.collectDeletedDocsElapsed);
+ assertEquals(stats.checkDeletedDocs.elapsed(MICROSECONDS),
cumulative.checkDeletedDocsElapsed);
+ assertEquals(stats.deleteDeletedDocs.elapsed(MICROSECONDS),
cumulative.deleteDeletedDocsElapsed);
+ assertEquals(stats.collectAndDeleteSplitDocs.elapsed(MICROSECONDS),
cumulative.collectAndDeleteSplitDocsElapsed);
+ assertEquals(stats.sortDocIds.elapsed(MICROSECONDS),
cumulative.sortDocIdsElapsed);
+ assertEquals(stats.updateResurrectedDocuments.elapsed(MICROSECONDS),
cumulative.updateResurrectedDocumentsElapsed);
+ }
+
+ @Test
+ public void addRunCumulative() {
+ VersionGCStats cumulative = new VersionGCStats();
+ cumulative.addRun(stats);
+ // double stats by adding to itself
+ cumulative.addRun(cumulative);
+ // now the stats must have doubled
+ assertEquals(stats.collectDeletedDocs.elapsed(MICROSECONDS) * 2,
cumulative.collectDeletedDocsElapsed);
+ assertEquals(stats.checkDeletedDocs.elapsed(MICROSECONDS) * 2,
cumulative.checkDeletedDocsElapsed);
+ assertEquals(stats.deleteDeletedDocs.elapsed(MICROSECONDS) * 2,
cumulative.deleteDeletedDocsElapsed);
+ assertEquals(stats.collectAndDeleteSplitDocs.elapsed(MICROSECONDS) *
2, cumulative.collectAndDeleteSplitDocsElapsed);
+ assertEquals(stats.sortDocIds.elapsed(MICROSECONDS) * 2,
cumulative.sortDocIdsElapsed);
+ assertEquals(stats.updateResurrectedDocuments.elapsed(MICROSECONDS) *
2, cumulative.updateResurrectedDocumentsElapsed);
+ }
+
+ private void forEachStopwatch(VersionGCStats stats, Callable c) {
+ c.call(stats.active);
+ c.call(stats.collectDeletedDocs);
+ c.call(stats.checkDeletedDocs);
+ c.call(stats.deleteDeletedDocs);
+ c.call(stats.collectAndDeleteSplitDocs);
+ c.call(stats.sortDocIds);
+ c.call(stats.updateResurrectedDocuments);
+ }
+
+ private interface Callable {
+
+ void call(Stopwatch watch);
+ }
+}
Propchange:
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/plugins/document/VersionGCStatsTest.java
------------------------------------------------------------------------------
svn:eol-style = native