HDFS-7357. FSNamesystem.checkFileProgress should log file path. Contributed by Tsz Wo Nicholas Sze.

hadoop-hdfs-project/hadoop-hdfs/CHANGES.txt

@@ -338,6 +338,9 @@ Release 2.7.0 - UNRELEASED
 
     HDFS-7333. Improve logging in Storage.tryLock(). (shv)
 
+    HDFS-7357. FSNamesystem.checkFileProgress should log file path.
+    (Tsz Wo Nicholas Sze via wheat9)
+
   OPTIMIZATIONS
 
   BUG FIXES

hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/blockmanagement/BlockInfoUnderConstruction.java

@@ -141,7 +141,7 @@ public String toString() {
     
     @Override
     public void appendStringTo(StringBuilder sb) {
-      sb.append("ReplicaUnderConstruction[")
+      sb.append("ReplicaUC[")
         .append(expectedLocation)
         .append("|")
         .append(state)
@@ -370,7 +370,7 @@ public void appendStringTo(StringBuilder sb) {
   }
 
   private void appendUCParts(StringBuilder sb) {
-    sb.append("{blockUCState=").append(blockUCState)
+    sb.append("{UCState=").append(blockUCState)
       .append(", primaryNodeIndex=").append(primaryNodeIndex)
       .append(", replicas=[");
     if (replicas != null) {

hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/EditLogFileOutputStream.java

@@ -161,7 +161,7 @@ public void close() throws IOException {
       fp.close();
       fp = null;
     } finally {
-      IOUtils.cleanup(FSNamesystem.LOG, fc, fp);
+      IOUtils.cleanup(LOG, fc, fp);
       doubleBuf = null;
       fc = null;
       fp = null;
@@ -233,8 +233,8 @@ private void preallocate() throws IOException {
       size += fillCapacity;
       total += fillCapacity;
     }
-    if(FSNamesystem.LOG.isDebugEnabled()) {
-      FSNamesystem.LOG.debug("Preallocated " + total + " bytes at the end of " +
+    if(LOG.isDebugEnabled()) {
+      LOG.debug("Preallocated " + total + " bytes at the end of " +
       		"the edit log (offset " + oldSize + ")");
     }
   }

hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSEditLogLoader.java

@@ -329,8 +329,8 @@ private long applyEditLogOp(FSEditLogOp op, FSDirectory fsDir,
       AddCloseOp addCloseOp = (AddCloseOp)op;
       final String path =
           renameReservedPathsOnUpgrade(addCloseOp.path, logVersion);
-      if (FSNamesystem.LOG.isDebugEnabled()) {
-        FSNamesystem.LOG.debug(op.opCode + ": " + path +
+      if (LOG.isDebugEnabled()) {
+        LOG.debug(op.opCode + ": " + path +
             " numblocks : " + addCloseOp.blocks.length +
             " clientHolder " + addCloseOp.clientName +
             " clientMachine " + addCloseOp.clientMachine);

hadoop-hdfs-project/hadoop-hdfs/src/main/java/org/apache/hadoop/hdfs/server/namenode/FSNamesystem.java

@@ -3151,7 +3151,7 @@ LocatedBlock getAdditionalBlock(String src, long fileId, String clientName,
     String clientMachine = null;
 
     if(NameNode.stateChangeLog.isDebugEnabled()) {
-      NameNode.stateChangeLog.debug("BLOCK* NameSystem.getAdditionalBlock: "
+      NameNode.stateChangeLog.debug("BLOCK* getAdditionalBlock: "
           + src + " inodeId " +  fileId  + " for " + clientName);
     }
 
@@ -3374,7 +3374,7 @@ FileState analyzeFileState(String src,
     }
 
     // Check if the penultimate block is minimally replicated
-    if (!checkFileProgress(pendingFile, false)) {
+    if (!checkFileProgress(src, pendingFile, false)) {
       throw new NotReplicatedYetException("Not replicated yet: " + src);
     }
     return new FileState(pendingFile, src);
@@ -3622,14 +3622,14 @@ private boolean completeFileInternal(String src,
     }
     // Check the state of the penultimate block. It should be completed
     // before attempting to complete the last one.
-    if (!checkFileProgress(pendingFile, false)) {
+    if (!checkFileProgress(src, pendingFile, false)) {
       return false;
     }
 
     // commit the last block and complete it if it has minimum replicas
     commitOrCompleteLastBlock(pendingFile, last);
 
-    if (!checkFileProgress(pendingFile, true)) {
+    if (!checkFileProgress(src, pendingFile, true)) {
       return false;
     }
 
@@ -3653,8 +3653,7 @@ BlockInfo saveAllocatedBlock(String src, INodesInPath inodesInPath,
           throws IOException {
     assert hasWriteLock();
     BlockInfo b = dir.addBlock(src, inodesInPath, newBlock, targets);
-    NameNode.stateChangeLog.info("BLOCK* allocateBlock: " + src + ". "
-        + getBlockPoolId() + " " + b);
+    NameNode.stateChangeLog.info("BLOCK* allocate " + b + " for " + src);
     DatanodeStorageInfo.incrementBlocksScheduled(targets);
     return b;
   }
@@ -3675,30 +3674,21 @@ Block createNewBlock() throws IOException {
    * replicated.  If not, return false. If checkall is true, then check
    * all blocks, otherwise check only penultimate block.
    */
-  boolean checkFileProgress(INodeFile v, boolean checkall) {
+  private boolean checkFileProgress(String src, INodeFile v, boolean checkall) {
     readLock();
     try {
       if (checkall) {
-        //
         // check all blocks of the file.
-        //
         for (BlockInfo block: v.getBlocks()) {
-          if (!block.isComplete()) {
-            LOG.info("BLOCK* checkFileProgress: " + block
-                + " has not reached minimal replication "
-                + blockManager.minReplication);
+          if (!isCompleteBlock(src, block, blockManager.minReplication)) {
             return false;
           }
         }
       } else {
-        //
         // check the penultimate block of this file
-        //
         BlockInfo b = v.getPenultimateBlock();
-        if (b != null && !b.isComplete()) {
-          LOG.warn("BLOCK* checkFileProgress: " + b
-              + " has not reached minimal replication "
-              + blockManager.minReplication);
+        if (b != null
+            && !isCompleteBlock(src, b, blockManager.minReplication)) {
           return false;
         }
       }
@@ -3708,6 +3698,19 @@ boolean checkFileProgress(INodeFile v, boolean checkall) {
     }
   }
 
+  private static boolean isCompleteBlock(String src, BlockInfo b, int minRepl) {
+    if (!b.isComplete()) {
+      final BlockInfoUnderConstruction uc = (BlockInfoUnderConstruction)b;
+      final int numNodes = b.numNodes();
+      LOG.info("BLOCK* " + b + " is not COMPLETE (ucState = "
+          + uc.getBlockUCState() + ", replication# = " + numNodes
+          + (numNodes < minRepl? " < ": " >= ")
+          + " minimum = " + minRepl + ") in file " + src);
+      return false;
+    }
+    return true;
+  }
+
   ////////////////////////////////////////////////////////////////
   // Here's how to handle block-copy failure during client write:
   // -- As usual, the client's write should result in a streaming
@@ -5152,9 +5155,9 @@ public void run () {
           if(!nameNodeHasResourcesAvailable()) {
             String lowResourcesMsg = "NameNode low on available disk space. ";
             if (!isInSafeMode()) {
-              FSNamesystem.LOG.warn(lowResourcesMsg + "Entering safe mode.");
+              LOG.warn(lowResourcesMsg + "Entering safe mode.");
             } else {
-              FSNamesystem.LOG.warn(lowResourcesMsg + "Already in safe mode.");
+              LOG.warn(lowResourcesMsg + "Already in safe mode.");
             }
             enterSafeMode(true);
           }
@@ -7014,11 +7017,11 @@ void updatePipeline(String clientName, ExtendedBlock oldBlock,
     if (cacheEntry != null && cacheEntry.isSuccess()) {
       return; // Return previous response
     }
-    LOG.info("updatePipeline(block=" + oldBlock
-             + ", newGenerationStamp=" + newBlock.getGenerationStamp()
+    LOG.info("updatePipeline(" + oldBlock.getLocalBlock()
+             + ", newGS=" + newBlock.getGenerationStamp()
              + ", newLength=" + newBlock.getNumBytes()
              + ", newNodes=" + Arrays.asList(newNodes)
-             + ", clientName=" + clientName
+             + ", client=" + clientName
              + ")");
     waitForLoadingFSImage();
     writeLock();
@@ -7036,7 +7039,8 @@ void updatePipeline(String clientName, ExtendedBlock oldBlock,
       RetryCache.setState(cacheEntry, success);
     }
     getEditLog().logSync();
-    LOG.info("updatePipeline(" + oldBlock + ") successfully to " + newBlock);
+    LOG.info("updatePipeline(" + oldBlock.getLocalBlock() + " => "
+        + newBlock.getLocalBlock() + ") success");
   }
 
   /**