Return-Path: X-Original-To: apmail-hbase-commits-archive@www.apache.org Delivered-To: apmail-hbase-commits-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 7D79617A89 for ; Tue, 19 May 2015 23:14:13 +0000 (UTC) Received: (qmail 99811 invoked by uid 500); 19 May 2015 23:13:58 -0000 Delivered-To: apmail-hbase-commits-archive@hbase.apache.org Received: (qmail 99707 invoked by uid 500); 19 May 2015 23:13:58 -0000 Mailing-List: contact commits-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@hbase.apache.org Delivered-To: mailing list commits@hbase.apache.org Received: (qmail 97427 invoked by uid 99); 19 May 2015 23:13:57 -0000 Received: from git1-us-west.apache.org (HELO git1-us-west.apache.org) (140.211.11.23) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 19 May 2015 23:13:57 +0000 Received: by git1-us-west.apache.org (ASF Mail Server at git1-us-west.apache.org, from userid 33) id 02D5BE41A5; Tue, 19 May 2015 23:13:57 +0000 (UTC) Content-Type: text/plain; charset="us-ascii" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit From: jmhsieh@apache.org To: commits@hbase.apache.org Date: Tue, 19 May 2015 23:14:39 -0000 Message-Id: In-Reply-To: <65ecb2fd79854c10a28305ca46f30d41@git.apache.org> References: <65ecb2fd79854c10a28305ca46f30d41@git.apache.org> X-Mailer: ASF-Git Admin Mailer Subject: [44/50] [abbrv] hbase git commit: HBASE-13675 ProcedureExecutor completion report should be at DEBUG log level HBASE-13675 ProcedureExecutor completion report should be at DEBUG log level Project: http://git-wip-us.apache.org/repos/asf/hbase/repo Commit: http://git-wip-us.apache.org/repos/asf/hbase/commit/901714d7 Tree: http://git-wip-us.apache.org/repos/asf/hbase/tree/901714d7 Diff: http://git-wip-us.apache.org/repos/asf/hbase/diff/901714d7 Branch: refs/heads/hbase-11339 Commit: 901714d75dd6da9c3b7dca3f48046119c6f08905 Parents: bc189d0 Author: Srikanth Srungarapu Authored: Mon May 18 19:51:41 2015 -0700 Committer: Srikanth Srungarapu Committed: Mon May 18 19:51:41 2015 -0700 ---------------------------------------------------------------------- .../hbase/procedure2/ProcedureExecutor.java | 68 +++++++++++++------- 1 file changed, 44 insertions(+), 24 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/hbase/blob/901714d7/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java ---------------------------------------------------------------------- diff --git a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java index 2982058..6e87997 100644 --- a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java +++ b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java @@ -148,7 +148,9 @@ public class ProcedureExecutor { public void periodicExecute(final TEnvironment env) { if (completed.isEmpty()) { - LOG.debug("no completed procedures to cleanup"); + if (LOG.isDebugEnabled()) { + LOG.debug("No completed procedures to cleanup."); + } return; } @@ -164,7 +166,9 @@ public class ProcedureExecutor { // TODO: Select TTL based on Procedure type if ((result.hasClientAckTime() && (now - result.getClientAckTime()) >= evictAckTtl) || (now - result.getLastUpdate()) >= evictTtl) { - LOG.debug("Evict completed procedure " + entry.getKey()); + if (LOG.isDebugEnabled()) { + LOG.debug("Evict completed procedure " + entry.getKey()); + } store.delete(entry.getKey()); it.remove(); } @@ -281,8 +285,10 @@ public class ProcedureExecutor { proc.beforeReplay(getEnvironment()); procedures.put(proc.getProcId(), proc); logMaxProcId = Math.max(logMaxProcId, proc.getProcId()); - LOG.debug("Loading procedure state=" + proc.getState() + - " isFailed=" + proc.hasException() + ": " + proc); + if (LOG.isDebugEnabled()) { + LOG.debug("Loading procedure state=" + proc.getState() + + " isFailed=" + proc.hasException() + ": " + proc); + } if (!proc.hasParent() && !proc.isFinished()) { rollbackStack.put(proc.getProcId(), new RootProcedureState()); } @@ -305,8 +311,10 @@ public class ProcedureExecutor { } if (!proc.hasParent() && proc.isFinished()) { - LOG.debug("The procedure is completed state=" + proc.getState() + - " isFailed=" + proc.hasException() + ": " + proc); + if (LOG.isDebugEnabled()) { + LOG.debug("The procedure is completed state=" + proc.getState() + + " isFailed=" + proc.hasException() + ": " + proc); + } assert !rollbackStack.containsKey(proc.getProcId()); completed.put(proc.getProcId(), newResultFromProcedure(proc)); continue; @@ -514,7 +522,9 @@ public class ProcedureExecutor { // Commit the transaction store.insert(proc, null); - LOG.debug("procedure " + proc + " added to the store"); + if (LOG.isDebugEnabled()) { + LOG.debug("Procedure " + proc + " added to the store."); + } // Create the rollback stack for the procedure RootProcedureState stack = new RootProcedureState(); @@ -564,7 +574,9 @@ public class ProcedureExecutor { ProcedureResult result = completed.get(procId); if (result == null) { assert !procedures.containsKey(procId) : "procId=" + procId + " is still running"; - LOG.debug("Procedure procId=" + procId + " already removed by the cleaner"); + if (LOG.isDebugEnabled()) { + LOG.debug("Procedure procId=" + procId + " already removed by the cleaner."); + } return; } @@ -620,7 +632,7 @@ public class ProcedureExecutor { private void execLoop(Procedure proc) { if (LOG.isTraceEnabled()) { - LOG.trace("trying to start the execution of " + proc); + LOG.trace("Trying to start the execution of " + proc); } Long rootProcId = getRootProcedureId(proc); @@ -673,8 +685,10 @@ public class ProcedureExecutor { if (proc.getProcId() == rootProcId && proc.isSuccess()) { // Finalize the procedure state - LOG.info("Procedure completed in " + - StringUtils.humanTimeDiff(proc.elapsedTime()) + ": " + proc); + if (LOG.isDebugEnabled()) { + LOG.debug("Procedure completed in " + + StringUtils.humanTimeDiff(proc.elapsedTime()) + ": " + proc); + } procedureFinished(proc); break; } @@ -708,7 +722,7 @@ public class ProcedureExecutor { try { ((CompletedProcedureCleaner)proc).periodicExecute(getEnvironment()); } catch (Throwable e) { - LOG.error("ignoring CompletedProcedureCleaner exception: " + e.getMessage(), e); + LOG.error("Ignoring CompletedProcedureCleaner exception: " + e.getMessage(), e); } proc.setStartTime(EnvironmentEdgeManager.currentTime()); waitingTimeout.add(proc); @@ -743,7 +757,7 @@ public class ProcedureExecutor { } List subprocStack = procStack.getSubprocedures(); - assert subprocStack != null : "called rollback with no steps executed rootProc=" + rootProc; + assert subprocStack != null : "Called rollback with no steps executed rootProc=" + rootProc; int stackTail = subprocStack.size(); boolean reuseLock = false; @@ -793,17 +807,21 @@ public class ProcedureExecutor { try { proc.doRollback(getEnvironment()); } catch (IOException e) { - LOG.debug("rollback attempt failed for " + proc, e); + if (LOG.isDebugEnabled()) { + LOG.debug("rollback attempt failed for " + proc, e); + } return false; } catch (Throwable e) { // Catch NullPointerExceptions or similar errors... - LOG.fatal("CODE-BUG: uncatched runtime exception for procedure: " + proc, e); + LOG.fatal("CODE-BUG: Uncatched runtime exception for procedure: " + proc, e); } // allows to kill the executor before something is stored to the wal. // useful to test the procedure recovery. if (testing != null && testing.shouldKillBeforeStoreUpdate()) { - LOG.debug("TESTING: Kill before store update"); + if (LOG.isDebugEnabled()) { + LOG.debug("TESTING: Kill before store update"); + } stop(); return false; } @@ -854,13 +872,13 @@ public class ProcedureExecutor { } } catch (ProcedureYieldException e) { if (LOG.isTraceEnabled()) { - LOG.trace("yield procedure: " + procedure); + LOG.trace("Yield procedure: " + procedure); } runnables.yield(procedure); return; } catch (Throwable e) { // Catch NullPointerExceptions or similar errors... - String msg = "CODE-BUG: uncatched runtime exception for procedure: " + procedure; + String msg = "CODE-BUG: Uncatched runtime exception for procedure: " + procedure; LOG.error(msg, e); procedure.setFailure(new RemoteProcedureException(msg, e)); } @@ -916,7 +934,9 @@ public class ProcedureExecutor { // allows to kill the executor before something is stored to the wal. // useful to test the procedure recovery. if (testing != null && testing.shouldKillBeforeStoreUpdate()) { - LOG.debug("TESTING: Kill before store update"); + if (LOG.isDebugEnabled()) { + LOG.debug("TESTING: Kill before store update"); + } stop(); return; } @@ -924,12 +944,12 @@ public class ProcedureExecutor { // Commit the transaction if (subprocs != null && !procedure.isFailed()) { if (LOG.isTraceEnabled()) { - LOG.trace("store add " + procedure + " children " + Arrays.toString(subprocs)); + LOG.trace("Store add " + procedure + " children " + Arrays.toString(subprocs)); } store.insert(procedure, subprocs); } else { if (LOG.isTraceEnabled()) { - LOG.trace("store update " + procedure); + LOG.trace("Store update " + procedure); } store.update(procedure); } @@ -981,7 +1001,7 @@ public class ProcedureExecutor { try { listener.procedureLoaded(procId); } catch (Throwable e) { - LOG.error("the listener " + listener + " had an error: " + e.getMessage(), e); + LOG.error("The listener " + listener + " had an error: " + e.getMessage(), e); } } } @@ -993,7 +1013,7 @@ public class ProcedureExecutor { try { listener.procedureAdded(procId); } catch (Throwable e) { - LOG.error("the listener " + listener + " had an error: " + e.getMessage(), e); + LOG.error("The listener " + listener + " had an error: " + e.getMessage(), e); } } } @@ -1005,7 +1025,7 @@ public class ProcedureExecutor { try { listener.procedureFinished(procId); } catch (Throwable e) { - LOG.error("the listener " + listener + " had an error: " + e.getMessage(), e); + LOG.error("The listener " + listener + " had an error: " + e.getMessage(), e); } } }