DisposableBeanAdapter.destroy() method should not log error on destroy failures [SPR-4478]

[spring-projects-issues]

Niklas Schlimm opened SPR-4478 and commented

Only a small but irritating one (generates lots of noncritical exceptions in our log file):

1. Problem

org.springframework.beans.factory.support.DisposableBeanAdapter.destroy() generates lots of senceless exception traces in my log.

2. Root cause

Method shows the following code sequence:

try {
((DisposableBean) this.bean).destroy();
}
catch (Throwable ex) {
logger.error("Couldn't invoke destroy method of bean with name '" + this.beanName + "'", ex);
}

All excpetions are logged as errors with complete excpetion trace, but nothing else happens in catch block ...

3. Consequence

Loads of noncritical exception traces in log file. Developers spending valuable time on analyzing what happens.

4. Possible Actions

Log a warning instead saying that destroy failed. Do not log exception trace.

---

Affects: 2.5.1

[spring-projects-issues]

Juergen Hoeller commented

Why is it that your destroy methods actually fail in such "senseless" form? What kind of stacktraces do you see there that happen all the time but can be safely ignored?

Juergen

[spring-projects-issues]

Juergen Hoeller commented

I've revised bean destruction logging to log at WARN level with the exception toString only. The full exception will still be logged when DEBUG level is active. This will make it into Spring 2.5.2.

However, components should not usually thrown an exception from their destroy method. If you repeatedly encounter such exceptions, double-check whether your destroy methods are implemented properly... They should maybe catch non-serious exceptions themselves and swallow them internally, not propagating them to the container.

Juergen

[spring-projects-issues]

Niklas Schlimm commented

I am using a standard job configuration with spring batch 1.0.0.m4.
Here is the stack trace:

265 [main] ERROR org.springframework.beans.factory.support.DisposableBeanAdapter - Couldn't invoke destroy method of bean with name 'scopedTarget.hibernateItemReader'
org.hibernate.SessionException: Session is closed!
at org.hibernate.impl.AbstractSessionImpl.errorIfClosed(AbstractSessionImpl.java:49)
at org.hibernate.impl.SessionImpl.getBatcher(SessionImpl.java:260)
at org.hibernate.impl.AbstractScrollableResults.close(AbstractScrollableResults.java:99)
at org.springframework.batch.io.cursor.HibernateCursorItemReader.close(HibernateCursorItemReader.java:112)
at org.springframework.batch.io.cursor.HibernateCursorItemReader.destroy(HibernateCursorItemReader.java:152)
at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:154)
at org.springframework.beans.factory.support.DisposableBeanAdapter.run(DisposableBeanAdapter.java:134)
at org.springframework.batch.execution.scope.SimpleStepContext.close(SimpleStepContext.java:163)
at org.springframework.batch.execution.scope.StepSynchronizationManager.close(StepSynchronizationManager.java:58)
at org.springframework.batch.execution.step.simple.SimpleStepExecutor.execute(SimpleStepExecutor.java:288)
at org.springframework.batch.execution.step.simple.RepeatOperationsStep.execute(RepeatOperationsStep.java:89)
at org.springframework.batch.execution.job.simple.SimpleJob.execute(SimpleJob.java:82)
at org.springframework.batch.execution.launch.SimpleJobLauncher$1.run(SimpleJobLauncher.java:85)
at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:49)
at org.springframework.batch.execution.launch.SimpleJobLauncher.run(SimpleJobLauncher.java:80)
at com.admiral.angebotssynchro.job.AbstractJobLaunchJunit4IntegrationTest.testLaunchJob(AbstractJobLaunchJunit4IntegrationTest.java:83)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.springframework.test.context.junit4.SpringTestMethod.invoke(SpringTestMethod.java:198)
at org.springframework.test.context.junit4.SpringMethodRoadie.runTestMethod(SpringMethodRoadie.java:274)
at org.springframework.test.context.junit4.SpringMethodRoadie$2.run(SpringMethodRoadie.java:207)
at org.springframework.test.context.junit4.SpringMethodRoadie.runBeforesThenTestThenAfters(SpringMethodRoadie.java:254)
at org.springframework.test.context.junit4.SpringMethodRoadie.runWithRepetitions(SpringMethodRoadie.java:234)
at org.springframework.test.context.junit4.SpringMethodRoadie.runTest(SpringMethodRoadie.java:204)
at org.springframework.test.context.junit4.SpringMethodRoadie.run(SpringMethodRoadie.java:146)
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.invokeTestMethod(SpringJUnit4ClassRunner.java:151)
at org.junit.internal.runners.JUnit4ClassRunner.runMethods(JUnit4ClassRunner.java:51)
at org.junit.internal.runners.JUnit4ClassRunner$1.run(JUnit4ClassRunner.java:44)
at org.junit.internal.runners.ClassRoadie.runUnprotected(ClassRoadie.java:27)
at org.junit.internal.runners.ClassRoadie.runProtected(ClassRoadie.java:37)
at org.junit.internal.runners.JUnit4ClassRunner.run(JUnit4ClassRunner.java:42)
at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:38)
at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)

Job configuration:

<bean id="hibernateJob" parent="simpleJob">
	<!-- set restartable=false so that this job can be used by more than one test -->
	<property name="restartable" value="false" />
	<property name="steps">
		<bean id="angebotsLoad" parent="repeatOperationsStep">
			<property name="tasklet">
				<bean class="org.springframework.batch.execution.tasklet.ItemOrientedTasklet">
					<property name="itemReader" ref="hibernateItemReader" />
					<property name="itemWriter" ref="hibernateOutputSource" />
				</bean>
			</property>
			<property name="chunkOperations">
				<bean class="org.springframework.batch.repeat.support.RepeatTemplate">
					<property name="interceptors" ref="hibernateOutputSource" />
					<property name="completionPolicy">
						<bean class="org.springframework.batch.repeat.policy.SimpleCompletionPolicy">
							<property name="chunkSize" value="3" />
						</bean>
					</property>
				</bean>
			</property>
			<property name="stepOperations">
				<bean
					class="org.springframework.batch.repeat.support.RepeatTemplate">
					<property name="exceptionHandler">
						<bean class="org.springframework.batch.repeat.exception.handler.SimpleLimitExceptionHandler" p:limit="2" p:useParent="true" p:type="java.lang.Exception" />
					</property>
				</bean>
			</property>
		</bean>
	</property>
</bean>

[spring-projects-issues]

Juergen Hoeller commented

Thanks for the details! I've forwarded this to the Spring Batch guys - for them to check whether they can handle those non-critical cleanup exceptions explicitly.

Juergen