HBASE-27268 In trace log mode, the client does not print callId/startTime and the server does not print receiveTime (#4710)

Co-authored-by: jay.zhu <jay.zhu@huolala.cn>
Signed-off-by: Duo Zhang <zhangduo@apache.org>
(cherry picked from commit 32c135d)

Author: 2 people

hbase-client/src/main/java/org/apache/hadoop/hbase/ipc/AbstractRpcClient.java

@@ -373,8 +373,8 @@ private void onCallFinished(Call call, HBaseRpcController hrc, InetSocketAddress
       metrics.updateRpc(call.md, call.param, call.callStats);
     }
     if (LOG.isTraceEnabled()) {
-      LOG.trace(
-        "Call: " + call.md.getName() + ", callTime: " + call.callStats.getCallTimeMs() + "ms");
+      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) {

hbase-server/src/main/java/org/apache/hadoop/hbase/ipc/RpcServer.java

@@ -390,9 +390,10 @@ public Pair<Message, CellScanner> 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();