svn commit: r1181401 - in /hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver: CompactSplitThread.java HRegion.java metrics/RegionServerMetrics.java

[ns...@apache.org]

Author: nspiegelberg
Date: Tue Oct 11 02:05:31 2011
New Revision: 1181401

URL: http://svn.apache.org/viewvc?rev=1181401&view=rev
Log:
HBASE-3102: Add Compaction Time to JMX

Summary:
Added the ability to track compaction count + duration.  Since compactions are
long running, the avg/opcount stats are should be reset longer than the polling
period (60 sec).  Added the idea of a 'marathon', or a long duration after which
some metrics should expire.  Compaction stats & all min/max stats expire after
the marathon (1 hr).

Test Plan:
mvn clean install
loaded on cluster

DiffCamp Revision: 167960
Reviewed By: kannan
CC: nspiegelberg, kannan
Revert Plan:
OK

Modified:
    hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/CompactSplitThread.java
    hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java
    hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java

Modified: hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/CompactSplitThread.java
URL: http://svn.apache.org/viewvc/hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/CompactSplitThread.java?rev=1181401&r1=1181400&r2=1181401&view=diff
==============================================================================
--- hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/CompactSplitThread.java (original)
+++ hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/CompactSplitThread.java Tue Oct 11 02:05:31 2011
@@ -101,6 +101,10 @@ class CompactSplitThread extends Thread 
             if(!this.server.isStopRequested()) {
               // Don't interrupt us while we are working
               byte [] midKey = r.compactStores();
+              long lastCompactPeriod = r.getLastCompactPeriod();
+              if (lastCompactPeriod > 0) {  // 0 == compaction aborted
+                this.server.getMetrics().addCompaction(lastCompactPeriod);
+              }
               LOG.debug("Just finished a compaction. " +
                         " Current Compaction Queue Size: " +
                         getCompactionQueueSize());

Modified: hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java
URL: http://svn.apache.org/viewvc/hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java?rev=1181401&r1=1181400&r2=1181401&view=diff
==============================================================================
--- hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java (original)
+++ hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java Tue Oct 11 02:05:31 2011
@@ -177,6 +177,7 @@ public class HRegion implements HeapSize
    * major compaction.  Cleared each time through compaction code.
    */
   private volatile boolean forceMajorCompaction = false;
+  private long lastCompactPeriod = 0;
 
   /*
    * Data structure of write state flags used coordinating flushes,
@@ -606,6 +607,11 @@ public class HRegion implements HeapSize
     return this.fs;
   }
 
+  /** @return how long the last compaction took */
+  public long getLastCompactPeriod() {
+    return this.lastCompactPeriod;
+  }
+
   /** @return the last time the region was flushed */
   public long getLastFlushTime() {
     return this.lastFlushTime;
@@ -847,6 +853,7 @@ public class HRegion implements HeapSize
           LOG.info(((completed) ? "completed" : "aborted")
               + " compaction on region " + this
               + " after " + StringUtils.formatTimeDiff(now, startTime));
+          this.lastCompactPeriod = (completed) ? (now - startTime) / 1000 : 0;
         }
       } finally {
         synchronized (writestate) {

Modified: hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java
URL: http://svn.apache.org/viewvc/hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java?rev=1181401&r1=1181400&r2=1181401&view=diff
==============================================================================
--- hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java (original)
+++ hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java Tue Oct 11 02:05:31 2011
@@ -25,6 +25,7 @@ import org.apache.hadoop.hbase.io.hfile.
 import org.apache.hadoop.hbase.metrics.MetricsRate;
 import org.apache.hadoop.hbase.regionserver.wal.HLog;
 import org.apache.hadoop.hbase.util.Strings;
+import org.apache.hadoop.metrics.ContextFactory;
 import org.apache.hadoop.metrics.MetricsContext;
 import org.apache.hadoop.metrics.MetricsRecord;
 import org.apache.hadoop.metrics.MetricsUtil;
@@ -35,6 +36,7 @@ import org.apache.hadoop.metrics.util.Me
 import org.apache.hadoop.metrics.util.MetricsRegistry;
 import org.apache.hadoop.metrics.util.MetricsTimeVaryingRate;
 
+import java.io.IOException;
 import java.lang.management.ManagementFactory;
 import java.lang.management.MemoryUsage;
 
@@ -50,6 +52,8 @@ public class RegionServerMetrics impleme
   private final Log LOG = LogFactory.getLog(this.getClass());
   private final MetricsRecord metricsRecord;
   private long lastUpdate = System.currentTimeMillis();
+  private long lastMarathon = System.currentTimeMillis();
+  private long marathonPeriod = 0;
   private static final int MB = 1024*1024;
   private MetricsRegistry registry = new MetricsRegistry();
   private final RegionServerStatistics statistics;
@@ -134,6 +138,12 @@ public class RegionServerMetrics impleme
   public final MetricsTimeVaryingRate fsSyncLatency =
     new MetricsTimeVaryingRate("fsSyncLatency", registry);
 
+  /**
+   * time each scheduled compaction takes
+   */
+  public final MetricsTimeVaryingRate compaction =
+    new MetricsTimeVaryingRate("compaction", registry);
+
   public RegionServerMetrics() {
     MetricsContext context = MetricsUtil.getContext("hbase");
     metricsRecord = MetricsUtil.createRecord(context, "regionserver");
@@ -146,6 +156,16 @@ public class RegionServerMetrics impleme
     // export for JMX
     statistics = new RegionServerStatistics(this.registry, name);
 
+    // get custom attributes
+    try {
+      Object m = ContextFactory.getFactory().getAttribute("hbase.marathon");
+      if (m instanceof String) {
+        this.marathonPeriod = Long.parseLong((String) m)*1000;
+      }
+    } catch (IOException ioe) {
+      LOG.info("Couldn't load ContextFactory for Metrics config info");
+    }
+
     LOG.info("Initialized");
   }
 
@@ -157,10 +177,20 @@ public class RegionServerMetrics impleme
   /**
    * Since this object is a registered updater, this method will be called
    * periodically, e.g. every 5 seconds.
-   * @param unused unused argument
+   * @param caller the metrics context that this responsible for calling us
    */
-  public void doUpdates(MetricsContext unused) {
+  public void doUpdates(MetricsContext caller) {
     synchronized (this) {
+      this.lastUpdate = System.currentTimeMillis();
+
+      // has the marathon period for long-living stats elapsed?
+      boolean marathonExpired = (this.marathonPeriod > 0) &&
+          (this.lastUpdate - this.lastMarathon >= this.marathonPeriod);
+      if (marathonExpired) {
+        this.lastMarathon = this.lastUpdate;
+        this.resetAllMinMax();
+      }
+
       this.stores.pushMetric(this.metricsRecord);
       this.storefiles.pushMetric(this.metricsRecord);
       this.storefileIndexSizeMB.pushMetric(this.metricsRecord);
@@ -196,15 +226,39 @@ public class RegionServerMetrics impleme
       this.fsReadLatency.pushMetric(this.metricsRecord);
       this.fsWriteLatency.pushMetric(this.metricsRecord);
       this.fsSyncLatency.pushMetric(this.metricsRecord);
+      this.compaction.pushMetric(this.metricsRecord);
+
+      if (!marathonExpired) {
+        maintainStats(this.compaction);
+      }
     }
     this.metricsRecord.update();
-    this.lastUpdate = System.currentTimeMillis();
+  }
+
+  /* MetricsTimeVaryingRate will reset every time pushMetric() is called
+   * This is annoying for long-running stats that might not get a single
+   * operation in the polling period.  This function ensures that values
+   * for those stat entries don't get reset.
+   */
+  protected void maintainStats(MetricsTimeVaryingRate stat) {
+    int curOps = stat.getPreviousIntervalNumOps();
+    if (curOps > 0) {
+      long curTime = stat.getPreviousIntervalAverageTime();
+      long totalTime = curTime * curOps;
+      if (totalTime / curTime == curOps) {
+        stat.inc(curOps, totalTime);
+      } else {
+        LOG.info("Stats for " + stat.getName() + " overflowed! resetting");
+      }
+    }
   }
 
   public void resetAllMinMax() {
     this.atomicIncrementTime.resetMinMax();
     this.fsReadLatency.resetMinMax();
     this.fsWriteLatency.resetMinMax();
+    this.fsSyncLatency.resetMinMax();
+    this.compaction.resetMinMax();
   }
 
   /**
@@ -215,6 +269,15 @@ public class RegionServerMetrics impleme
   }
 
   /**
+   * @param periodSec seconds that last compaction took
+   */
+  public void addCompaction(final long periodSec) {
+    synchronized (this) {
+      this.compaction.inc(periodSec);
+    }
+  }
+
+  /**
    * @param inc How much to add to requests.
    */
   public void incrementRequests(final int inc) {