Repository: hbase Updated Branches: refs/heads/master 539f97c02 -> 3fe510250
HBASE-17611 Thrift2 per-call latency metrics are capped at ~2 seconds Project: http://git-wip-us.apache.org/repos/asf/hbase/repo Commit: http://git-wip-us.apache.org/repos/asf/hbase/commit/3fe51025 Tree: http://git-wip-us.apache.org/repos/asf/hbase/tree/3fe51025 Diff: http://git-wip-us.apache.org/repos/asf/hbase/diff/3fe51025 Branch: refs/heads/master Commit: 3fe51025068f04968518be4e3ecaef889f6f63d3 Parents: 539f97c Author: Gary Helmling <ga...@apache.org> Authored: Wed Feb 8 16:59:34 2017 -0800 Committer: Gary Helmling <ga...@apache.org> Committed: Mon Feb 13 10:16:36 2017 -0800 ---------------------------------------------------------------------- .../thrift2/ThriftHBaseServiceHandler.java | 2 +- .../thrift2/TestThriftHBaseServiceHandler.java | 87 ++++++++++++++++++++ 2 files changed, 88 insertions(+), 1 deletion(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/hbase/blob/3fe51025/hbase-thrift/src/main/java/org/apache/hadoop/hbase/thrift2/ThriftHBaseServiceHandler.java ---------------------------------------------------------------------- diff --git a/hbase-thrift/src/main/java/org/apache/hadoop/hbase/thrift2/ThriftHBaseServiceHandler.java b/hbase-thrift/src/main/java/org/apache/hadoop/hbase/thrift2/ThriftHBaseServiceHandler.java index c5da48e..d0c44aa 100644 --- a/hbase-thrift/src/main/java/org/apache/hadoop/hbase/thrift2/ThriftHBaseServiceHandler.java +++ b/hbase-thrift/src/main/java/org/apache/hadoop/hbase/thrift2/ThriftHBaseServiceHandler.java @@ -122,7 +122,7 @@ public class ThriftHBaseServiceHandler implements THBaseService.Iface { metrics.exception(e); throw new RuntimeException("unexpected invocation exception: " + e.getMessage()); } finally { - int processTime = (int) (now() - start); + long processTime = now() - start; metrics.incMethodTime(m.getName(), processTime); } return result; http://git-wip-us.apache.org/repos/asf/hbase/blob/3fe51025/hbase-thrift/src/test/java/org/apache/hadoop/hbase/thrift2/TestThriftHBaseServiceHandler.java ---------------------------------------------------------------------- diff --git a/hbase-thrift/src/test/java/org/apache/hadoop/hbase/thrift2/TestThriftHBaseServiceHandler.java b/hbase-thrift/src/test/java/org/apache/hadoop/hbase/thrift2/TestThriftHBaseServiceHandler.java index 9a3800d..c909a01 100644 --- a/hbase-thrift/src/test/java/org/apache/hadoop/hbase/thrift2/TestThriftHBaseServiceHandler.java +++ b/hbase-thrift/src/test/java/org/apache/hadoop/hbase/thrift2/TestThriftHBaseServiceHandler.java @@ -22,7 +22,9 @@ import com.google.common.collect.Lists; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; import org.apache.hadoop.conf.Configuration; +import org.apache.hadoop.hbase.Cell; import org.apache.hadoop.hbase.CompatibilityFactory; +import org.apache.hadoop.hbase.CoprocessorEnvironment; import org.apache.hadoop.hbase.HBaseTestingUtility; import org.apache.hadoop.hbase.HColumnDescriptor; import org.apache.hadoop.hbase.HTableDescriptor; @@ -35,7 +37,11 @@ import org.apache.hadoop.hbase.client.Increment; import org.apache.hadoop.hbase.client.Delete; import org.apache.hadoop.hbase.client.Durability; import org.apache.hadoop.hbase.client.Table; +import org.apache.hadoop.hbase.coprocessor.BaseRegionObserver; +import org.apache.hadoop.hbase.coprocessor.ObserverContext; +import org.apache.hadoop.hbase.coprocessor.RegionCoprocessorEnvironment; import org.apache.hadoop.hbase.filter.ParseFilter; +import org.apache.hadoop.hbase.protobuf.generated.HBaseProtos; import org.apache.hadoop.hbase.security.UserProvider; import org.apache.hadoop.hbase.test.MetricsAssertHelper; import org.apache.hadoop.hbase.testclassification.ClientTests; @@ -69,6 +75,7 @@ import org.junit.Test; import org.junit.experimental.categories.Category; import java.io.IOException; +import java.io.InterruptedIOException; import java.nio.ByteBuffer; import java.util.ArrayList; import java.util.Arrays; @@ -77,6 +84,7 @@ import java.util.Comparator; import java.util.List; import java.util.Map; import java.util.HashMap; +import java.util.concurrent.TimeUnit; import static org.apache.hadoop.hbase.thrift2.ThriftUtilities.getFromThrift; import static org.apache.hadoop.hbase.thrift2.ThriftUtilities.putFromThrift; @@ -1044,6 +1052,59 @@ public class TestThriftHBaseServiceHandler { } + /** + * See HBASE-17611 + * + * Latency metrics were capped at ~ 2 seconds due to the use of an int variable to capture the + * duration. + */ + @Test + public void testMetricsPrecision() throws Exception { + byte[] rowkey = Bytes.toBytes("row1"); + byte[] family = Bytes.toBytes("f"); + byte[] col = Bytes.toBytes("c"); + // create a table which will throw exceptions for requests + TableName tableName = TableName.valueOf("testMetricsPrecision"); + HTableDescriptor tableDesc = new HTableDescriptor(tableName); + tableDesc.addCoprocessor(DelayingRegionObserver.class.getName()); + tableDesc.addFamily(new HColumnDescriptor(family)); + + Table table = null; + try { + table = UTIL.createTable(tableDesc, null); + + table.put(new Put(rowkey).addColumn(family, col, Bytes.toBytes("val1"))); + + ThriftHBaseServiceHandler hbaseHandler = createHandler(); + ThriftMetrics metrics = getMetrics(UTIL.getConfiguration()); + THBaseService.Iface handler = + ThriftHBaseServiceHandler.newInstance(hbaseHandler, metrics); + ByteBuffer tTableName = wrap(tableName.getName()); + + // check metrics latency with a successful get + TGet tGet = new TGet(wrap(rowkey)); + TResult tResult = handler.get(tTableName, tGet); + + List<TColumnValue> expectedColumnValues = Lists.newArrayList( + new TColumnValue(wrap(family), wrap(col), wrap(Bytes.toBytes("val1"))) + ); + assertArrayEquals(rowkey, tResult.getRow()); + List<TColumnValue> returnedColumnValues = tResult.getColumnValues(); + assertTColumnValuesEqual(expectedColumnValues, returnedColumnValues); + + metricsHelper.assertGaugeGt("get_max", 3000L, metrics.getSource()); + } finally { + if (table != null) { + try { + table.close(); + } catch (IOException ignored) { + } + UTIL.deleteTable(tableName); + } + } + } + + @Test public void testAttribute() throws Exception { byte[] rowName = "testAttribute".getBytes(); @@ -1264,5 +1325,31 @@ public class TestThriftHBaseServiceHandler { assertTColumnValueEqual(columnValueA, result.getColumnValues().get(0)); assertTColumnValueEqual(columnValueB, result.getColumnValues().get(1)); } + + public static class DelayingRegionObserver extends BaseRegionObserver { + private static final Log LOG = LogFactory.getLog(DelayingRegionObserver.class); + // sleep time in msec + private long delayMillis; + + @Override + public void start(CoprocessorEnvironment e) throws IOException { + this.delayMillis = e.getConfiguration() + .getLong("delayingregionobserver.delay", 3000); + } + + @Override + public void preGetOp(ObserverContext<RegionCoprocessorEnvironment> e, Get get, + List<Cell> results) throws IOException { + try { + long start = System.currentTimeMillis(); + TimeUnit.MILLISECONDS.sleep(delayMillis); + if (LOG.isTraceEnabled()) { + LOG.trace("Slept for " + (System.currentTimeMillis() - start) + " msec"); + } + } catch (InterruptedException ie) { + throw new InterruptedIOException("Interrupted while sleeping"); + } + } + } }
