BATCH-2412 Add guards around debug statements

In various places in the code base a debug message is constructed
unconditionally. This adds unnecessary overhead in the common case when
debug logging is off.

 - add guards around debug statements in non-test code

Issue: BATCH-2412
This commit is contained in:
Philippe Marschall
2015-08-04 08:46:54 +02:00
committed by Michael Minella
parent 7ec7152c5e
commit 3783345c55
26 changed files with 153 additions and 53 deletions

View File

@@ -233,7 +233,9 @@ public abstract class AbstractApplicationContextFactory implements ApplicationCo
for (BeanPostProcessor beanPostProcessor : new ArrayList<BeanPostProcessor>(aggregatedPostProcessors)) {
for (Class<?> cls : beanPostProcessorExcludeClasses) {
if (cls.isAssignableFrom(beanPostProcessor.getClass())) {
logger.debug("Removing bean post processor: " + beanPostProcessor + " of type " + cls);
if (logger.isDebugEnabled()) {
logger.debug("Removing bean post processor: " + beanPostProcessor + " of type " + cls);
}
aggregatedPostProcessors.remove(beanPostProcessor);
}
}

View File

@@ -129,7 +129,9 @@ public class DefaultJobLoader implements JobLoader, InitializingBean {
if (contexts.containsKey(factory)) {
ConfigurableApplicationContext context = contexts.get(factory);
for (String name : contextToJobNames.get(context)) {
logger.debug("Unregistering job: " + name + " from context: " + context.getDisplayName());
if (logger.isDebugEnabled()) {
logger.debug("Unregistering job: " + name + " from context: " + context.getDisplayName());
}
doUnregister(name);
}
context.close();
@@ -179,11 +181,15 @@ public class DefaultJobLoader implements JobLoader, InitializingBean {
// On reload try to unregister first
if (unregister) {
logger.debug("Unregistering job: " + jobName + " from context: " + context.getDisplayName());
if (logger.isDebugEnabled()) {
logger.debug("Unregistering job: " + jobName + " from context: " + context.getDisplayName());
}
doUnregister(jobName);
}
logger.debug("Registering job: " + jobName + " from context: " + context.getDisplayName());
if (logger.isDebugEnabled()) {
logger.debug("Registering job: " + jobName + " from context: " + context.getDisplayName());
}
doRegister(context, job);
jobsRegistered.add(jobName);
}

View File

@@ -113,7 +113,9 @@ DisposableBean {
@Override
public void destroy() throws Exception {
for (String name : jobNames) {
logger.debug("Unregistering job: " + name);
if (logger.isDebugEnabled()) {
logger.debug("Unregistering job: " + name);
}
jobRegistry.unregister(name);
}
jobNames.clear();
@@ -138,7 +140,9 @@ DisposableBean {
job = groupName==null ? job : new GroupAwareJob(groupName, job);
ReferenceJobFactory jobFactory = new ReferenceJobFactory(job);
String name = jobFactory.getJobName();
logger.debug("Registering job: " + name);
if (logger.isDebugEnabled()) {
logger.debug("Registering job: " + name);
}
jobRegistry.register(jobFactory);
jobNames.add(name);
}

View File

@@ -285,7 +285,9 @@ InitializingBean {
@Override
public final void execute(JobExecution execution) {
logger.debug("Job execution starting: " + execution);
if (logger.isDebugEnabled()) {
logger.debug("Job execution starting: " + execution);
}
JobSynchronizationManager.register(execution);
@@ -302,7 +304,9 @@ InitializingBean {
try {
doExecute(execution);
logger.debug("Job execution complete: " + execution);
if (logger.isDebugEnabled()) {
logger.debug("Job execution complete: " + execution);
}
} catch (RepeatException e) {
throw e.getCause();
}
@@ -312,7 +316,9 @@ InitializingBean {
// with it in the same way as any other interruption.
execution.setStatus(BatchStatus.STOPPED);
execution.setExitStatus(ExitStatus.COMPLETED);
logger.debug("Job execution was stopped: " + execution);
if (logger.isDebugEnabled()) {
logger.debug("Job execution was stopped: " + execution);
}
}

View File

@@ -145,7 +145,9 @@ public class SimpleJob extends AbstractJob {
// Update the job status to be the same as the last step
//
if (stepExecution != null) {
logger.debug("Upgrading JobExecution status: " + stepExecution);
if (logger.isDebugEnabled()) {
logger.debug("Upgrading JobExecution status: " + stepExecution);
}
execution.upgradeStatus(stepExecution.getStatus());
execution.setExitStatus(stepExecution.getExitStatus());
}

View File

@@ -153,7 +153,9 @@ public class SimpleFlow implements Flow, InitializingBean {
FlowExecutionStatus status = FlowExecutionStatus.UNKNOWN;
State state = stateMap.get(stateName);
logger.debug("Resuming state="+stateName+" with status="+status);
if (logger.isDebugEnabled()) {
logger.debug("Resuming state="+stateName+" with status="+status);
}
StepExecution stepExecution = null;
// Terminate if there are no more states
@@ -161,7 +163,9 @@ public class SimpleFlow implements Flow, InitializingBean {
stateName = state.getName();
try {
logger.debug("Handling state="+stateName);
if (logger.isDebugEnabled()) {
logger.debug("Handling state="+stateName);
}
status = state.handle(executor);
stepExecution = executor.getStepExecution();
}
@@ -175,7 +179,9 @@ public class SimpleFlow implements Flow, InitializingBean {
stateName), e);
}
logger.debug("Completed state="+stateName+" with status="+status);
if (logger.isDebugEnabled()) {
logger.debug("Completed state="+stateName+" with status="+status);
}
state = nextState(stateName, status, stepExecution);
}

View File

@@ -170,7 +170,9 @@ public class JsrChunkProcessor<I,O> implements ChunkProcessor<I> {
return item;
}
catch (Exception e) {
logger.debug(e.getMessage() + " : " + e.getClass().getName());
if (logger.isDebugEnabled()) {
logger.debug(e.getMessage() + " : " + e.getClass().getName());
}
listener.onReadError(e);
throw e;
}

View File

@@ -536,7 +536,9 @@ public class CommandLineJobRunner {
String line = " ";
while (line != null) {
if (!line.startsWith("#") && StringUtils.hasText(line)) {
logger.debug("Stdin arg: " + line);
if (logger.isDebugEnabled()) {
logger.debug("Stdin arg: " + line);
}
newargs.add(line);
}
line = reader.readLine();

View File

@@ -203,7 +203,9 @@ public class JdbcJobExecutionDao extends AbstractJdbcBatchMetadataDao implements
String exitDescription = jobExecution.getExitStatus().getExitDescription();
if (exitDescription != null && exitDescription.length() > exitMessageLength) {
exitDescription = exitDescription.substring(0, exitMessageLength);
logger.debug("Truncating long message before update of JobExecution: " + jobExecution);
if (logger.isDebugEnabled()) {
logger.debug("Truncating long message before update of JobExecution: " + jobExecution);
}
}
Object[] parameters = new Object[] { jobExecution.getStartTime(), jobExecution.getEndTime(),
jobExecution.getStatus().toString(), jobExecution.getExitStatus().getExitCode(), exitDescription,

View File

@@ -271,7 +271,9 @@ public class JdbcStepExecutionDao extends AbstractJdbcBatchMetadataDao implement
*/
private String truncateExitDescription(String description) {
if (description != null && description.length() > exitMessageLength) {
logger.debug("Truncating long message before update of StepExecution, original message is: " + description);
if (logger.isDebugEnabled()) {
logger.debug("Truncating long message before update of StepExecution, original message is: " + description);
}
return description.substring(0, exitMessageLength);
} else {
return description;

View File

@@ -98,7 +98,9 @@ public class JobScope extends BatchScopeSupport {
scopedObject = context.getAttribute(name);
if (scopedObject == null) {
logger.debug(String.format("Creating object in scope=%s, name=%s", this.getName(), name));
if (logger.isDebugEnabled()) {
logger.debug(String.format("Creating object in scope=%s, name=%s", this.getName(), name));
}
scopedObject = objectFactory.getObject();
context.setAttribute(name, scopedObject);
@@ -126,7 +128,9 @@ public class JobScope extends BatchScopeSupport {
@Override
public void registerDestructionCallback(String name, Runnable callback) {
JobContext context = getContext();
logger.debug(String.format("Registered destruction callback in scope=%s, name=%s", this.getName(), name));
if (logger.isDebugEnabled()) {
logger.debug(String.format("Registered destruction callback in scope=%s, name=%s", this.getName(), name));
}
context.registerDestructionCallback(name, callback);
}
@@ -136,7 +140,9 @@ public class JobScope extends BatchScopeSupport {
@Override
public Object remove(String name) {
JobContext context = getContext();
logger.debug(String.format("Removing from scope=%s, name=%s", this.getName(), name));
if (logger.isDebugEnabled()) {
logger.debug(String.format("Removing from scope=%s, name=%s", this.getName(), name));
}
return context.removeAttribute(name);
}

View File

@@ -105,7 +105,10 @@ public class StepScope extends BatchScopeSupport {
scopedObject = context.getAttribute(name);
if (scopedObject == null) {
logger.debug(String.format("Creating object in scope=%s, name=%s", this.getName(), name));
if (logger.isDebugEnabled()) {
logger.debug(String.format("Creating object in scope=%s, name=%s", this.getName(), name));
}
scopedObject = objectFactory.getObject();
context.setAttribute(name, scopedObject);
@@ -133,7 +136,9 @@ public class StepScope extends BatchScopeSupport {
@Override
public void registerDestructionCallback(String name, Runnable callback) {
StepContext context = getContext();
logger.debug(String.format("Registered destruction callback in scope=%s, name=%s", this.getName(), name));
if (logger.isDebugEnabled()) {
logger.debug(String.format("Registered destruction callback in scope=%s, name=%s", this.getName(), name));
}
context.registerDestructionCallback(name, callback);
}
@@ -143,7 +148,9 @@ public class StepScope extends BatchScopeSupport {
@Override
public Object remove(String name) {
StepContext context = getContext();
logger.debug(String.format("Removing from scope=%s, name=%s", this.getName(), name));
if (logger.isDebugEnabled()) {
logger.debug(String.format("Removing from scope=%s, name=%s", this.getName(), name));
}
return context.removeAttribute(name);
}

View File

@@ -65,7 +65,9 @@ public abstract class StepContextRepeatCallback implements RepeatCallback {
// The StepContext has to be the same for all chunks,
// otherwise step-scoped beans will be re-initialised for each chunk.
StepContext stepContext = StepSynchronizationManager.register(stepExecution);
logger.debug("Preparing chunk execution for StepContext: "+ObjectUtils.identityToString(stepContext));
if (logger.isDebugEnabled()) {
logger.debug("Preparing chunk execution for StepContext: "+ObjectUtils.identityToString(stepContext));
}
ChunkContext chunkContext = attributeQueue.poll();
if (chunkContext == null) {
@@ -73,7 +75,9 @@ public abstract class StepContextRepeatCallback implements RepeatCallback {
}
try {
logger.debug("Chunk execution starting: queue size="+attributeQueue.size());
if (logger.isDebugEnabled()) {
logger.debug("Chunk execution starting: queue size="+attributeQueue.size());
}
return doInChunkContext(context, chunkContext);
}
finally {

View File

@@ -180,7 +180,9 @@ public abstract class AbstractStep implements Step, InitializingBean, BeanNameAw
public final void execute(StepExecution stepExecution) throws JobInterruptedException,
UnexpectedJobExecutionException {
logger.debug("Executing: id=" + stepExecution.getId());
if (logger.isDebugEnabled()) {
logger.debug("Executing: id=" + stepExecution.getId());
}
stepExecution.setStartTime(new Date());
stepExecution.setStatus(BatchStatus.STARTED);
getJobRepository().update(stepExecution);
@@ -209,7 +211,9 @@ public abstract class AbstractStep implements Step, InitializingBean, BeanNameAw
// Need to upgrade here not set, in case the execution was stopped
stepExecution.upgradeStatus(BatchStatus.COMPLETED);
logger.debug("Step execution success: id=" + stepExecution.getId());
if (logger.isDebugEnabled()) {
logger.debug("Step execution success: id=" + stepExecution.getId());
}
}
catch (Throwable e) {
stepExecution.upgradeStatus(determineBatchStatus(e));
@@ -273,7 +277,9 @@ public abstract class AbstractStep implements Step, InitializingBean, BeanNameAw
doExecutionRelease();
logger.debug("Step execution complete: " + stepExecution.getSummary());
if (logger.isDebugEnabled()) {
logger.debug("Step execution complete: " + stepExecution.getSummary());
}
}
}

View File

@@ -85,7 +85,9 @@ public class ChunkOrientedTasklet<I> implements Tasklet {
chunkContext.removeAttribute(INPUTS_KEY);
chunkContext.setComplete();
logger.debug("Inputs not busy, ended: " + inputs.isEnd());
if (logger.isDebugEnabled()) {
logger.debug("Inputs not busy, ended: " + inputs.isEnd());
}
return RepeatStatus.continueIf(!inputs.isEnd());
}

View File

@@ -95,7 +95,9 @@ public class SimpleChunkProvider<I> implements ChunkProvider<I> {
return item;
}
catch (Exception e) {
logger.debug(e.getMessage() + " : " + e.getClass().getName());
if (logger.isDebugEnabled()) {
logger.debug(e.getMessage() + " : " + e.getClass().getName());
}
listener.onReadError(e);
throw e;
}

View File

@@ -97,7 +97,9 @@ public class SimpleRetryExceptionHandler extends RetryListenerSupport implements
@Override
public <T, E extends Throwable> void close(RetryContext context, RetryCallback<T, E> callback, Throwable throwable) {
if (!retryPolicy.canRetry(context)) {
logger.debug("Marking retry as exhausted: "+context);
if (logger.isDebugEnabled()) {
logger.debug("Marking retry as exhausted: "+context);
}
getRepeatContext().setAttribute(EXHAUSTED, "true");
}
}

View File

@@ -434,7 +434,9 @@ public class TaskletStep extends AbstractStep {
// Apply the contribution to the step
// even if unsuccessful
logger.debug("Applying contribution: " + contribution);
if (logger.isDebugEnabled()) {
logger.debug("Applying contribution: " + contribution);
}
stepExecution.apply(contribution);
}
@@ -448,7 +450,9 @@ public class TaskletStep extends AbstractStep {
// stay false and we can use that later.
getJobRepository().updateExecutionContext(stepExecution);
stepExecution.incrementCommitCount();
logger.debug("Saving step execution before commit: " + stepExecution);
if (logger.isDebugEnabled()) {
logger.debug("Saving step execution before commit: " + stepExecution);
}
getJobRepository().update(stepExecution);
}
catch (Exception e) {
@@ -460,17 +464,23 @@ public class TaskletStep extends AbstractStep {
}
}
catch (Error e) {
logger.debug("Rollback for Error: " + e.getClass().getName() + ": " + e.getMessage());
if (logger.isDebugEnabled()) {
logger.debug("Rollback for Error: " + e.getClass().getName() + ": " + e.getMessage());
}
rollback(stepExecution);
throw e;
}
catch (RuntimeException e) {
logger.debug("Rollback for RuntimeException: " + e.getClass().getName() + ": " + e.getMessage());
if (logger.isDebugEnabled()) {
logger.debug("Rollback for RuntimeException: " + e.getClass().getName() + ": " + e.getMessage());
}
rollback(stepExecution);
throw e;
}
catch (Exception e) {
logger.debug("Rollback for Exception: " + e.getClass().getName() + ": " + e.getMessage());
if (logger.isDebugEnabled()) {
logger.debug("Rollback for Exception: " + e.getClass().getName() + ": " + e.getMessage());
}
rollback(stepExecution);
// Allow checked exceptions
throw new UncheckedTransactionException(e);

View File

@@ -169,7 +169,10 @@ public class StoredProcedureItemReader<T> extends AbstractCursorItemReader<T> {
SqlParameter cursorParameter = callContext.createReturnResultSetParameter("cursor", rowMapper);
this.callString = callContext.createCallString();
log.debug("Call string is: " + callString);
if (log.isDebugEnabled()) {
log.debug("Call string is: " + callString);
}
int cursorSqlType = Types.OTHER;
if (function) {

View File

@@ -558,7 +558,9 @@ ResourceAwareItemWriterItemStream<T>, InitializingBean {
if (key.contains(":")) {
prefix = key.substring(key.indexOf(":") + 1);
}
log.debug("registering prefix: " +prefix + "=" + entry.getValue());
if (log.isDebugEnabled()) {
log.debug("registering prefix: " +prefix + "=" + entry.getValue());
}
writer.setPrefix(prefix, entry.getValue());
}
}

View File

@@ -84,9 +84,11 @@ public abstract class StaxUtils {
staxResultClassCtorOnSpringWs15 = staxResultClassOnSpringWs15.getConstructor(XMLEventWriter.class);
} else {
logger.debug("'StaxSource' was not detected in Spring 3.0's OXM support or Spring WS 1.5's OXM support. " +
"This is a problem if you intend to use the " +StaxEventItemWriter.class.getName() + " or " +
StaxEventItemReader.class.getName()+". Please add the appropriate dependencies.");
if (logger.isDebugEnabled()) {
logger.debug("'StaxSource' was not detected in Spring 3.0's OXM support or Spring WS 1.5's OXM support. " +
"This is a problem if you intend to use the " +StaxEventItemWriter.class.getName() + " or " +
StaxEventItemReader.class.getName()+". Please add the appropriate dependencies.");
}
}
} catch (Exception ex) {

View File

@@ -249,8 +249,10 @@ public class RepeatTemplate implements RepeatOperations {
if (!deferred.isEmpty()) {
Throwable throwable = deferred.iterator().next();
logger.debug("Handling fatal exception explicitly (rethrowing first of " + deferred.size() + "): "
+ throwable.getClass().getName() + ": " + throwable.getMessage());
if (logger.isDebugEnabled()) {
logger.debug("Handling fatal exception explicitly (rethrowing first of " + deferred.size() + "): "
+ throwable.getClass().getName() + ": " + throwable.getMessage());
}
rethrow(throwable);
}
@@ -285,12 +287,16 @@ public class RepeatTemplate implements RepeatOperations {
RepeatListener interceptor = listeners[i];
// This is not an error - only log at debug
// level.
logger.debug("Exception intercepted (" + (i + 1) + " of " + listeners.length + ")", unwrappedThrowable);
if (logger.isDebugEnabled()) {
logger.debug("Exception intercepted (" + (i + 1) + " of " + listeners.length + ")", unwrappedThrowable);
}
interceptor.onError(context, unwrappedThrowable);
}
logger.debug("Handling exception: " + throwable.getClass().getName() + ", caused by: "
+ unwrappedThrowable.getClass().getName() + ": " + unwrappedThrowable.getMessage());
if (logger.isDebugEnabled()) {
logger.debug("Handling exception: " + throwable.getClass().getName() + ", caused by: "
+ unwrappedThrowable.getClass().getName() + ": " + unwrappedThrowable.getMessage());
}
exceptionHandler.handleException(context, unwrappedThrowable);
}

View File

@@ -34,7 +34,9 @@ public class ResourcelessTransactionManager extends AbstractPlatformTransactionM
@Override
protected void doCommit(DefaultTransactionStatus status) throws TransactionException {
logger.debug("Committing resourceless transaction on [" + status.getTransaction() + "]");
if (logger.isDebugEnabled()) {
logger.debug("Committing resourceless transaction on [" + status.getTransaction() + "]");
}
}
@Override
@@ -56,7 +58,9 @@ public class ResourcelessTransactionManager extends AbstractPlatformTransactionM
@Override
protected void doRollback(DefaultTransactionStatus status) throws TransactionException {
logger.debug("Rolling back resourceless transaction on [" + status.getTransaction() + "]");
if (logger.isDebugEnabled()) {
logger.debug("Rolling back resourceless transaction on [" + status.getTransaction() + "]");
}
}
@Override

View File

@@ -74,7 +74,9 @@ public class ChunkProcessorChunkHandler<S> implements ChunkHandler<S>, Initializ
@ServiceActivator
public ChunkResponse handleChunk(ChunkRequest<S> chunkRequest) throws Exception {
logger.debug("Handling chunk: " + chunkRequest);
if (logger.isDebugEnabled()) {
logger.debug("Handling chunk: " + chunkRequest);
}
StepContribution stepContribution = chunkRequest.getStepContribution();
@@ -85,7 +87,9 @@ public class ChunkProcessorChunkHandler<S> implements ChunkHandler<S>, Initializ
+ ": " + failure.getMessage());
}
logger.debug("Completed chunk handling with " + stepContribution);
if (logger.isDebugEnabled()) {
logger.debug("Completed chunk handling with " + stepContribution);
}
return new ChunkResponse(true, chunkRequest.getSequence(), chunkRequest.getJobId(), stepContribution);
}

View File

@@ -29,7 +29,9 @@ public class JmsRedeliveredExtractor {
private static final Log logger = LogFactory.getLog(JmsRedeliveredExtractor.class);
public ChunkResponse extract(ChunkResponse input, @Header(JmsHeaders.REDELIVERED) boolean redelivered) {
logger.debug("Extracted redelivered flag for response, value="+redelivered);
if (logger.isDebugEnabled()) {
logger.debug("Extracted redelivered flag for response, value="+redelivered);
}
return new ChunkResponse(input, redelivered);
}

View File

@@ -118,7 +118,9 @@ public class RemoteChunkHandlerFactoryBean<T> implements FactoryBean<ChunkHandle
}
Assert.state(step instanceof TaskletStep, "Step [" + step.getName() + "] must be a TaskletStep");
logger.debug("Converting TaskletStep with name=" + step.getName());
if (logger.isDebugEnabled()) {
logger.debug("Converting TaskletStep with name=" + step.getName());
}
Tasklet tasklet = getTasklet((TaskletStep) step);
Assert.state(tasklet instanceof ChunkOrientedTasklet<?>, "Tasklet must be ChunkOrientedTasklet in step="
@@ -233,7 +235,9 @@ public class RemoteChunkHandlerFactoryBean<T> implements FactoryBean<ChunkHandle
Assert.notNull(target, "Target object must not be null");
Field field = ReflectionUtils.findField(target.getClass(), name);
if (field == null) {
logger.debug("Could not find field [" + name + "] on target [" + target + "]");
if (logger.isDebugEnabled()) {
logger.debug("Could not find field [" + name + "] on target [" + target + "]");
}
return null;
}