[hadoop] branch trunk updated: HADOOP-16531. Log more timing information for slow RPCs. Contributed by Chen Zhang.

[xk...@apache.org]

This is an automated email from the ASF dual-hosted git repository.

xkrogen pushed a commit to branch trunk
in repository https://gitbox.apache.org/repos/asf/hadoop.git


The following commit(s) were added to refs/heads/trunk by this push:
     new a234175  HADOOP-16531. Log more timing information for slow RPCs. Contributed by Chen Zhang.
a234175 is described below

commit a23417533e1ee052893baf207ec636c4993c5994
Author: Erik Krogen <xk...@apache.org>
AuthorDate: Fri Sep 6 10:28:21 2019 -0700

    HADOOP-16531. Log more timing information for slow RPCs. Contributed by Chen Zhang.
---
 .../src/main/java/org/apache/hadoop/ipc/Server.java      | 16 +++++++++++-----
 1 file changed, 11 insertions(+), 5 deletions(-)

diff --git a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/ipc/Server.java b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/ipc/Server.java
index 14fc2de..df19de2 100644
--- a/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/ipc/Server.java
+++ b/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/ipc/Server.java
@@ -508,7 +508,7 @@ public abstract class Server {
    * Logs a Slow RPC Request.
    *
    * @param methodName - RPC Request method name
-   * @param processingTime - Processing Time.
+   * @param details - Processing Detail.
    *
    * if this request took too much time relative to other requests
    * we consider that as a slow RPC. 3 is a magic number that comes
@@ -517,7 +517,8 @@ public abstract class Server {
    * if and only if it falls above 99.7% of requests. We start this logic
    * only once we have enough sample size.
    */
-  void logSlowRpcCalls(String methodName, Call call, long processingTime) {
+  void logSlowRpcCalls(String methodName, Call call,
+      ProcessingDetails details) {
     final int deviation = 3;
 
     // 1024 for minSampleSize just a guess -- not a number computed based on
@@ -528,10 +529,15 @@ public abstract class Server {
     final double threeSigma = rpcMetrics.getProcessingMean() +
         (rpcMetrics.getProcessingStdDev() * deviation);
 
+    long processingTime =
+            details.get(Timing.PROCESSING, RpcMetrics.TIMEUNIT);
     if ((rpcMetrics.getProcessingSampleCount() > minSampleSize) &&
         (processingTime > threeSigma)) {
-      LOG.warn("Slow RPC : {} took {} {} to process from client {}",
-          methodName, processingTime, RpcMetrics.TIMEUNIT, call);
+      LOG.warn(
+          "Slow RPC : {} took {} {} to process from client {},"
+              + " the processing detail is {}",
+          methodName, processingTime, RpcMetrics.TIMEUNIT, call,
+          details.toString());
       rpcMetrics.incrSlowRpc();
     }
   }
@@ -570,7 +576,7 @@ public abstract class Server {
     rpcDetailedMetrics.addProcessingTime(name, processingTime);
     callQueue.addResponseTime(name, call, details);
     if (isLogSlowRPC()) {
-      logSlowRpcCalls(name, call, processingTime);
+      logSlowRpcCalls(name, call, details);
     }
   }
 


---------------------------------------------------------------------
To unsubscribe, e-mail: common-commits-unsubscribe@hadoop.apache.org
For additional commands, e-mail: common-commits-help@hadoop.apache.org