From 4e0109dab015cbe54b9b06db1354c47dd712605e Mon Sep 17 00:00:00 2001 From: fantasy <875282031@qq.com> Date: Tue, 16 Aug 2022 22:46:42 +0800 Subject: [PATCH 1/6] In trace log mode, the client does not print callId/startTime and the server does not print receiveTime, so fix it --- .../java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java | 3 ++- .../main/java/org/apache/hadoop/hbase/ipc/RpcServer.java | 6 +++--- 2 files changed, 5 insertions(+), 4 deletions(-) diff --git a/hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java b/hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java index e5863948a58c..d8f4b96bf0aa 100644 --- a/hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java +++ b/hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java @@ -380,7 +380,8 @@ private void onCallFinished(Call call, HBaseRpcController hrc, Address addr, } if (LOG.isTraceEnabled()) { LOG.trace( - "Call: " + call.md.getName() + ", callTime: " + call.callStats.getCallTimeMs() + "ms"); + "CallId: {}, call: {}, startTime: {}ms, callTime: {}ms", call.id, call.getStartTime(), + call.md.getName(), call.callStats.getCallTimeMs()); } if (call.error != null) { if (call.error instanceof RemoteException) { diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java index 966b13aa869c..d39ef2a782b8 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java @@ -390,9 +390,9 @@ public Pair call(RpcCall call, MonitoredRPCHandler status) int qTime = (int) (startTime - receiveTime); int totalTime = (int) (endTime - receiveTime); if (LOG.isTraceEnabled()) { - LOG.trace(CurCall.get().toString() + ", response " + TextFormat.shortDebugString(result) - + " queueTime: " + qTime + " processingTime: " + processingTime + " totalTime: " - + totalTime); + LOG.trace("{}, response: {}, receiveTime: {}, queueTime: {}, processingTime: {}, totalTime: {}", + CurCall.get().toString(), TextFormat.shortDebugString(result), CurCall.get().getReceiveTime(), + qTime, processingTime, totalTime); } // Use the raw request call size for now. long requestSize = call.getSize(); From c906356202d993c107eea297590e93a5ca5aed65 Mon Sep 17 00:00:00 2001 From: "jay.zhu" Date: Wed, 17 Aug 2022 16:06:28 +0800 Subject: [PATCH 2/6] HBASE-27268 In trace log mode, the client does not print callId/startTime and the server does not print receiveTime --- .../org/apache/hadoop/hbase/ipc/AbstractRpcClient.java | 5 ++--- .../main/java/org/apache/hadoop/hbase/ipc/RpcServer.java | 7 ++++--- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java b/hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java index d8f4b96bf0aa..0afd07d79513 100644 --- a/hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java +++ b/hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java @@ -379,9 +379,8 @@ private void onCallFinished(Call call, HBaseRpcController hrc, Address addr, metrics.updateRpc(call.md, call.param, call.callStats); } if (LOG.isTraceEnabled()) { - LOG.trace( - "CallId: {}, call: {}, startTime: {}ms, callTime: {}ms", call.id, call.getStartTime(), - call.md.getName(), call.callStats.getCallTimeMs()); + LOG.trace("CallId: {}, call: {}, startTime: {}ms, callTime: {}ms", call.id, call.md.getName(), + call.getStartTime(), call.callStats.getCallTimeMs()); } if (call.error != null) { if (call.error instanceof RemoteException) { diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java index d39ef2a782b8..15caac476f35 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java @@ -390,9 +390,10 @@ public Pair call(RpcCall call, MonitoredRPCHandler status) int qTime = (int) (startTime - receiveTime); int totalTime = (int) (endTime - receiveTime); if (LOG.isTraceEnabled()) { - LOG.trace("{}, response: {}, receiveTime: {}, queueTime: {}, processingTime: {}, totalTime: {}", - CurCall.get().toString(), TextFormat.shortDebugString(result), CurCall.get().getReceiveTime(), - qTime, processingTime, totalTime); + LOG.trace( + "{}, response: {}, receiveTime: {}, queueTime: {}, processingTime: {}, totalTime: {}", + CurCall.get().toString(), TextFormat.shortDebugString(result), + CurCall.get().getReceiveTime(), qTime, processingTime, totalTime); } // Use the raw request call size for now. long requestSize = call.getSize(); From 5e8d1c1a2a97d9eaac939e922f72f080785de9ac Mon Sep 17 00:00:00 2001 From: "jay.zhu" Date: Fri, 5 May 2023 15:57:25 +0800 Subject: [PATCH 3/6] HBASE-27845 Distinguish the mutate type of rpc error in MetricsConnection --- .../hbase/client/MetricsConnection.java | 22 ++++++++++++++++++- .../hbase/client/TestMetricsConnection.java | 19 +++++++++++++--- 2 files changed, 37 insertions(+), 4 deletions(-) diff --git a/hbase-client/src/main/java/org/apache/hadoop/hbase/client/MetricsConnection.java b/hbase-client/src/main/java/org/apache/hadoop/hbase/client/MetricsConnection.java index dd3e571a8b7a..039455ddd633 100644 --- a/hbase-client/src/main/java/org/apache/hadoop/hbase/client/MetricsConnection.java +++ b/hbase-client/src/main/java/org/apache/hadoop/hbase/client/MetricsConnection.java @@ -652,7 +652,27 @@ public void updateRpc(MethodDescriptor method, Message param, CallStats stats, T concurrentCallsPerServerHist.update(callsPerServer); } // Update the counter that tracks RPCs by type. - final String methodName = method.getService().getName() + "_" + method.getName(); + String methodName = method.getService().getName() + "_" + method.getName(); + // Distinguish mutate types. + if ("Mutate".equals(method.getName())) { + final MutationType type = ((MutateRequest) param).getMutation().getMutateType(); + switch (type) { + case APPEND: + methodName += "(Append)"; + break; + case DELETE: + methodName += "(Delete)"; + break; + case INCREMENT: + methodName += "(Increment)"; + break; + case PUT: + methodName += "(Put)"; + break; + default: + throw new RuntimeException("Unrecognized mutation type " + type); + } + } getMetric(CNT_BASE + methodName, rpcCounters, counterFactory).inc(); if (e != null) { getMetric(FAILURE_CNT_BASE + methodName, rpcCounters, counterFactory).inc(); diff --git a/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java b/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java index d70d2cf60006..704ce751ebcd 100644 --- a/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java +++ b/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java @@ -188,15 +188,15 @@ public void testStaticMetrics() throws IOException { long metricVal; Counter counter; - for (String method : new String[] { "Get", "Scan", "Multi", "Mutate" }) { + for (String method : new String[] { "Get", "Scan", "Multi" }) { metricKey = rpcCountPrefix + method; metricVal = METRICS.getRpcCounters().get(metricKey).getCount(); - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal >= loop); + assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); metricKey = rpcFailureCountPrefix + method; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; - if (method.equals("Get") || method.equals("Mutate")) { + if (method.equals("Get")) { // no failure assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == 0); } else { @@ -205,6 +205,19 @@ public void testStaticMetrics() throws IOException { } } + String method = "Mutate"; + for (String mutationType : new String[] { "Append", "Delete", "Increment", "Put" }) { + metricKey = rpcCountPrefix + method + "(" + mutationType + ")"; + metricVal = METRICS.getRpcCounters().get(metricKey).getCount(); + assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); + + metricKey = rpcFailureCountPrefix + method; + counter = METRICS.getRpcCounters().get(metricKey); + metricVal = (counter != null) ? counter.getCount() : 0; + // no failure + assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == 0); + } + // remote exception metricKey = "rpcRemoteExceptions_IOException"; counter = METRICS.getRpcCounters().get(metricKey); From b3d846a94a4fae3963bc378031f6762dac33b81b Mon Sep 17 00:00:00 2001 From: "jay.zhu" Date: Fri, 5 May 2023 16:19:53 +0800 Subject: [PATCH 4/6] HBASE-27845 Distinguish the mutate type of rpc error in MetricsConnection --- .../hbase/client/TestMetricsConnection.java | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java b/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java index 704ce751ebcd..92f5e65e36a1 100644 --- a/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java +++ b/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java @@ -177,8 +177,8 @@ public void testStaticMetrics() throws IOException { METRICS.updateRpc(ClientService.getDescriptor().findMethodByName("Mutate"), MutateRequest.newBuilder() .setMutation(ProtobufUtil.toMutation(MutationType.PUT, new Put(foo))).setRegion(region) - .build(), - MetricsConnection.newCallStats(), null); + .build(), MetricsConnection.newCallStats(), + new CallTimeoutException("test with CallTimeoutException")); } final String rpcCountPrefix = "rpcCount_" + ClientService.getDescriptor().getName() + "_"; @@ -211,11 +211,16 @@ public void testStaticMetrics() throws IOException { metricVal = METRICS.getRpcCounters().get(metricKey).getCount(); assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); - metricKey = rpcFailureCountPrefix + method; + metricKey = rpcFailureCountPrefix + method + "(" + mutationType + ")"; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; - // no failure - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == 0); + if (mutationType.equals("Put")) { + // no failure + assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); + } else { + // has failure + assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == 0); + } } // remote exception @@ -228,13 +233,13 @@ public void testStaticMetrics() throws IOException { metricKey = "rpcLocalExceptions_CallTimeoutException"; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); + assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop * 2); // total exception metricKey = "rpcTotalExceptions"; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop * 2); + assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop * 3); for (MetricsConnection.CallTracker t : new MetricsConnection.CallTracker[] { METRICS.getGetTracker(), METRICS.getScanTracker(), METRICS.getMultiTracker(), From ef0ce71c7e7b058bc35a78796b28cd2436d07214 Mon Sep 17 00:00:00 2001 From: "jay.zhu" Date: Fri, 5 May 2023 17:31:13 +0800 Subject: [PATCH 5/6] run spotless:apply to fix. --- .../org/apache/hadoop/hbase/client/TestMetricsConnection.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java b/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java index 92f5e65e36a1..746240df31b3 100644 --- a/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java +++ b/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java @@ -177,7 +177,8 @@ public void testStaticMetrics() throws IOException { METRICS.updateRpc(ClientService.getDescriptor().findMethodByName("Mutate"), MutateRequest.newBuilder() .setMutation(ProtobufUtil.toMutation(MutationType.PUT, new Put(foo))).setRegion(region) - .build(), MetricsConnection.newCallStats(), + .build(), + MetricsConnection.newCallStats(), new CallTimeoutException("test with CallTimeoutException")); } From b04e455bdcdd7004b85a3b34111c0e96a5c205da Mon Sep 17 00:00:00 2001 From: "jay.zhu" Date: Mon, 22 May 2023 11:01:47 +0800 Subject: [PATCH 6/6] HBASE-27845 Distinguish the mutate types of rpc error in MetricsConnection. --- .../hbase/client/MetricsConnection.java | 15 ++++++------ .../hbase/client/TestMetricsConnection.java | 24 +++++++++---------- 2 files changed, 20 insertions(+), 19 deletions(-) diff --git a/hbase-client/src/main/java/org/apache/hadoop/hbase/client/MetricsConnection.java b/hbase-client/src/main/java/org/apache/hadoop/hbase/client/MetricsConnection.java index 039455ddd633..8a299dc4e5c1 100644 --- a/hbase-client/src/main/java/org/apache/hadoop/hbase/client/MetricsConnection.java +++ b/hbase-client/src/main/java/org/apache/hadoop/hbase/client/MetricsConnection.java @@ -652,25 +652,26 @@ public void updateRpc(MethodDescriptor method, Message param, CallStats stats, T concurrentCallsPerServerHist.update(callsPerServer); } // Update the counter that tracks RPCs by type. - String methodName = method.getService().getName() + "_" + method.getName(); + StringBuilder methodName = new StringBuilder(); + methodName.append(method.getService().getName()).append("_").append(method.getName()); // Distinguish mutate types. if ("Mutate".equals(method.getName())) { final MutationType type = ((MutateRequest) param).getMutation().getMutateType(); switch (type) { case APPEND: - methodName += "(Append)"; + methodName.append("(Append)"); break; case DELETE: - methodName += "(Delete)"; + methodName.append("(Delete)"); break; case INCREMENT: - methodName += "(Increment)"; + methodName.append("(Increment)"); break; case PUT: - methodName += "(Put)"; + methodName.append("(Put)"); break; default: - throw new RuntimeException("Unrecognized mutation type " + type); + methodName.append("(Unknown)"); } } getMetric(CNT_BASE + methodName, rpcCounters, counterFactory).inc(); @@ -749,7 +750,7 @@ public void updateRpc(MethodDescriptor method, Message param, CallStats stats, T } } // Fallback to dynamic registry lookup for DDL methods. - updateRpcGeneric(methodName, stats); + updateRpcGeneric(methodName.toString(), stats); } public void incrCacheDroppingExceptions(Object exception) { diff --git a/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java b/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java index 746240df31b3..2afdc7ee558d 100644 --- a/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java +++ b/hbase-client/src/test/java/org/apache/hadoop/hbase/client/TestMetricsConnection.java @@ -99,7 +99,7 @@ public void testMetricsConnectionScope() throws IOException { } @Test - public void testMetricsWithMutiConnections() throws IOException { + public void testMetricsWithMultiConnections() throws IOException { Configuration conf = new Configuration(); conf.setBoolean(MetricsConnection.CLIENT_SIDE_METRICS_ENABLED_KEY, true); conf.set(MetricsConnection.METRICS_SCOPE_KEY, "unit-test"); @@ -192,17 +192,17 @@ public void testStaticMetrics() throws IOException { for (String method : new String[] { "Get", "Scan", "Multi" }) { metricKey = rpcCountPrefix + method; metricVal = METRICS.getRpcCounters().get(metricKey).getCount(); - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); + assertEquals("metric: " + metricKey + " val: " + metricVal, metricVal, loop); metricKey = rpcFailureCountPrefix + method; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; if (method.equals("Get")) { // no failure - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == 0); + assertEquals("metric: " + metricKey + " val: " + metricVal, 0, metricVal); } else { // has failure - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); + assertEquals("metric: " + metricKey + " val: " + metricVal, metricVal, loop); } } @@ -210,17 +210,17 @@ public void testStaticMetrics() throws IOException { for (String mutationType : new String[] { "Append", "Delete", "Increment", "Put" }) { metricKey = rpcCountPrefix + method + "(" + mutationType + ")"; metricVal = METRICS.getRpcCounters().get(metricKey).getCount(); - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); + assertEquals("metric: " + metricKey + " val: " + metricVal, metricVal, loop); metricKey = rpcFailureCountPrefix + method + "(" + mutationType + ")"; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; if (mutationType.equals("Put")) { - // no failure - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); - } else { // has failure - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == 0); + assertEquals("metric: " + metricKey + " val: " + metricVal, metricVal, loop); + } else { + // no failure + assertEquals("metric: " + metricKey + " val: " + metricVal, 0, metricVal); } } @@ -228,19 +228,19 @@ public void testStaticMetrics() throws IOException { metricKey = "rpcRemoteExceptions_IOException"; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop); + assertEquals("metric: " + metricKey + " val: " + metricVal, metricVal, loop); // local exception metricKey = "rpcLocalExceptions_CallTimeoutException"; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop * 2); + assertEquals("metric: " + metricKey + " val: " + metricVal, metricVal, loop * 2); // total exception metricKey = "rpcTotalExceptions"; counter = METRICS.getRpcCounters().get(metricKey); metricVal = (counter != null) ? counter.getCount() : 0; - assertTrue("metric: " + metricKey + " val: " + metricVal, metricVal == loop * 3); + assertEquals("metric: " + metricKey + " val: " + metricVal, metricVal, loop * 3); for (MetricsConnection.CallTracker t : new MetricsConnection.CallTracker[] { METRICS.getGetTracker(), METRICS.getScanTracker(), METRICS.getMultiTracker(),