MAPREDUCE-2250. Fix logging in raid code. (Ramkumar Vadali via schen)



git-svn-id: https://svn.apache.org/repos/asf/hadoop/mapreduce/trunk@1063053 13f79535-47bb-0310-9956-ffa450edef68
diff --git a/CHANGES.txt b/CHANGES.txt
index 305a6e5..bfad2b2 100644
--- a/CHANGES.txt
+++ b/CHANGES.txt
@@ -228,6 +228,8 @@
 
     MAPREDUCE-2180. Add coverage of fair scheduler servlet to system test (todd)
 
+    MAPREDUCE-2250. Fix logging in raid code. (Ramkumar Vadali via schen)
+
   OPTIMIZATIONS
 
     MAPREDUCE-1354. Enhancements to JobTracker for better performance and
diff --git a/src/contrib/raid/src/java/org/apache/hadoop/raid/ConfigManager.java b/src/contrib/raid/src/java/org/apache/hadoop/raid/ConfigManager.java
index 6ae6044..0ae288d 100644
--- a/src/contrib/raid/src/java/org/apache/hadoop/raid/ConfigManager.java
+++ b/src/contrib/raid/src/java/org/apache/hadoop/raid/ConfigManager.java
@@ -303,7 +303,7 @@
                 curr.setProperty(pname,pvalue);
               }
             } else {
-              LOG.info("Found bad property " + propertyName +
+              LOG.warn("Found bad property " + propertyName +
                        " for srcPath" + srcPathPrefix +
                        " policy name " + policyName +
                        ". Ignoring."); 
diff --git a/src/contrib/raid/src/java/org/apache/hadoop/raid/Decoder.java b/src/contrib/raid/src/java/org/apache/hadoop/raid/Decoder.java
index bdb062a..c38885c 100644
--- a/src/contrib/raid/src/java/org/apache/hadoop/raid/Decoder.java
+++ b/src/contrib/raid/src/java/org/apache/hadoop/raid/Decoder.java
@@ -135,10 +135,10 @@
           LOG.info("Copied till " + out.getPos() + " from " + srcFile);
           continue;
         } catch (BlockMissingException e) {
-          LOG.info("Encountered BME at " + srcFile + ":" + offset);
+          LOG.warn("Encountered BME at " + srcFile + ":" + offset);
           bytesAlreadyCopied = out.getPos() - offset;
         } catch (ChecksumException e) {
-          LOG.info("Encountered CE at " + srcFile + ":" + offset);
+          LOG.warn("Encountered CE at " + srcFile + ":" + offset);
           bytesAlreadyCopied = out.getPos() - offset;
         }
       }
@@ -155,7 +155,7 @@
       fs.setTimes(decodedFile, srcStat.getModificationTime(),
                   srcStat.getAccessTime());
     } catch (Exception exc) {
-      LOG.info("Didn't manage to copy meta information because of " + exc +
+      LOG.warn("Didn't manage to copy meta information because of " + exc +
                " Ignoring...");
     }
 
diff --git a/src/contrib/raid/src/java/org/apache/hadoop/raid/DistBlockFixer.java b/src/contrib/raid/src/java/org/apache/hadoop/raid/DistBlockFixer.java
index 8a2ab7e..232165e 100644
--- a/src/contrib/raid/src/java/org/apache/hadoop/raid/DistBlockFixer.java
+++ b/src/contrib/raid/src/java/org/apache/hadoop/raid/DistBlockFixer.java
@@ -224,7 +224,7 @@
    */
   private void failJob(Job job) throws IOException {
     // assume no files have been fixed
-    LOG.info("job " + job.getJobID() + "(" + job.getJobName() +
+    LOG.error("DistBlockFixer job " + job.getJobID() + "(" + job.getJobName() +
       ") finished (failed)");
     for (CorruptFileInfo fileInfo: jobIndex.get(job)) {
       fileInfo.fail();
@@ -237,7 +237,7 @@
    */ 
   private void succeedJob(Job job, long filesSucceeded, long filesFailed)
     throws IOException {
-    LOG.info("job " + job.getJobID() + "(" + job.getJobName() +
+    LOG.info("DistBlockFixer job " + job.getJobID() + "(" + job.getJobName() +
       ") finished (succeeded)");
 
     if (filesFailed == 0) {
@@ -381,6 +381,9 @@
     SequenceFileOutputFormat.setOutputPath(job, outDir);
 
     job.submit();
+    LOG.info("DistBlockFixer job " + job.getJobID() + "(" + job.getJobName() +
+          ") started");
+
     // submit the job before inserting it into the index
     // this way, if submit fails, we won't have added anything to the index
     insertJob(job, filesInJob);
@@ -511,7 +514,7 @@
         LOG.error("trying to remove file not in file index: " +
                   file.toString());
       } else {
-        LOG.info("fixing " + file.toString() + " failed");
+        LOG.error("fixing " + file.toString() + " failed");
       }
       pendingFiles--;
     }
diff --git a/src/contrib/raid/src/java/org/apache/hadoop/raid/DistRaid.java b/src/contrib/raid/src/java/org/apache/hadoop/raid/DistRaid.java
index 9460882..81a3198 100644
--- a/src/contrib/raid/src/java/org/apache/hadoop/raid/DistRaid.java
+++ b/src/contrib/raid/src/java/org/apache/hadoop/raid/DistRaid.java
@@ -188,7 +188,7 @@
         String s = "FAIL: " + policy + ", " + key + " "
             + StringUtils.stringifyException(e);
         context.write(new Text(key), new Text(s));
-        LOG.info(s);
+        LOG.error(s);
       } finally {
         context.setStatus(getCountString());
       }
@@ -289,7 +289,7 @@
          if (runningJob.isSuccessful()) {
            LOG.info("Job Complete(Succeeded): " + jobID);
          } else {
-           LOG.info("Job Complete(Failed): " + jobID);
+           LOG.error("Job Complete(Failed): " + jobID);
          }
          raidPolicyPathPairList.clear();
          return true;
diff --git a/src/contrib/raid/src/java/org/apache/hadoop/raid/DistRaidNode.java b/src/contrib/raid/src/java/org/apache/hadoop/raid/DistRaidNode.java
index 7732869..d2219ae 100644
--- a/src/contrib/raid/src/java/org/apache/hadoop/raid/DistRaidNode.java
+++ b/src/contrib/raid/src/java/org/apache/hadoop/raid/DistRaidNode.java
@@ -49,8 +49,6 @@
     this.jobMonitor = new JobMonitor(conf);
     this.jobMonitorThread = new Daemon(this.jobMonitor);
     this.jobMonitorThread.start();
-    
-    LOG.info("created");
   }
 
   /**
@@ -105,4 +103,4 @@
   }
 
 
-}
\ No newline at end of file
+}
diff --git a/src/contrib/raid/src/java/org/apache/hadoop/raid/LocalRaidNode.java b/src/contrib/raid/src/java/org/apache/hadoop/raid/LocalRaidNode.java
index fb75fbf..5d2444d 100644
--- a/src/contrib/raid/src/java/org/apache/hadoop/raid/LocalRaidNode.java
+++ b/src/contrib/raid/src/java/org/apache/hadoop/raid/LocalRaidNode.java
@@ -40,8 +40,6 @@
 
   public LocalRaidNode(Configuration conf) throws IOException {
     super(conf);
-
-    LOG.info("created");
   }
 
   /**
@@ -59,4 +57,4 @@
   int getRunningJobsForPolicy(String policyName) {
     return 0;
   }
-}
\ No newline at end of file
+}
diff --git a/src/contrib/raid/src/java/org/apache/hadoop/raid/RaidNode.java b/src/contrib/raid/src/java/org/apache/hadoop/raid/RaidNode.java
index ded2091..9254f4c 100644
--- a/src/contrib/raid/src/java/org/apache/hadoop/raid/RaidNode.java
+++ b/src/contrib/raid/src/java/org/apache/hadoop/raid/RaidNode.java
@@ -522,7 +522,7 @@
           try {
             filteredPaths = selectFiles(info, allPolicies);
           } catch (Exception e) {
-            LOG.info("Exception while invoking filter on policy " + info.getName() +
+            LOG.error("Exception while invoking filter on policy " + info.getName() +
                      " srcPath " + info.getSrcPath() + 
                      " exception " + StringUtils.stringifyException(e));
             continue;
@@ -539,7 +539,7 @@
           try {
             raidFiles(info, filteredPaths);
           } catch (Exception e) {
-            LOG.info("Exception while invoking action on policy " + info.getName() +
+            LOG.error("Exception while invoking action on policy " + info.getName() +
                      " srcPath " + info.getSrcPath() + 
                      " exception " + StringUtils.stringifyException(e));
             continue;
@@ -769,7 +769,7 @@
     // reduce the replication factor of the source file
     if (!doSimulate) {
       if (srcFs.setReplication(p, (short)targetRepl) == false) {
-        LOG.info("Error in reducing relication factor of file " + p + " to " + targetRepl);
+        LOG.error("Error in reducing relication factor of file " + p + " to " + targetRepl);
         statistics.remainingSize += diskSpace;  // no change in disk space usage
         return;
       }
@@ -1048,7 +1048,7 @@
             LOG.info("Purging " + destStr + " at usage " + harUsedPercent);
             boolean done = destFs.delete(destPath, true);
             if (!done) {
-              LOG.error("Could not purge " + destPath);
+              LOG.error("Unable to purge directory " + destPath);
             }
           }
         } catch (IOException e) {
@@ -1075,7 +1075,7 @@
             LOG.info("Purged directory " + destPath );
           }
           else {
-            LOG.info("Unable to purge directory " + destPath);
+            LOG.error("Unable to purge directory " + destPath);
           }
         }
         if (files != null) {
@@ -1128,7 +1128,7 @@
         if (done) {
           LOG.info("Purged file " + destPath );
         } else {
-          LOG.info("Unable to purge file " + destPath );
+          LOG.error("Unable to purge file " + destPath );
         }
       }
     } 
@@ -1339,7 +1339,7 @@
       ret = ToolRunner.run(har, args);
       if (ret == 0 && !destFs.rename(new Path(tmpHarPath+"/"+harFileSrc), 
                                      new Path(qualifiedPath, harFileDst))) {
-        LOG.info("HAR rename didn't succeed from " + tmpHarPath+"/"+harFileSrc +
+        LOG.error("HAR rename didn't succeed from " + tmpHarPath+"/"+harFileSrc +
             " to " + qualifiedPath + "/" + harFileDst);
         ret = -2;
       }
diff --git a/src/contrib/raid/src/java/org/apache/hadoop/raid/RaidShell.java b/src/contrib/raid/src/java/org/apache/hadoop/raid/RaidShell.java
index eadcb1f..479043c 100644
--- a/src/contrib/raid/src/java/org/apache/hadoop/raid/RaidShell.java
+++ b/src/contrib/raid/src/java/org/apache/hadoop/raid/RaidShell.java
@@ -107,7 +107,7 @@
   private static RaidProtocol createRPCRaidnode(InetSocketAddress raidNodeAddr,
       Configuration conf, UserGroupInformation ugi)
     throws IOException {
-    LOG.info("RaidShell connecting to " + raidNodeAddr);
+    LOG.debug("RaidShell connecting to " + raidNodeAddr);
     return (RaidProtocol)RPC.getProxy(RaidProtocol.class,
         RaidProtocol.versionID, raidNodeAddr, ugi, conf,
         NetUtils.getSocketFactory(conf, RaidProtocol.class));
@@ -296,9 +296,9 @@
     for (int i = startindex; i < argv.length; i = i + 2) {
       String path = argv[i];
       long corruptOffset = Long.parseLong(argv[i+1]);
-      LOG.info("RaidShell recoverFile for " + path + " corruptOffset " + corruptOffset);
+      LOG.debug("RaidShell recoverFile for " + path + " corruptOffset " + corruptOffset);
       paths[j] = new Path(raidnode.recoverFile(path, corruptOffset));
-      LOG.info("Raidshell created recovery file " + paths[j]);
+      LOG.debug("Raidshell created recovery file " + paths[j]);
       j++;
     }
     return paths;
@@ -315,7 +315,7 @@
 
   public void recoverBlocks(String[] args, int startIndex)
     throws IOException {
-    LOG.info("Recovering blocks for " + (args.length - startIndex) + " files");
+    LOG.debug("Recovering blocks for " + (args.length - startIndex) + " files");
     BlockFixer.BlockFixerHelper fixer = new BlockFixer.BlockFixerHelper(conf);
     for (int i = startIndex; i < args.length; i++) {
       String path = args[i];
@@ -361,11 +361,11 @@
           corruptBlocksPerStripe.put(stripe, corruptBlocksPerStripe.
                                      get(stripe) + 1);
         }
-        LOG.info("file " + filePath.toString() + " corrupt in block " +
+        LOG.debug("file " + filePath.toString() + " corrupt in block " +
                  blockNo + "/" + fileLengthInBlocks + ", stripe " + stripe +
                  "/" + fileStripes);
       } else {
-        LOG.info("file " + filePath.toString() + " OK in block " + blockNo +
+        LOG.debug("file " + filePath.toString() + " OK in block " + blockNo +
                  "/" + fileLengthInBlocks + ", stripe " + stripe + "/" +
                  fileStripes);
       }
@@ -489,7 +489,7 @@
                               parityBlockSize);
       }
     } else if (parityFS instanceof HarFileSystem) {
-      LOG.info("HAR FS found");
+      LOG.debug("HAR FS found");
     } else {
       LOG.warn("parity file system is not of a supported type");
     }
@@ -527,7 +527,7 @@
                               "multiple of parity block size");
       }
       int blocksInContainer = (int) (cb.getLength() / blockSize);
-      LOG.info("found container with offset " + cb.getOffset() +
+      LOG.debug("found container with offset " + cb.getOffset() +
                ", length " + cb.getLength());
 
       for (long offset = cb.getOffset();
@@ -550,7 +550,7 @@
 
         if (cb.isCorrupt() ||
             (cb.getNames().length == 0 && cb.getLength() > 0)) {
-          LOG.info("parity file for " + filePath.toString() +
+          LOG.debug("parity file for " + filePath.toString() +
                    " corrupt in block " + block +
                    ", stripe " + stripe + "/" + fileStripes);
 
@@ -562,7 +562,7 @@
                                        1);
           }
         } else {
-          LOG.info("parity file for " + filePath.toString() +
+          LOG.debug("parity file for " + filePath.toString() +
                    " OK in block " + block +
                    ", stripe " + stripe + "/" + fileStripes);
         }
@@ -606,7 +606,7 @@
     if (!rsPrefix.endsWith("/")) {
       rsPrefix = rsPrefix + "/";
     }
-    LOG.info("prefixes: " + xorPrefix + ", " + rsPrefix);
+    LOG.debug("prefixes: " + xorPrefix + ", " + rsPrefix);
 
     // get a list of corrupted files (not considering parity blocks just yet)
     // from the name node
diff --git a/src/contrib/raid/src/test/org/apache/hadoop/hdfs/server/namenode/TestBlockPlacementPolicyRaid.java b/src/contrib/raid/src/test/org/apache/hadoop/hdfs/server/namenode/TestBlockPlacementPolicyRaid.java
index 88a507d..562d540 100644
--- a/src/contrib/raid/src/test/org/apache/hadoop/hdfs/server/namenode/TestBlockPlacementPolicyRaid.java
+++ b/src/contrib/raid/src/test/org/apache/hadoop/hdfs/server/namenode/TestBlockPlacementPolicyRaid.java
@@ -117,8 +117,8 @@
       FileStatus parityStat = fs.getFileStatus(new Path(parity));
       BlockLocation[] parityLoc =
           fs.getFileBlockLocations(parityStat, 0, parityStat.getLen());
-      int stripeLen = RaidNode.getStripeLength(conf);
-      for (int i = 0; i < numBlocks / stripeLen; i++) {
+      int parityLen = RaidNode.rsParityLength(conf);
+      for (int i = 0; i < numBlocks / parityLen; i++) {
         Set<String> locations = new HashSet<String>();
         for (int j = 0; j < srcLoc.length; j++) {
           String [] names = srcLoc[j].getNames();
@@ -127,8 +127,8 @@
             locations.add(names[k]);
           }
         }
-        for (int j = 0 ; j < stripeLen; j++) {
-          String[] names = parityLoc[j + i * stripeLen].getNames();
+        for (int j = 0 ; j < parityLen; j++) {
+          String[] names = parityLoc[j + i * parityLen].getNames();
           for (int k = 0; k < names.length; k++) {
             LOG.info("Parity block location: " + names[k]);
             Assert.assertTrue(locations.add(names[k]));