Author: apurtell
Date: Thu Dec 31 05:19:33 2009
New Revision: 894780
URL: http://svn.apache.org/viewvc?rev=894780&view=rev
Log:
HBASE-1956 Export HDFS read and write latency as a metric
Modified:
hadoop/hbase/branches/0.20/CHANGES.txt
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/io/hfile/HFile.java
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/HLog.java
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java
Modified: hadoop/hbase/branches/0.20/CHANGES.txt
URL:
http://svn.apache.org/viewvc/hadoop/hbase/branches/0.20/CHANGES.txt?rev=894780&r1=894779&r2=894780&view=diff
==============================================================================
--- hadoop/hbase/branches/0.20/CHANGES.txt (original)
+++ hadoop/hbase/branches/0.20/CHANGES.txt Thu Dec 31 05:19:33 2009
@@ -72,6 +72,7 @@
HBASE-2025 0.20.2 accessed from older client throws
UndeclaredThrowableException; frustrates rolling upgrade
HBASE-2081 Set the retries higher in shell since client pause is lower
+ HBASE-1956 Export HDFS read and write latency as a metric
Release 0.20.2 - November 18th, 2009
INCOMPATIBLE CHANGES
Modified:
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/io/hfile/HFile.java
URL:
http://svn.apache.org/viewvc/hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/io/hfile/HFile.java?rev=894780&r1=894779&r2=894780&view=diff
==============================================================================
---
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/io/hfile/HFile.java
(original)
+++
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/io/hfile/HFile.java
Thu Dec 31 05:19:33 2009
@@ -154,6 +154,36 @@
public final static String DEFAULT_COMPRESSION =
DEFAULT_COMPRESSION_ALGORITHM.getName();
+ // For measuring latency of "typical" reads and writes
+ private static volatile long readOps;
+ private static volatile long readTime;
+ private static volatile long writeOps;
+ private static volatile long writeTime;
+
+ public static final long getReadOps() {
+ long ret = readOps;
+ readOps = 0;
+ return ret;
+ }
+
+ public static final long getReadTime() {
+ long ret = readTime;
+ readTime = 0;
+ return ret;
+ }
+
+ public static final long getWriteOps() {
+ long ret = writeOps;
+ writeOps = 0;
+ return ret;
+ }
+
+ public static final long getWriteTime() {
+ long ret = writeTime;
+ writeTime = 0;
+ return ret;
+ }
+
/**
* HFile Writer.
*/
@@ -320,12 +350,17 @@
*/
private void finishBlock() throws IOException {
if (this.out == null) return;
+ long now = System.currentTimeMillis();
+
int size = releaseCompressingStream(this.out);
this.out = null;
blockKeys.add(firstKey);
blockOffsets.add(Long.valueOf(blockBegin));
blockDataSizes.add(Integer.valueOf(size));
this.totalBytes += size;
+
+ writeTime += System.currentTimeMillis() - now;
+ writeOps++;
}
/*
@@ -887,6 +922,7 @@
buf.rewind();
return buf;
}
+
/**
* Read in a file block.
* @param block Index of block to read.
@@ -901,7 +937,6 @@
throw new IOException("Requested block is out of range: " + block +
", max: " + blockIndex.count);
}
-
// For any given block from any given file, synchronize reads for said
// block.
// Without a cache, this synchronizing is needless overhead, but really
@@ -921,6 +956,7 @@
}
// Load block from filesystem.
+ long now = System.currentTimeMillis();
long onDiskBlockSize;
if (block == blockIndex.count - 1) {
// last block! The end of data block is first meta block if there is
@@ -945,6 +981,9 @@
buf.limit(buf.limit() - DATABLOCKMAGIC.length);
buf.rewind();
+ readTime += System.currentTimeMillis() - now;
+ readOps++;
+
// Cache the block
if(cacheBlock && cache != null) {
cache.cacheBlock(name + block, buf.duplicate(), inMemory);
Modified:
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/HLog.java
URL:
http://svn.apache.org/viewvc/hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/HLog.java?rev=894780&r1=894779&r2=894780&view=diff
==============================================================================
---
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/HLog.java
(original)
+++
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/HLog.java
Thu Dec 31 05:19:33 2009
@@ -175,6 +175,37 @@
}
}
+ // For measuring latency of writes
+ private static volatile long writeOps;
+ private static volatile long writeTime;
+ // For measuring latency of syncs
+ private static volatile long syncOps;
+ private static volatile long syncTime;
+
+ public static long getWriteOps() {
+ long ret = writeOps;
+ writeOps = 0;
+ return ret;
+ }
+
+ public static long getWriteTime() {
+ long ret = writeTime;
+ writeTime = 0;
+ return ret;
+ }
+
+ public static long getSyncOps() {
+ long ret = syncOps;
+ syncOps = 0;
+ return ret;
+ }
+
+ public static long getSyncTime() {
+ long ret = syncTime;
+ syncTime = 0;
+ return ret;
+ }
+
/**
* Create an edit log at the given <code>dir</code> location.
*
@@ -615,6 +646,8 @@
this.writer.sync();
}
this.unflushedEntries.set(0);
+ syncTime += System.currentTimeMillis() - lastLogFlushTime;
+ syncOps++;
}
void optionalSync() {
@@ -653,14 +686,16 @@
try {
this.editsSize.addAndGet(logKey.heapSize() + logEdit.heapSize());
this.writer.append(logKey, logEdit);
- if (sync || this.unflushedEntries.incrementAndGet() >= flushlogentries) {
- sync();
- }
long took = System.currentTimeMillis() - now;
+ writeTime += took;
+ writeOps++;
if (took > 1000) {
LOG.warn(Thread.currentThread().getName() + " took " + took +
"ms appending an edit to hlog; editcount=" + this.numEntries.get());
}
+ if (sync || this.unflushedEntries.incrementAndGet() >= flushlogentries) {
+ sync();
+ }
} catch (IOException e) {
LOG.fatal("Could not append. Requesting close of hlog", e);
requestLogRoll();
@@ -734,8 +769,11 @@
return;
}
synchronized (updateLock) {
+ long now = System.currentTimeMillis();
this.writer.append(makeKey(regionName, tableName, logSeqId,
System.currentTimeMillis()),
completeCacheFlushLogEdit());
+ writeTime += System.currentTimeMillis() - now;
+ writeOps++;
this.numEntries.incrementAndGet();
Long seq = this.lastSeqWritten.get(regionName);
if (seq != null && logSeqId >= seq.longValue()) {
Modified:
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java
URL:
http://svn.apache.org/viewvc/hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java?rev=894780&r1=894779&r2=894780&view=diff
==============================================================================
---
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java
(original)
+++
hadoop/hbase/branches/0.20/src/java/org/apache/hadoop/hbase/regionserver/metrics/RegionServerMetrics.java
Thu Dec 31 05:19:33 2009
@@ -22,7 +22,9 @@
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
+import org.apache.hadoop.hbase.io.hfile.HFile;
import org.apache.hadoop.hbase.metrics.MetricsRate;
+import org.apache.hadoop.hbase.regionserver.HLog;
import org.apache.hadoop.hbase.util.Strings;
import org.apache.hadoop.metrics.MetricsContext;
import org.apache.hadoop.metrics.MetricsRecord;
@@ -105,6 +107,24 @@
public final MetricsIntValue memstoreSizeMB =
new MetricsIntValue("memstoreSizeMB", registry);
+ /**
+ * filesystem read latency
+ */
+ public final MetricsTimeVaryingRate fsReadLatency =
+ new MetricsTimeVaryingRate("fsReadLatency", registry);
+
+ /**
+ * filesystem write latency
+ */
+ public final MetricsTimeVaryingRate fsWriteLatency =
+ new MetricsTimeVaryingRate("fsWriteLatency", registry);
+
+ /**
+ * filesystem sync latency
+ */
+ public final MetricsTimeVaryingRate fsSyncLatency =
+ new MetricsTimeVaryingRate("fsSyncLatency", registry);
+
public RegionServerMetrics() {
MetricsContext context = MetricsUtil.getContext("hbase");
metricsRecord = MetricsUtil.createRecord(context, "regionserver");
@@ -143,13 +163,26 @@
this.blockCacheFree.pushMetric(this.metricsRecord);
this.blockCacheCount.pushMetric(this.metricsRecord);
this.blockCacheHitRatio.pushMetric(this.metricsRecord);
+
+ // mix in HFile metrics
+ this.fsReadLatency.inc((int)HFile.getReadOps(), HFile.getReadTime());
+ this.fsWriteLatency.inc((int)HFile.getWriteOps(), HFile.getWriteTime());
+ // mix in HLog metrics
+ this.fsWriteLatency.inc((int)HLog.getWriteOps(), HLog.getWriteTime());
+ this.fsSyncLatency.inc((int)HLog.getSyncOps(), HLog.getSyncTime());
+ // push the result
+ this.fsReadLatency.pushMetric(this.metricsRecord);
+ this.fsWriteLatency.pushMetric(this.metricsRecord);
+ this.fsSyncLatency.pushMetric(this.metricsRecord);
}
this.metricsRecord.update();
this.lastUpdate = System.currentTimeMillis();
}
public void resetAllMinMax() {
- // Nothing to do
+ this.atomicIncrementTime.resetMinMax();
+ this.fsReadLatency.resetMinMax();
+ this.fsWriteLatency.resetMinMax();
}
/**
