HBASE-20989 Minor, miscellaneous logging fixes

Signed-off-by: Zach York <zyork@amazon.com>
Signed-off-by: Mingliang Liu <liuml07@apache.org>

hbase-client/src/main/java/org/apache/hadoop/hbase/client/AsyncRequestFutureImpl.java

@@ -952,13 +952,13 @@ class AsyncRequestFutureImpl<CResult> implements AsyncRequestFuture {
                            Throwable error, long backOffTime, boolean willRetry, String startTime,
                            int failed, int stopped) {
     StringBuilder sb = new StringBuilder();
-    sb.append("id=").append(asyncProcess.id).append(", table=").append(tableName).append(", ")
-        .append("attempt=").append(numAttempt)
-        .append("/").append(asyncProcess.numTries).append(", ");
+    sb.append("id=").append(asyncProcess.id).append(", table=").append(tableName).
+        append(", attempt=").append(numAttempt).append("/").append(asyncProcess.numTries).
+        append(", ");
 
     if (failureCount > 0 || error != null){
-      sb.append("failed=").append(failureCount).append("ops").append(", last exception=").
-          append(error == null ? "null" : error);
+      sb.append("failureCount=").append(failureCount).append("ops").append(", last exception=").
+          append(error);
     } else {
       sb.append("succeeded");
     }
@@ -967,15 +967,15 @@ class AsyncRequestFutureImpl<CResult> implements AsyncRequestFuture {
 
     if (willRetry) {
       sb.append(", retrying after=").append(backOffTime).append("ms").
-          append(", replay=").append(replaySize).append("ops");
+          append(", operationsToReplay=").append(replaySize);
     } else if (failureCount > 0) {
       if (stopped > 0) {
-        sb.append("; not retrying ").append(stopped).append(" due to success from other replica");
+        sb.append("; NOT retrying, stopped=").append(stopped).
+            append(" because successful operation on other replica");
       }
       if (failed > 0) {
-        sb.append("; not retrying ").append(failed).append(" - final failure");
+        sb.append("; NOT retrying, failed=").append(failed).append(" -- final attempt!");
       }
-
     }
 
     return sb.toString();

hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java

@@ -1500,7 +1500,7 @@ public class ProcedureExecutor<TEnvironment> {
   private void execProcedure(RootProcedureState<TEnvironment> procStack,
       Procedure<TEnvironment> procedure) {
     Preconditions.checkArgument(procedure.getState() == ProcedureState.RUNNABLE,
-      procedure.toString());
+        "NOT RUNNABLE! " + procedure.toString());
 
     // Procedures can suspend themselves. They skip out by throwing a ProcedureSuspendedException.
     // The exception is caught below and then we hurry to the exit without disturbing state. The

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

@@ -188,7 +188,7 @@ public abstract class AbstractStateMachineTableProcedure<TState>
       throw new UnknownRegionException("No RegionState found for " + ri.getEncodedName());
     }
     if (!rs.isOpened()) {
-      throw new DoNotRetryRegionException(ri.getEncodedName() + " is not OPEN");
+      throw new DoNotRetryRegionException(ri.getEncodedName() + " is not OPEN; regionState=" + rs);
     }
     if (ri.isSplitParent()) {
       throw new DoNotRetryRegionException(ri.getEncodedName() +

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

@@ -94,7 +94,7 @@ public class DeleteTableProcedure
           }
 
           // TODO: Move out... in the acquireLock()
-          LOG.debug("Waiting for '" + getTableName() + "' regions in transition");
+          LOG.debug("Waiting for RIT for {}", this);
           regions = env.getAssignmentManager().getRegionStates().getRegionsOfTable(getTableName());
           assert regions != null && !regions.isEmpty() : "unexpected 0 regions";
           ProcedureSyncWait.waitRegionInTransition(env, regions);
@@ -105,29 +105,29 @@ public class DeleteTableProcedure
           setNextState(DeleteTableState.DELETE_TABLE_REMOVE_FROM_META);
           break;
         case DELETE_TABLE_REMOVE_FROM_META:
-          LOG.debug("delete '" + getTableName() + "' regions from META");
+          LOG.debug("Deleting regions from META for {}", this);
           DeleteTableProcedure.deleteFromMeta(env, getTableName(), regions);
           setNextState(DeleteTableState.DELETE_TABLE_CLEAR_FS_LAYOUT);
           break;
         case DELETE_TABLE_CLEAR_FS_LAYOUT:
-          LOG.debug("delete '" + getTableName() + "' from filesystem");
+          LOG.debug("Deleting regions from filesystem for {}", this);
           DeleteTableProcedure.deleteFromFs(env, getTableName(), regions, true);
           setNextState(DeleteTableState.DELETE_TABLE_UPDATE_DESC_CACHE);
           regions = null;
           break;
         case DELETE_TABLE_UPDATE_DESC_CACHE:
-          LOG.debug("delete '" + getTableName() + "' descriptor");
+          LOG.debug("Deleting descriptor for {}", this);
           DeleteTableProcedure.deleteTableDescriptorCache(env, getTableName());
           setNextState(DeleteTableState.DELETE_TABLE_UNASSIGN_REGIONS);
           break;
         case DELETE_TABLE_UNASSIGN_REGIONS:
-          LOG.debug("delete '" + getTableName() + "' assignment state");
+          LOG.debug("Deleting assignment state for {}", this);
           DeleteTableProcedure.deleteAssignmentState(env, getTableName());
           setNextState(DeleteTableState.DELETE_TABLE_POST_OPERATION);
           break;
         case DELETE_TABLE_POST_OPERATION:
           postDelete(env);
-          LOG.debug("delete '" + getTableName() + "' completed");
+          LOG.debug("Finished {}", this);
           return Flow.NO_MORE_STATE;
         default:
           throw new UnsupportedOperationException("unhandled state=" + state);

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

@@ -142,7 +142,7 @@ public class DisableTableProcedure
       if (isRollbackSupported(state)) {
         setFailure("master-disable-table", e);
       } else {
-        LOG.warn("Retriable error trying to disable table={} (in state={})", tableName, state, e);
+        LOG.warn("Retryable error in {}", this, e);
       }
     }
     return Flow.HAS_MORE_STATE;
@@ -256,7 +256,7 @@ public class DisableTableProcedure
       TableStateManager tsm = env.getMasterServices().getTableStateManager();
       TableState ts = tsm.getTableState(tableName);
       if (!ts.isEnabled()) {
-        LOG.info("Not ENABLED tableState=" + ts + "; skipping disable");
+        LOG.info("Not ENABLED skipping {}", this);
         setFailure("master-disable-table", new TableNotEnabledException(ts.toString()));
         canTableBeDisabled = false;
       }
@@ -292,6 +292,7 @@ public class DisableTableProcedure
     env.getMasterServices().getTableStateManager().setTableState(
       tableName,
       TableState.State.DISABLING);
+    LOG.info("Set {} to state={}", tableName, TableState.State.DISABLING);
   }
 
   /**
@@ -306,7 +307,7 @@ public class DisableTableProcedure
     env.getMasterServices().getTableStateManager().setTableState(
       tableName,
       TableState.State.DISABLED);
-    LOG.info("Disabled table, " + tableName + ", is completed.");
+    LOG.info("Set {} to state={}", tableName, TableState.State.DISABLED);
   }
 
   /**

hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/HRegion.java

@@ -1536,7 +1536,7 @@ public class HRegion implements HeapSize, PropagatingConfigurationObserver, Regi
     // the close flag?
     if (!abort && worthPreFlushing() && canFlush) {
       status.setStatus("Pre-flushing region before close");
-      LOG.info("Running close preflush of {}" + this.getRegionInfo().getEncodedName());
+      LOG.info("Running close preflush of {}", this.getRegionInfo().getEncodedName());
       try {
         internalFlushcache(status);
       } catch (IOException ioe) {