You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hbase.apache.org by ns...@apache.org on 2011/10/11 04:14:02 UTC
svn commit: r1181500 - in
/hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver:
HRegion.java metrics/RegionServerMetrics.java
Author: nspiegelberg
Date: Tue Oct 11 02:14:02 2011
New Revision: 1181500
URL: http://svn.apache.org/viewvc?rev=1181500&view=rev
Log:
add instrumentation to collect memstore insert time, RWCC wait time, and row lock acquisition time
Summary:
Add instrumentation to collect:
- memstore insert time
- RWCC wait time (the time we wait after an write operation to, for RWCC read
point to advance).
- row lock acquisition time
Test Plan:
Sending the diff out for review, while I test this out on my dev cluster. If it
works fine, next thing will be to push this to dark launch cell #1 to understand
why the put latencies are high.
Reviewed By: jgray
Reviewers: jgray, nspiegelberg, dhruba, kranganathan
CC: jgray, hbase@lists,
Revert Plan:
OK
Differential Revision: 224550
Modified:
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/HRegion.java
URL: http://svn.apache.org/viewvc/hbase/branches/0.89/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java?rev=1181500&r1=1181499&r2=1181500&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:14:02 2011
@@ -234,6 +234,29 @@ public class HRegion implements HeapSize
private final ReadWriteConsistencyControl rwcc =
new ReadWriteConsistencyControl();
+ public static volatile AtomicLong writeOps = new AtomicLong(0);
+ public static volatile AtomicLong rowLockTime = new AtomicLong(0);
+ public static volatile AtomicLong rwccWaitTime = new AtomicLong(0);
+ public static volatile AtomicLong memstoreInsertTime = new AtomicLong(0);
+
+ public static final long getWriteOps() {
+ return writeOps.getAndSet(0);
+ }
+
+ public static final long getRowLockTime()
+ {
+ return rowLockTime.getAndSet(0);
+ }
+
+ public static final long getRWCCWaitTime()
+ {
+ return rwccWaitTime.getAndSet(0);
+ }
+
+ public static final long getMemstoreInsertTime() {
+ return memstoreInsertTime.getAndSet(0);
+ }
+
/**
* Name of the region info file that resides just under the region directory.
*/
@@ -1296,6 +1319,7 @@ public class HRegion implements HeapSize
} finally {
if(lockid == null) releaseRowLock(lid);
splitsAndClosesLock.readLock().unlock();
+ HRegion.writeOps.incrementAndGet();
}
}
@@ -1385,6 +1409,7 @@ public class HRegion implements HeapSize
// Request a cache flush. Do it outside update lock.
requestFlush();
}
+ HRegion.writeOps.incrementAndGet();
}
/**
@@ -1448,6 +1473,7 @@ public class HRegion implements HeapSize
}
} finally {
splitsAndClosesLock.readLock().unlock();
+ HRegion.writeOps.incrementAndGet();
}
}
@@ -1511,6 +1537,7 @@ public class HRegion implements HeapSize
requestFlush();
}
}
+ HRegion.writeOps.incrementAndGet();
return batchOp.retCodes;
}
@@ -1843,6 +1870,7 @@ public class HRegion implements HeapSize
* new entries.
*/
private long applyFamilyMapToMemstore(Map<byte[], List<KeyValue>> familyMap) {
+ long start = EnvironmentEdgeManager.currentTimeMillis();
ReadWriteConsistencyControl.WriteEntry w = null;
long size = 0;
try {
@@ -1859,7 +1887,12 @@ public class HRegion implements HeapSize
}
}
} finally {
+ long now = EnvironmentEdgeManager.currentTimeMillis();
+ HRegion.memstoreInsertTime.addAndGet(now - start);
+ start = now;
rwcc.completeMemstoreInsert(w);
+ now = EnvironmentEdgeManager.currentTimeMillis();
+ HRegion.rwccWaitTime.addAndGet(now - start);
}
return size;
}
@@ -2285,7 +2318,10 @@ public class HRegion implements HeapSize
throws IOException {
Integer lid = null;
if (lockid == null) {
+ long start = EnvironmentEdgeManager.currentTimeMillis();
lid = internalObtainRowLock(row, waitForLock);
+ long end = EnvironmentEdgeManager.currentTimeMillis();
+ HRegion.rowLockTime.addAndGet(end - start);
} else {
if (!isRowLocked(lockid)) {
throw new IOException("Invalid row lock");
@@ -3122,6 +3158,7 @@ public class HRegion implements HeapSize
} finally {
this.updatesLock.readLock().unlock();
releaseRowLock(lid);
+ HRegion.writeOps.incrementAndGet();
}
if (flush) {
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=1181500&r1=1181499&r2=1181500&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:14:02 2011
@@ -25,6 +25,7 @@ import org.apache.hadoop.hbase.io.hfile.
import org.apache.hadoop.hbase.metrics.HBaseInfo;
import org.apache.hadoop.hbase.metrics.MetricsRate;
import org.apache.hadoop.hbase.metrics.PersistentMetricsTimeVaryingRate;
+import org.apache.hadoop.hbase.regionserver.HRegion;
import org.apache.hadoop.hbase.regionserver.wal.HLog;
import org.apache.hadoop.hbase.util.Pair;
import org.apache.hadoop.hbase.util.Strings;
@@ -156,6 +157,18 @@ public class RegionServerMetrics impleme
new MetricsTimeVaryingRate("fsGroupSyncLatency", registry);
/**
+ * Memstore Insert time (in ms).
+ */
+ public final MetricsTimeVaryingRate memstoreInsertTime =
+ new MetricsTimeVaryingRate("memstoreInsert", registry);
+
+ public final MetricsTimeVaryingRate rowLockTime =
+ new MetricsTimeVaryingRate("rowLock", registry);
+
+ public final MetricsTimeVaryingRate rwccWaitTime =
+ new MetricsTimeVaryingRate("rwccWait", registry);
+
+ /**
* time each scheduled compaction takes
*/
protected final PersistentMetricsTimeVaryingRate compactionTime =
@@ -260,12 +273,22 @@ public class RegionServerMetrics impleme
* by compaction & flush metrics.
*/
+ int writeOps = (int)HRegion.getWriteOps();
+ if (writeOps != 0) {
+ this.memstoreInsertTime.inc(writeOps, HRegion.getMemstoreInsertTime());
+ this.rwccWaitTime.inc(writeOps, HRegion.getRWCCWaitTime());
+ this.rowLockTime.inc(writeOps, HRegion.getRowLockTime());
+ }
+
// push the result
this.fsReadLatency.pushMetric(this.metricsRecord);
this.fsWriteLatency.pushMetric(this.metricsRecord);
this.fsWriteSize.pushMetric(this.metricsRecord);
this.fsSyncLatency.pushMetric(this.metricsRecord);
this.fsGroupSyncLatency.pushMetric(this.metricsRecord);
+ this.memstoreInsertTime.pushMetric(this.metricsRecord);
+ this.rowLockTime.pushMetric(this.metricsRecord);
+ this.rwccWaitTime.pushMetric(this.metricsRecord);
this.compactionTime.pushMetric(this.metricsRecord);
this.compactionSize.pushMetric(this.metricsRecord);
this.flushTime.pushMetric(this.metricsRecord);
@@ -293,6 +316,9 @@ public class RegionServerMetrics impleme
this.fsWriteSize.resetMinMax();
this.fsSyncLatency.resetMinMax();
this.fsGroupSyncLatency.resetMinMax();
+ this.memstoreInsertTime.resetMinMax();
+ this.rowLockTime.resetMinMax();
+ this.rwccWaitTime.resetMinMax();
}
/**