apache · roryqi · Jul 21, 2022 · Jul 21, 2022 · Jul 21, 2022
diff --git a/client/src/main/java/org/apache/uniffle/client/impl/ShuffleWriteClientImpl.java b/client/src/main/java/org/apache/uniffle/client/impl/ShuffleWriteClientImpl.java
@@ -134,17 +134,17 @@ private boolean sendShuffleDataAsync(
               appId, retryMax, retryIntervalMax, shuffleIdToBlocks);
           long s = System.currentTimeMillis();
           RssSendShuffleDataResponse response = getShuffleServerClient(ssi).sendShuffleData(request);
-          LOG.info("ShuffleWriteClientImpl sendShuffleData cost:" + (System.currentTimeMillis() - s) + "(ms)");
+
+          String msgPrefix = String.format("ShuffleWriteClientImpl sendShuffleData with %s blocks to %s cost: %s(ms)",
+              serverToBlockIds.get(ssi).size(), ssi.getId(), System.currentTimeMillis() - s);
 
           if (response.getStatusCode() == ResponseStatusCode.SUCCESS) {
             // mark a replica of block that has been sent
             serverToBlockIds.get(ssi).forEach(block -> blockIdsTracker.get(block).incrementAndGet());
-            LOG.info("Send: " + serverToBlockIds.get(ssi).size()
-                + " blocks to [" + ssi.getId() + "] successfully");
+            LOG.info("{} successfully.", msgPrefix);
           } else {
             isAllServersSuccess.set(false);
-            LOG.warn("Send: " + serverToBlockIds.get(ssi).size() + " blocks to [" + ssi.getId()
-                + "] failed with statusCode[" + response.getStatusCode() + "], ");
+            LOG.warn("{}, it failed wth statusCode[{}]", msgPrefix, response.getStatusCode());
           }
         } catch (Exception e) {
           isAllServersSuccess.set(false);

diff --git a/...nal-client/src/main/java/org/apache/uniffle/client/impl/grpc/ShuffleServerGrpcClient.java b/...nal-client/src/main/java/org/apache/uniffle/client/impl/grpc/ShuffleServerGrpcClient.java
@@ -163,6 +163,7 @@ private AppHeartBeatResponse doSendHeartBeat(String appId, long timeout) {
 
   public long requirePreAllocation(int requireSize, int retryMax, long retryIntervalMax) {
     RequireBufferRequest rpcRequest = RequireBufferRequest.newBuilder().setRequireSize(requireSize).build();
+    long start = System.currentTimeMillis();
     RequireBufferResponse rpcResponse = blockingStub.withDeadlineAfter(
         RPC_TIMEOUT_DEFAULT_MS, TimeUnit.MILLISECONDS).requireBuffer(rpcRequest);
     int retry = 0;
@@ -174,21 +175,24 @@ public long requirePreAllocation(int requireSize, int retryMax, long retryInterv
           + retry + "] again");
       if (retry >= retryMax) {
         LOG.warn("ShuffleServer " + host + ":" + port + " is full and can't send shuffle"
-            + " data successfully after retry " + retryMax + " times");
+            + " data successfully after retry " + retryMax + " times, cost: {}(ms)",
+            System.currentTimeMillis() - start);
         return result;
       }
       try {
         long backoffTime =
             Math.min(retryIntervalMax, backOffBase * (1 << Math.min(retry, 16)) + random.nextInt(backOffBase));
         Thread.sleep(backoffTime);
       } catch (Exception e) {
-        LOG.warn("Exception happened when require pre allocation", e);
+        LOG.warn("Exception happened when require pre allocation from " + host + ":" + port, e);
       }
       rpcResponse = blockingStub.withDeadlineAfter(
           RPC_TIMEOUT_DEFAULT_MS, TimeUnit.MILLISECONDS).requireBuffer(rpcRequest);
       retry++;
     }
     if (rpcResponse.getStatus() == StatusCode.SUCCESS) {
+      LOG.info("Require preAllocated size of {} from {}:{}, cost: {}(ms)",
+          requireSize, host, port, System.currentTimeMillis() - start);
       result = rpcResponse.getRequireBufferId();
     }
     return result;