HDFS-8522. Change heavily recorded NN logs from INFO to DEBUG level. Contributed by xyao.

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

@@ -105,6 +105,8 @@ Release 2.7.1 - UNRELEASED
     HDFS-8523. Remove usage information on unsupported operation
     "fsck -showprogress" from branch-2 (J.Andreina via vinayakumarb)
 
+    HDFS-8522. Change heavily recorded NN logs from INFO to DEBUG level. (xyao)
+
 Release 2.7.0 - 2015-04-20
 
   INCOMPATIBLE CHANGES

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

@@ -2008,10 +2008,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
                       long mtime)
       throws IOException, UnresolvedLinkException {
     String src = srcArg;
-    if (NameNode.stateChangeLog.isDebugEnabled()) {
+    NameNode.stateChangeLog.debug(
-      NameNode.stateChangeLog.debug("DIR* NameSystem.truncate: src="
+        "DIR* NameSystem.truncate: src={} newLength={}", src, newLength);
-          + src + " newLength=" + newLength);
-    }
     if (newLength < 0) {
       throw new HadoopIllegalArgumentException(
           "Cannot truncate to a negative file size: " + newLength + ".");
@@ -2161,10 +2159,10 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
       file.setLastBlock(truncatedBlockUC, blockManager.getStorages(oldBlock));
       getBlockManager().addBlockCollection(truncatedBlockUC, file);
 
-      NameNode.stateChangeLog.info("BLOCK* prepareFileForTruncate: "
+      NameNode.stateChangeLog.debug(
-          + "Scheduling copy-on-truncate to new size "
+          "BLOCK* prepareFileForTruncate: Scheduling copy-on-truncate to new" +
-          + truncatedBlockUC.getNumBytes() + " new block " + newBlock
+          " size {}  new block {} old block {}", truncatedBlockUC.getNumBytes(),
-          + " old block " + truncatedBlockUC.getTruncateBlock());
+          newBlock, truncatedBlockUC.getTruncateBlock());
     } else {
       // Use new generation stamp for in-place truncate recovery
       blockManager.convertLastBlockToUnderConstruction(file, lastBlockDelta);
@@ -2177,10 +2175,10 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
       truncatedBlockUC.getTruncateBlock().setGenerationStamp(
           newBlock.getGenerationStamp());
 
-      NameNode.stateChangeLog.debug("BLOCK* prepareFileForTruncate: "
+      NameNode.stateChangeLog.debug(
-          + "Scheduling in-place block truncate to new size "
+          "BLOCK* prepareFileForTruncate: {} Scheduling in-place block " +
-          + truncatedBlockUC.getTruncateBlock().getNumBytes()
+          "truncate to new size {}",
-          + " block=" + truncatedBlockUC);
+          truncatedBlockUC.getTruncateBlock().getNumBytes(), truncatedBlockUC);
     }
     if (shouldRecoverNow) {
       truncatedBlockUC.initializeBlockRecovery(newBlock.getGenerationStamp());
@@ -2597,10 +2595,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
 
       // record file record in log, record new generation stamp
       getEditLog().logOpenFile(src, newNode, overwrite, logRetryEntry);
-      if (NameNode.stateChangeLog.isDebugEnabled()) {
+      NameNode.stateChangeLog.debug("DIR* NameSystem.startFile: added {}" +
-        NameNode.stateChangeLog.debug("DIR* NameSystem.startFile: added " +
+          " inode {} holder {}", src, newNode.getId(), holder);
-            src + " inode " + newNode.getId() + " " + holder);
-      }
       return toRemoveBlocks;
     } catch (IOException ie) {
       NameNode.stateChangeLog.warn("DIR* NameSystem.startFile: " + src + " " +
@@ -2961,11 +2957,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
       String clientMachine, boolean newBlock, boolean logRetryCache)
       throws IOException {
     String src = srcArg;
-    if (NameNode.stateChangeLog.isDebugEnabled()) {
+    NameNode.stateChangeLog.debug(
-      NameNode.stateChangeLog.debug("DIR* NameSystem.appendFile: src=" + src
+        "DIR* NameSystem.appendFile: src={}, holder={}, clientMachine={}",
-          + ", holder=" + holder
+        src, holder, clientMachine);
-          + ", clientMachine=" + clientMachine);
-    }
     boolean skipSync = false;
     if (!supportAppends) {
       throw new UnsupportedOperationException(
@@ -3000,12 +2994,10 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
       }
     }
     if (lb != null) {
-      if (NameNode.stateChangeLog.isDebugEnabled()) {
+      NameNode.stateChangeLog.debug(
-        NameNode.stateChangeLog.debug("DIR* NameSystem.appendFile: file "
+          "DIR* NameSystem.appendFile: file {} for {} at {} block {} block" +
-            +src+" for "+holder+" at "+clientMachine
+          " size {}", src, holder, clientMachine, lb.getBlock(),
-            +" block " + lb.getBlock()
+          lb.getBlock().getNumBytes());
-            +" block size " + lb.getBlock().getNumBytes());
-      }
     }
     logAuditEvent(true, "append", srcArg);
     return new LastBlockWithStatus(lb, stat);
@@ -3065,10 +3057,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
     Node clientNode = null;
     String clientMachine = null;
 
-    if(NameNode.stateChangeLog.isDebugEnabled()) {
+    NameNode.stateChangeLog.debug("BLOCK* getAdditionalBlock: {}  inodeId {}" +
-      NameNode.stateChangeLog.debug("BLOCK* getAdditionalBlock: "
+        " for {}", src, fileId, clientName);
-          + src + " inodeId " +  fileId  + " for " + clientName);
-    }
 
     checkOperation(OperationCategory.READ);
     byte[][] pathComponents = FSDirectory.getPathComponentsForReservedPath(src);
@@ -3274,12 +3264,10 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
           lastBlockInFile.getNumBytes() >= pendingFile.getPreferredBlockSize() &&
           lastBlockInFile.isComplete()) {
         // Case 1
-        if (NameNode.stateChangeLog.isDebugEnabled()) {
+        NameNode.stateChangeLog.debug(
-           NameNode.stateChangeLog.debug(
+            "BLOCK* NameSystem.allocateBlock: handling block allocation" +
-               "BLOCK* NameSystem.allocateBlock: handling block allocation" +
+            " writing to a file with a complete previous block: src={}" +
-               " writing to a file with a complete previous block: src=" +
+            " lastBlock={}", src, lastBlockInFile);
-               src + " lastBlock=" + lastBlockInFile);
-        }
       } else if (Block.matchingIdAndGenStamp(penultimateBlock, previousBlock)) {
         if (lastBlockInFile.getNumBytes() != 0) {
           throw new IOException(
@@ -3384,10 +3372,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
    */
   boolean abandonBlock(ExtendedBlock b, long fileId, String src, String holder)
       throws IOException {
-    if(NameNode.stateChangeLog.isDebugEnabled()) {
+    NameNode.stateChangeLog.debug(
-      NameNode.stateChangeLog.debug("BLOCK* NameSystem.abandonBlock: " + b
+        "BLOCK* NameSystem.abandonBlock: {} of file {}", b, src);
-          + "of file " + src);
-    }
     checkOperation(OperationCategory.WRITE);
     byte[][] pathComponents = FSDirectory.getPathComponentsForReservedPath(src);
     FSPermissionChecker pc = getPermissionChecker();
@@ -3421,10 +3407,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
       if (!removed) {
         return true;
       }
-      if(NameNode.stateChangeLog.isDebugEnabled()) {
+      NameNode.stateChangeLog.debug("BLOCK* NameSystem.abandonBlock: {} is " +
-        NameNode.stateChangeLog.debug("BLOCK* NameSystem.abandonBlock: "
+          "removed from pendingCreates", b);
-                                      + b + " is removed from pendingCreates");
-      }
       persistBlocks(src, file, false);
     } finally {
       writeUnlock();
@@ -3484,10 +3468,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
                        ExtendedBlock last, long fileId)
     throws SafeModeException, UnresolvedLinkException, IOException {
     String src = srcArg;
-    if (NameNode.stateChangeLog.isDebugEnabled()) {
+    NameNode.stateChangeLog.debug("DIR* NameSystem.completeFile: {} for {}",
-      NameNode.stateChangeLog.debug("DIR* NameSystem.completeFile: " +
+        src, holder);
-          src + " for " + holder);
-    }
     checkBlock(last);
     boolean success = false;
     checkOperation(OperationCategory.WRITE);
@@ -4622,11 +4604,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
     assert hasWriteLock();
     Preconditions.checkArgument(file.isUnderConstruction());
     getEditLog().logUpdateBlocks(path, file, logRetryCache);
-    if(NameNode.stateChangeLog.isDebugEnabled()) {
+    NameNode.stateChangeLog.debug("persistBlocks: {} with {} blocks is" +
-      NameNode.stateChangeLog.debug("persistBlocks: " + path
+        " peristed to the file system", path, file.getBlocks().length);
-              + " with " + file.getBlocks().length + " blocks is persisted to" +
-              " the file system");
-    }
   }
 
   /**
@@ -4639,11 +4618,8 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
     waitForLoadingFSImage();
     // file is closed
     getEditLog().logCloseFile(path, file);
-    if (NameNode.stateChangeLog.isDebugEnabled()) {
+    NameNode.stateChangeLog.debug("closeFile: {} with {} blocks is persisted" +
-      NameNode.stateChangeLog.debug("closeFile: "
+        " to the file system", path, file.getBlocks().length);
-              +path+" with "+ file.getBlocks().length
-              +" blocks is persisted to the file system");
-    }
   }
 
   /**
@@ -5094,11 +5070,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
   private void persistNewBlock(String path, INodeFile file) {
     Preconditions.checkArgument(file.isUnderConstruction());
     getEditLog().logAddBlock(path, file);
-    if (NameNode.stateChangeLog.isDebugEnabled()) {
+    NameNode.stateChangeLog.debug("persistNewBlock: {} with new block {}," +
-      NameNode.stateChangeLog.debug("persistNewBlock: "
+        " current total block count is {}", path,
-              + path + " with new block " + file.getLastBlock().toString()
+        file.getLastBlock().toString(), file.getBlocks().length);
-              + ", current total block count is " + file.getBlocks().length);
-    }
   }
 
   /**
@@ -6553,7 +6527,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
       if (cookieTab[0] == null) {
         cookieTab[0] = String.valueOf(getIntCookie(cookieTab[0]));
       }
-      LOG.info("there are no corrupt file blocks.");
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("there are no corrupt file blocks.");
+      }
       return corruptFiles;
     }
 
@@ -6588,7 +6564,9 @@ public class FSNamesystem implements Namesystem, FSNamesystemMBean,
         }
       }
       cookieTab[0] = String.valueOf(skip);
-      LOG.info("list corrupt file blocks returned: " + count);
+      if (LOG.isDebugEnabled()) {
+        LOG.debug("list corrupt file blocks returned: " + count);
+      }
       return corruptFiles;
     } finally {
       readUnlock();