DefaultMessageListenerContainer hangs on shutdown [SPR-11787]

[spring-projects-issues]

Ivo Leitão opened SPR-11787 and commented

We are having an issue in our application in production when we try to make a deploy. When the weblogic (the application server that we are using) tries to stop the defaultmessagelistener container it hangs the process and we have to shutdown the server and restart it. From my understanding of the thread dump that I've attached it is hanging on the method org.springframework.jms.listener.DefaultMessageListenerContainer.doShutdown(DefaultMessageListenerContainer.java:543) but I don't know if i'm interpreting this right. We have recently updated the spring version and the previous versions (pre 4.0 I think but I'm not sure) didn't have this problem.

---

Affects: 4.0.3, 4.2.4

Attachments:

• threadDump.txt (66.25 kB)

Issue Links:

• DefaultMessageListenerContainer#doShutdown hangs [SPR-11841] #16460 DefaultMessageListenerContainer#doShutdown hangs
• Application Server Fail to Stop Application and server while stopping transactions with spring [SPR-16586] #21128 Application Server Fail to Stop Application and server while stopping transactions with spring
• DefaultMessageListenerContainer doesn't shutdown gracefully if long recovery interval is set [SPR-14200] #18774 DefaultMessageListenerContainer doesn't shutdown gracefully if long recovery interval is set

[spring-projects-issues]

Juergen Hoeller commented

Is this reproducible every time, i.e. on every shutdown of your application, or just occasionally?

Juergen

[spring-projects-issues]

Ivo Leitão commented

Hello,
I've made only three deployments in production since January of this year, it happened today and in the previous deployment (in March). On the deployment that I've made in January it didn't happen. From what I've seen in my git history the version that we were using in January was the 3.2.5.RELEASE, we are now at the 4.0.3.RELEASE. Since it happens only in production I cannot stop the application to check if it happens every time. It is however a peculiar application in terms of workload. We are using jms to push log information namely soap requests, errors, events and sql queries to a database. To achieve that we are publishing the logs to 4 different queues that are pooled by DefaultMessageListenerContainer. This means that we have an extreme amount of inserts in production, typically 10-20 per second. It's working fairly well but it is subject to an extreme workload.

My configuration bellow (jms):

<bean id="lvrConnectionFactory" class="org.springframework.jndi.JndiObjectFactoryBean"
		p:jndiTemplate="jndiTemplate" 
		p:jndiName="${svc.jms.connection.factory.jndi.name}"
		p:resourceRef="${svc.jms.resourceref}"/>

	<bean id="lvrDestinationResolver"
		class="org.springframework.jms.support.destination.JndiDestinationResolver"
		p:jndiTemplate="jndiTemplate" 
		p:cache="true"
		p:resourceRef="${svc.jms.resourceref}"/>

	<bean id="coreJMSLOGService" class="xx.xxx.logvw.core.service.jms.CoreLOGBrokerImpl" />

	<jms:listener-container connection-factory="lvrConnectionFactory" 
		acknowledge="auto"
		destination-resolver="lvrDestinationResolver" 
		task-executor="taskExecutor"			
		concurrency="${svc.jms.listener.concurrency}"
		container-type="default">
		<jms:listener destination="${svc.jms.queue.event.jndi.name}" ref="coreJMSLOGService" method="onEventMessage" />
		<jms:listener destination="${svc.jms.queue.error.jndi.name}" ref="coreJMSLOGService" method="onErrorMessage" />
		<jms:listener destination="${svc.jms.queue.soap.jndi.name}" ref="coreJMSLOGService" method="onSoapMessage" />
		<jms:listener destination="${svc.jms.queue.sql.jndi.name}" ref="coreJMSLOGService" method="onSqlMessage" />
	</jms:listener-container>

Note that I'm using a taskexecutor to fetch weblogic threadpool via commonj (in my web.xml):

<resource-ref>
       <res-ref-name>default</res-ref-name>
       <res-type>commonj.work.WorkManager</res-type>
       <res-auth>Container</res-auth>
       <res-sharing-scope>Shareable</res-sharing-scope>
</resource-ref>

(in spring)

<bean id="taskExecutor" class="org.springframework.scheduling.commonj.WorkManagerTaskExecutor">
       <property name="workManagerName" value="java:comp/env/default"/>
       <property name="resourceRef" value="true"/>
            </bean>	

[spring-projects-issues]

Dirk Henselin commented

Hello,
we had a similar problem yesterday with WebSphere Application Server 8.5.5.7 and Spring 4.2.2. We left the recovery interval at default, but on shutdown we got the following log events every 4 millis (!) and we had to kill the server.

[25.01.16 12:41:16:748 CET] 0004a57a com.ibm.ejs.j2c.PoolManager E J2CA0046E: Die Methode reserve hat während der Erstellung der ManagedConnection für Ressource jms/QueueConnectionFactory eine Ausnahme abgefangen und löst ResourceAllocationException aus. Ursprüngliche Ausnahme: Pool requests blocked, connection pool is being shut down.
[25.01.16 12:41:16:748 CET] 0004a57a SystemOut O ERROR [Default Executor-thread-301484] org.springframework.jms.listener.DefaultMessageListenerContainer#refreshConnectionUntilSuccessful:937
Could not refresh JMS Connection for destination 'com.ibm.mq.connector.outbound.MQQueueProxy@2e1a3411' - retrying using FixedBackOff{interval=5000, currentAttempts=598, maxAttempts=unlimited}. Cause: MQJCA1011: Failed to allocate a JMS connection.

I assume, that the listening thread is interrupted by the application server on shutdown and if the interrupted status is (by chance) detected in Thread.sleep(..) in applyBackOffTime(..), then it leads to endless refresh attempts ignoring the recovery interval.

[spring-projects-issues]

Juergen Hoeller commented

Dirk Henselin, I'm wondering why DefaultMessageListenerContainer even continues to try to recover there: Hasn't it received a stop signal itself at that point? It would only really continue to recover if it wasn't notified of the shutdown itself...

We consider a thread interruption as a hint to retry the connection right away instead of continuing to wait. Admittedly, if this happens several times in short sequence, that assumption may be flawed and is worth improving.

However, we should rather abort recovery altogether when shutting down. The real problem in your scenario seems to be a missing shutdown notification.

Juergen

[spring-projects-issues]

Dirk Henselin commented

@Juergen: Thank you for your quick response. I agree with your conclusion that the main problem is a missing shut down notification. Looks like the application server shut down the connection pool and shut down the managed thread pool before shutting down the application.

Thread interruption as a hint to retry? Isn't it much more likely, that the interrupting thread wants the interrupted thread to stop what it is doing? IMHO the interrupted thread shouldn't re-interrupt itself if it intends to continue doing real work, because the interrupted status will be a burden. Code running in the interrupted thread can later poll the interrupted status to see if it has been requested to stop what it is doing. In our scenario this happens in Thread.sleep(..) in applyBackOffTime(..) and results in an endless sequence of self interruptions caused by a single thread interruption by another thread.

Dirk

[spring-projects-issues]

Juergen Hoeller commented

I've added an interrupted check to our recovery mode: If we got interrupted on the previous back-off attempt and we're still failing to recover, then we immediately give up.

So we do try to recover one more time, assuming that the interrupt signal might have been for that reason... but if that attempt fails, we assume that we are supposed to shut down.

Juergen