You are viewing a plain text version of this content. The canonical link for it is here.
Posted to oak-commits@jackrabbit.apache.org by am...@apache.org on 2018/06/04 09:14:40 UTC

svn commit: r1832803 - in /jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob: MarkSweepGarbageCollector.java OperationStatsCollector.java

Author: amitj
Date: Mon Jun  4 09:14:40 2018
New Revision: 1832803

URL: http://svn.apache.org/viewvc?rev=1832803&view=rev
Log:
OAK-7522: Enable collection of simple operation stats for DataStore garbage collection

Added timers for mark & sweep

Modified:
    jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java
    jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/OperationStatsCollector.java

Modified: jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java?rev=1832803&r1=1832802&r2=1832803&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java (original)
+++ jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/MarkSweepGarbageCollector.java Mon Jun  4 09:14:40 2018
@@ -300,33 +300,45 @@ public class MarkSweepGarbageCollector i
         statsCollector.start();
         boolean threw = true;
         GarbageCollectorFileState fs = new GarbageCollectorFileState(root);
+        Stopwatch sw = Stopwatch.createStarted();
+
         try {
-            Stopwatch sw = Stopwatch.createStarted();
             LOG.info("Starting Blob garbage collection with markOnly [{}]", markOnly);
-            
+
             long markStart = System.currentTimeMillis();
-            mark(fs);
+            long markFinish;
+            try {
+                mark(fs);
+            } finally {
+                markFinish = sw.elapsed(TimeUnit.MILLISECONDS);
+                statsCollector.updateMarkDuration(markFinish, TimeUnit.MILLISECONDS);
+                LOG.info("Blob garbage collection Mark completed in {} ({} ms).",
+                    sw.toString(), sw.elapsed(TimeUnit.MILLISECONDS));
+            }
+
             if (!markOnly) {
-                long deleteCount = sweep(fs, markStart, forceBlobRetrieve);
-                threw = false;
+                long deleteCount;
+                try {
+                    deleteCount = sweep(fs, markStart, forceBlobRetrieve);
+                    threw = false;
+                } finally {
+                    sw.stop();
+                    statsCollector.updateSweepDuration(sw.elapsed(TimeUnit.MILLISECONDS) - markFinish, TimeUnit.MILLISECONDS);
+                }
 
                 long maxTime = getMaxModifiedTime(markStart) > 0 ? getMaxModifiedTime(markStart) : markStart;
-                sw.stop();
 
                 LOG.info("Blob garbage collection completed in {} ({} ms). Number of blobs deleted [{}] with max modification time of [{}]",
                         sw.toString(), sw.elapsed(TimeUnit.MILLISECONDS), deleteCount, timestampToString(maxTime));
-            } else {
-                sw.stop();
-                LOG.info("Blob garbage collection Mark completed in {} ({} ms).",
-                    sw.toString(), sw.elapsed(TimeUnit.MILLISECONDS));
             }
+
             statsCollector.finishSuccess();
-            statsCollector.updateDuration(sw.elapsed(TimeUnit.MILLISECONDS), TimeUnit.MILLISECONDS);
         } catch (Exception e) {
             statsCollector.finishFailure();
             LOG.error("Blob garbage collection error", e);
             throw e;
         } finally {
+            statsCollector.updateDuration(sw.elapsed(TimeUnit.MILLISECONDS), TimeUnit.MILLISECONDS);
             if (!LOG.isTraceEnabled()) {
                 Closeables.close(fs, threw);
             }
@@ -973,11 +985,15 @@ public class MarkSweepGarbageCollector i
         private static final String FINISH_SUCCESS = "FINISH_SUCCESS";
         private static final String FINISH_FAILURE = "FINISH_FAILURE";
         private static final String DURATION = "DURATION";
+        private static final String MARK_DURATION = "MARK_DURATION";
+        private static final String SWEEP_DURATION = "SWEEP_DURATION";
 
         private CounterStats startCounter;
         private CounterStats finishSuccessCounter;
         private CounterStats finishFailureCounter;
         private TimerStats duration;
+        private final TimerStats markDuration;
+        private final TimerStats sweepDuration;
         private final OperationStatsCollector collector;
 
         GarbageCollectionOperationStats(StatisticsProvider sp) {
@@ -985,6 +1001,9 @@ public class MarkSweepGarbageCollector i
             this.finishSuccessCounter = sp.getCounterStats(getMetricName(FINISH_SUCCESS), StatsOptions.METRICS_ONLY);
             this.finishFailureCounter = sp.getCounterStats(getMetricName(FINISH_FAILURE), StatsOptions.METRICS_ONLY);
             this.duration = sp.getTimer(getMetricName(DURATION), StatsOptions.METRICS_ONLY);
+            this.markDuration = sp.getTimer(getMetricName(MARK_DURATION), StatsOptions.METRICS_ONLY);
+            this.sweepDuration = sp.getTimer(getMetricName(SWEEP_DURATION), StatsOptions.METRICS_ONLY);
+
             this.collector = new OperationStatsCollector() {
                 @Override
                 public void start() {
@@ -1005,6 +1024,14 @@ public class MarkSweepGarbageCollector i
                 public void updateDuration(long time, TimeUnit timeUnit) {
                     duration.update(time, timeUnit);
                 }
+
+                @Override public void updateMarkDuration(long time, TimeUnit timeUnit) {
+                    markDuration.update(time, timeUnit);
+                }
+
+                @Override public void updateSweepDuration(long time, TimeUnit timeUnit) {
+                    sweepDuration.update(time, timeUnit);
+                }
             };
         }
 

Modified: jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/OperationStatsCollector.java
URL: http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/OperationStatsCollector.java?rev=1832803&r1=1832802&r2=1832803&view=diff
==============================================================================
--- jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/OperationStatsCollector.java (original)
+++ jackrabbit/oak/trunk/oak-blob-plugins/src/main/java/org/apache/jackrabbit/oak/plugins/blob/OperationStatsCollector.java Mon Jun  4 09:14:40 2018
@@ -26,16 +26,22 @@ import java.util.concurrent.TimeUnit;
  */
 public interface OperationStatsCollector {
     OperationStatsCollector NOOP = new OperationStatsCollector() {
-        public void start() {
+        @Override public void start() {
         }
 
-        public void finishSuccess() {
+        @Override public void finishSuccess() {
         }
 
-        public void finishFailure() {
+        @Override public void finishFailure() {
         }
 
-        public void updateDuration(long time, TimeUnit timeUnit) {
+        @Override public void updateDuration(long time, TimeUnit timeUnit) {
+        }
+
+        @Override public void updateMarkDuration(long time, TimeUnit timeUnit) {
+        }
+
+        @Override public void updateSweepDuration(long time, TimeUnit timeUnit) {
         }
     };
 
@@ -61,4 +67,21 @@ public interface OperationStatsCollector
      * @param timeUnit unit of time
      */
     void updateDuration(long time, TimeUnit timeUnit);
+
+    /**
+     * Increment the mark phase duration timer
+     *
+     * @param time time recorded for the operation
+     * @param timeUnit unit of time
+     */
+    void updateMarkDuration(long time, TimeUnit timeUnit);
+
+    /**
+     * Increment the sweep phase duration timer
+     *
+     * @param time time recorded for the operation
+     * @param timeUnit unit of time
+     */
+    void updateSweepDuration(long time, TimeUnit timeUnit);
+
 }