You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hbase.apache.org by li...@apache.org on 2014/04/24 20:18:35 UTC

svn commit: r1589819 - in /hbase/branches/0.89-fb/src: main/java/org/apache/hadoop/hbase/ipc/thrift/ test/java/org/apache/hadoop/hbase/thrift/

Author: liyin
Date: Thu Apr 24 18:18:35 2014
New Revision: 1589819

URL: http://svn.apache.org/r1589819
Log:
[HBASE-9930] Making callContext fully support profiling data in swift

Author: adela

Summary: we now support profiling time on the client and on the serverside. I also refactored a little bit the unit test for Header Protocol & profiling data

Test Plan:
extended TestHeaderSendReceive unit test, this is how it looks like
profiling data after first put: client_network_latency.ms:40, hlog_sync_time.ms:1, total_server_time.ms:5
profiling data after second put: client_network_latency.ms:3, hlog_sync_time.ms:1, total_server_time.ms:1
profiling data after get: client_network_latency.ms:3, total_server_time.ms:1
profiling data after get: client_network_latency.ms:4, total_server_time.ms:1

Reviewers: manukranthk, gauravm, fan

Reviewed By: manukranthk

CC: elliott, hbase-eng@

Differential Revision: https://phabricator.fb.com/D1290014

Task ID: 3573857

Modified:
    hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/HBaseToThriftAdapter.java
    hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/ThriftCallStatsReporter.java
    hbase/branches/0.89-fb/src/test/java/org/apache/hadoop/hbase/thrift/TestHeaderSendReceive.java

Modified: hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/HBaseToThriftAdapter.java
URL: http://svn.apache.org/viewvc/hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/HBaseToThriftAdapter.java?rev=1589819&r1=1589818&r2=1589819&view=diff
==============================================================================
--- hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/HBaseToThriftAdapter.java (original)
+++ hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/HBaseToThriftAdapter.java Thu Apr 24 18:18:35 2014
@@ -51,6 +51,7 @@ import org.apache.hadoop.hbase.io.hfile.
 import org.apache.hadoop.hbase.ipc.HBaseRPCOptions;
 import org.apache.hadoop.hbase.ipc.HBaseServer.Call;
 import org.apache.hadoop.hbase.ipc.HRegionInterface;
+import org.apache.hadoop.hbase.ipc.ProfilingData;
 import org.apache.hadoop.hbase.ipc.ScannerResult;
 import org.apache.hadoop.hbase.ipc.ThriftClientInterface;
 import org.apache.hadoop.hbase.ipc.ThriftHRegionInterface;
@@ -58,6 +59,7 @@ import org.apache.hadoop.hbase.ipc.thrif
 import org.apache.hadoop.hbase.master.AssignmentPlan;
 import org.apache.hadoop.hbase.regionserver.HRegion;
 import org.apache.hadoop.hbase.util.Bytes;
+import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
 import org.apache.hadoop.hbase.util.Pair;
 import org.apache.hadoop.io.BytesWritable;
 import org.apache.hadoop.io.LongWritable;
@@ -87,6 +89,8 @@ public class HBaseToThriftAdapter implem
   private Class<? extends ThriftClientInterface> clazz;
   private HBaseRPCOptions options;
   private boolean useHeaderProtocol;
+  // start time of the call on the client side
+  private long startCallTimestamp;
 
   public HBaseToThriftAdapter(ThriftClientInterface connection,
       ThriftClientManager clientManager,
@@ -101,6 +105,7 @@ public class HBaseToThriftAdapter implem
     this.options = options;
     this.useHeaderProtocol = conf.getBoolean(HConstants.USE_HEADER_PROTOCOL,
       HConstants.DEFAULT_USE_HEADER_PROTOCOL);
+    this.startCallTimestamp = -1;
   }
 
   /**
@@ -182,6 +187,7 @@ public class HBaseToThriftAdapter implem
   }
 
   private void preProcess() {
+    this.startCallTimestamp = EnvironmentEdgeManager.currentTimeMillis();
     if (this.connection == null || clientManager == null) {
       if (connection != null) {
         try {
@@ -225,7 +231,11 @@ public class HBaseToThriftAdapter implem
         byte[] dataBytes = Bytes.string64ToBytes(dataString);
         try {
           Call call = Bytes.readThriftBytes(dataBytes, Call.class);
-          this.options.profilingResult = call.getProfilingData();
+          ProfilingData pd = call.getProfilingData();
+          pd.addLong(ProfilingData.CLIENT_NETWORK_LATENCY_MS,
+              EnvironmentEdgeManager.currentTimeMillis()
+                  - this.startCallTimestamp);
+          this.options.profilingResult = pd;
         } catch (Exception e) {
           LOG.error("data deserialization didn't succeed", e);
         }

Modified: hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/ThriftCallStatsReporter.java
URL: http://svn.apache.org/viewvc/hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/ThriftCallStatsReporter.java?rev=1589819&r1=1589818&r2=1589819&view=diff
==============================================================================
--- hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/ThriftCallStatsReporter.java (original)
+++ hbase/branches/0.89-fb/src/main/java/org/apache/hadoop/hbase/ipc/thrift/ThriftCallStatsReporter.java Thu Apr 24 18:18:35 2014
@@ -265,6 +265,8 @@ public class ThriftCallStatsReporter ext
         Call call = HRegionServer.callContext.get();
         HRegionServer.callContext.remove();
         if (call != null && call.isShouldProfile()) {
+          call.getProfilingData().addLong(ProfilingData.TOTAL_SERVER_TIME_MS,
+              ctx.getProcessingTimeMs());
           sendCallInfoToClient(call, ctx.requestContext);
         }
       } catch (Exception e) {

Modified: hbase/branches/0.89-fb/src/test/java/org/apache/hadoop/hbase/thrift/TestHeaderSendReceive.java
URL: http://svn.apache.org/viewvc/hbase/branches/0.89-fb/src/test/java/org/apache/hadoop/hbase/thrift/TestHeaderSendReceive.java?rev=1589819&r1=1589818&r2=1589819&view=diff
==============================================================================
--- hbase/branches/0.89-fb/src/test/java/org/apache/hadoop/hbase/thrift/TestHeaderSendReceive.java (original)
+++ hbase/branches/0.89-fb/src/test/java/org/apache/hadoop/hbase/thrift/TestHeaderSendReceive.java Thu Apr 24 18:18:35 2014
@@ -23,28 +23,32 @@ import static org.junit.Assert.assertNul
 
 import java.io.IOException;
 
+import junit.framework.Assert;
+
 import org.apache.hadoop.hbase.HBaseTestingUtility;
 import org.apache.hadoop.hbase.HConstants;
 import org.apache.hadoop.hbase.client.Get;
+import org.apache.hadoop.hbase.client.HBaseAdmin;
 import org.apache.hadoop.hbase.client.HTable;
 import org.apache.hadoop.hbase.client.HTableAsync;
 import org.apache.hadoop.hbase.client.Put;
 import org.apache.hadoop.hbase.ipc.ProfilingData;
 import org.apache.hadoop.hbase.regionserver.HRegionServer;
 import org.apache.hadoop.hbase.util.Bytes;
-import org.junit.After;
+import org.junit.AfterClass;
 import org.junit.Before;
+import org.junit.BeforeClass;
 import org.junit.Test;
 
 /**
- * Check whether we correctly receive profiling data with the header protocol enabled
+ * Check whether we correctly receive profiling data with the header protocol
+ * enabled
  *
  */
-
 public class TestHeaderSendReceive {
-  private final HBaseTestingUtility TEST_UTIL = new HBaseTestingUtility();
-  private final int SLAVES = 1;
-  static final byte[] TABLE = Bytes.toBytes("testTable");
+  private static HBaseTestingUtility TEST_UTIL;
+  private static final int SLAVES = 1;
+  static final byte[] TABLE1 = Bytes.toBytes("testTable");
   static final byte[] FAMILY = Bytes.toBytes("family");
   static final byte[][] FAMILIES = new byte[][] { FAMILY };
   byte[] r1 = Bytes.toBytes("r1");
@@ -53,6 +57,19 @@ public class TestHeaderSendReceive {
 
   @Before
   public void setUp() throws Exception {
+    HBaseAdmin admin = TEST_UTIL.getHBaseAdmin();
+    if (admin.tableExists(TABLE1)) {
+      if (admin.isTableEnabled(TABLE1)) {
+        admin.disableTable(TABLE1);
+      }
+      admin.deleteTable(TABLE1);
+    }
+    TEST_UTIL.createTable(TABLE1, FAMILIES);
+  }
+
+  @BeforeClass
+  public static void setUpBeforeClass() throws Exception {
+    TEST_UTIL = new HBaseTestingUtility();
     TEST_UTIL.getConfiguration().setBoolean(
         HConstants.REGION_SERVER_WRITE_THRIFT_INFO_TO_META, true);
     TEST_UTIL.getConfiguration().setBoolean(HConstants.CLIENT_TO_RS_USE_THRIFT,
@@ -62,8 +79,8 @@ public class TestHeaderSendReceive {
     TEST_UTIL.startMiniCluster(SLAVES);
   }
 
-  @After
-  public void tearDown() throws Exception {
+  @AfterClass
+  public static void tearDown() throws Exception {
     TEST_UTIL.shutdownMiniCluster();
   }
 
@@ -72,7 +89,7 @@ public class TestHeaderSendReceive {
    */
   @Test
   public void testProfilingData() throws Exception {
-    HTable ht = TEST_UTIL.createTable(TABLE, FAMILIES);
+    HTable ht = new HTable(TEST_UTIL.getConfiguration(), TABLE1);
     Put put = new Put(r1);
     put.add(FAMILY, null, value);
     ht.setProfiling(true);
@@ -80,6 +97,9 @@ public class TestHeaderSendReceive {
     ProfilingData pd = ht.getProfilingData();
     assertNotNull(pd);
     System.out.println("profiling data after first put: " + pd);
+    // check if we are gettng all necessary profiling params
+    checkProfiling(false, true, pd);
+
 
     // disable profiling and check that we get no profiling data back
     ht.setProfiling(false);
@@ -94,6 +114,7 @@ public class TestHeaderSendReceive {
     pd = ht.getProfilingData();
     assertNotNull(pd);
     System.out.println("profiling data after second put: " + pd);
+    checkProfiling(false, true, pd);
 
     // make a get
     Get get = new Get.Builder(r1).addFamily(FAMILY).create();
@@ -102,13 +123,45 @@ public class TestHeaderSendReceive {
     pd = ht.getProfilingData();
     System.out.println("profiling data after get: " + pd);
     assertNotNull(pd);
+    checkProfiling(true, false, pd);
 
     // test async get
     ht.setProfiling(true);
-    ((HTableAsync)ht).getAsync(get).get();
-    pd = ht.getProfilingData();
+    HTableAsync async = new HTableAsync(ht);
+    async.getAsync(get).get();
+    pd = async.getProfilingData();
     System.out.println("profiling data after get: " + pd);
     assertNotNull(pd);
+    checkProfiling(true, false, pd);
+    ht.close();
+  }
+
+  /**
+   * Check that all the necessary profiling info is in profiling data and is not
+   * equal to zero
+   *
+   * @param isGet
+   *          - if the last htable operation was get
+   * @param isPut
+   *          - !isGet (if the last htable operation was put
+   * @param pd
+   *          - profiling data object
+   */
+  public void checkProfiling(boolean isGet, boolean isPut, ProfilingData pd) {
+    assertNotNull(ProfilingData.CLIENT_NETWORK_LATENCY_MS + " is null",
+        pd.getLong(ProfilingData.CLIENT_NETWORK_LATENCY_MS));
+    Assert.assertTrue(ProfilingData.CLIENT_NETWORK_LATENCY_MS
+        + " should be greater than zero",
+        pd.getLong(ProfilingData.CLIENT_NETWORK_LATENCY_MS) > 0);
+    assertNotNull(ProfilingData.TOTAL_SERVER_TIME_MS + " is null",
+        pd.getLong(ProfilingData.TOTAL_SERVER_TIME_MS));
+    Assert.assertTrue(ProfilingData.TOTAL_SERVER_TIME_MS
+        + " should be greater than zero",
+        pd.getLong(ProfilingData.TOTAL_SERVER_TIME_MS) > 0);
+    if (isPut) {
+      assertNotNull(ProfilingData.HLOG_SYNC_TIME_MS + " is null",
+          pd.getLong(ProfilingData.HLOG_SYNC_TIME_MS));
+    }
   }
 
   /**
@@ -120,13 +173,14 @@ public class TestHeaderSendReceive {
   @Test
   public void testServerSideEnabledProfiling() throws IOException {
     HRegionServer.enableServerSideProfilingForAllCalls.set(true);
-    HTable ht = TEST_UTIL.createTable(TABLE, FAMILIES);
+    HTable ht = new HTable(TEST_UTIL.getConfiguration(), TABLE1);
     Put p = new Put(r1);
     p.add(FAMILY, null, value);
     ht.put(p);
     ProfilingData pd = ht.getProfilingData();
     assertNotNull(pd);
     System.out.println("profiling data: " + pd);
+    ht.close();
   }
 
 }