HBASE-7666 More logging improvements in online snapshots code

git-svn-id: https://svn.apache.org/repos/asf/hbase/branches/hbase-7290@1445863 13f79535-47bb-0310-9956-ffa450edef68

hbase-server/src/main/java/org/apache/hadoop/hbase/procedure/Procedure.java

@@ -290,7 +290,7 @@ public class Procedure implements Callable<Void>, ForeignExceptionListener {
           acquiredBarrierLatch.countDown();
         }
       }
-      LOG.debug("Waiting on: " + acquiredBarrierLatch + " remaining members to aqcuire global barrier");
+      LOG.debug("Waiting on: " + acquiredBarrierLatch + " remaining members to acquire global barrier");
     } else {
       LOG.warn("Member " + member + " joined barrier, but we weren't waiting on it to join." +
           " Continuting on.");

hbase-server/src/main/java/org/apache/hadoop/hbase/procedure/ProcedureMember.java

@@ -217,6 +217,7 @@ public class ProcedureMember implements Closeable {
    * @param ee exception information about the abort
    */
   public void receiveAbortProcedure(String procName, ForeignException ee) {
+    LOG.debug("Request received to abort procedure " + procName, ee);
     // if we know about the procedure, notify it
     Subprocedure sub = subprocs.get(procName);
     if (sub == null) {
@@ -224,7 +225,7 @@ public class ProcedureMember implements Closeable {
           ", ignoring it.", ee);
       return; // Procedure has already completed
     }
-    LOG.error("Remote procedure failure, not propagating error:" + ee);
+    LOG.error("Propagating foreign exception to subprocedure " + sub.getName(), ee);
     sub.monitor.receive(ee);
   }
 }

hbase-server/src/main/java/org/apache/hadoop/hbase/procedure/Subprocedure.java

@@ -103,7 +103,7 @@ abstract public class Subprocedure implements Callable<Void> {
       public void receive(ForeignException ee) {
         // if this is a notification from a remote source, just log
         if (ee.isRemote()) {
-          LOG.debug("Can't reach controller, not propagating error", ee);
+          LOG.debug("Was remote foreign exception, not redispatching error", ee);
           return;
         }
 
@@ -194,14 +194,14 @@ abstract public class Subprocedure implements Callable<Void> {
             " Likely due to pool shutdown.";
         Thread.currentThread().interrupt();
       } else if (e instanceof ForeignException) {
-        msg = "Subprocedure '" + barrierName + "' aborting due to external exception!";
+        msg = "Subprocedure '" + barrierName + "' aborting due to a ForeignException!";
       } else {
         msg = "Subprocedure '" + barrierName + "' failed!";
       }
       LOG.error(msg , e);
       cancel(msg, e);
 
-      LOG.debug("Subprocedure '" + barrierName + "' Running cleanup.");
+      LOG.debug("Subprocedure '" + barrierName + "' running cleanup.");
       cleanup(e);
     } finally {
       releasedLocalBarrier.countDown();

hbase-server/src/main/java/org/apache/hadoop/hbase/procedure/ZKProcedureMemberRpcs.java

@@ -104,12 +104,11 @@ public class ZKProcedureMemberRpcs implements ProcedureMemberRpcs {
 
       @Override
       public void nodeChildrenChanged(String path) {
-        LOG.info("Received children changed event:" + path);
         if (path.equals(this.acquiredZnode)) {
-          LOG.info("Received start event.");
+          LOG.info("Received procedure start children changed event: " + path);
           waitForNewProcedures();
         } else if (path.equals(this.abortZnode)) {
-          LOG.info("Received abort event.");
+          LOG.info("Received procedure abort children changed event: " + path);
           watchForAbortedProcedures();
         }
       }
@@ -303,6 +302,7 @@ public class ZKProcedureMemberRpcs implements ProcedureMemberRpcs {
    * @param abortZNode full znode path to the failed procedure information
    */
   protected void abort(String abortZNode) {
+    LOG.debug("Aborting procedure member for znode " + abortZNode);
     String opName = ZKUtil.getNodeName(abortZNode);
     try {
       byte[] data = ZKUtil.getData(zkController.getWatcher(), abortZNode);

hbase-server/src/main/java/org/apache/hadoop/hbase/procedure/ZKProcedureUtil.java

@@ -264,6 +264,8 @@ public abstract class ZKProcedureUtil
 
   public void clearChildZNodes() throws KeeperException {
     // TODO This is potentially racy since not atomic. update when we support zk that has multi
+    LOG.info("Clearing all procedure znodes: " + acquiredZnode + " " + reachedZnode + " "
+        + abortZnode);
 
     // If the coordinator was shutdown mid-procedure, then we are going to lose
     // an procedure that was previously started by cleaning out all the previous state. Its much
@@ -275,7 +277,8 @@ public abstract class ZKProcedureUtil
 
   public void clearZNodes(String procedureName) throws KeeperException {
     // TODO This is potentially racy since not atomic. update when we support zk that has multi
-
+    LOG.info("Clearing all znodes for procedure " + procedureName + "including nodes "
+        + acquiredZnode + " " + reachedZnode + " " + abortZnode);
     ZKUtil.deleteNodeRecursively(watcher, getAcquiredBarrierNode(procedureName));
     ZKUtil.deleteNodeRecursively(watcher, getReachedBarrierNode(procedureName));
     ZKUtil.deleteNodeRecursively(watcher, getAbortZNode(procedureName));