[QPID-2756] Java Client dead locks on session close using spring CachingConnectionFactory

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: M4, 0.6
• Component/s: JMS AMQP 0-x
• Labels: deadlock

Environment

CentOS, Java 1.6.0_17, Spring 2.5.6

• Assignee: Unassigned
• Reporter: Richard Peter
• Created: 24/Jul/10 03:35
• Updated: 18/Jul/14 22:42
• Resolved: 18/Jul/14 22:42

Description

Using spring in a standalone framework to connect to C++ broker version M4. Spring configured to use the CachingConnectionFactory. When the broker is killed and restarted the java client deadlocks more than 50% of the time in closing the connection and sessions. I originally ran into this issue against the M4 version of the client. I updated to 0.6 and still encountered the issue. The deadlock from jstack is listed below. The pertinent info from our spring configuration:

<bean id="amqConnectionFactory" class="org.apache.qpid.client.AMQConnectionFactory">
<constructor-arg type="java.lang.String" value="amqp://guest:guest@/edex?brokerlist='tcp://${broker.addr}?retries=9999&connectdelay=30000'&maxprefetch=10"/>
</bean>

<bean id="genericThreadPool"
class="org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor">
<property name="corePoolSize" value="${jms.pool.min}" />
<property name="maxPoolSize" value="${jms.pool.max}" />
<property name="keepAliveSeconds" value="60000" />
</bean>

<bean id="jms-generic" class="org.apache.camel.component.jms.JmsComponent">
<constructor-arg ref="jmsGenericConfig" />
<property name="taskExecutor" ref="genericThreadPool" />
</bean>

<bean id="jmsGenericConfig" class="org.apache.camel.component.jms.JmsConfiguration"
factory-bean="jmsConfig" factory-method="copy" />

<bean id="jmsRetryInterval" class="java.lang.Long">
<constructor-arg type="java.lang.String" value="30000" />
</bean>

<bean id="jmsTimeout" class="java.lang.Long">
<constructor-arg type="java.lang.String" value="30000" />
</bean>

<bean id="jmsConfig" class="org.apache.camel.component.jms.JmsConfiguration">
<property name="cacheLevelName" value="CACHE_SESSION" />
<property name="connectionFactory" ref="jmsConnectionFactory" />
<property name="recoveryInterval" ref="jmsRetryInterval" />
<property name="receiveTimeout" ref="jmsTimeout" />
</bean>

<bean id="jmsConnectionFactory" class="org.springframework.jms.connection.CachingConnectionFactory">
<constructor-arg ref="amqConnectionFactory" />
<property name="sessionCacheSize" value="${jms.pool.max}" />
</bean>

JStack deadlock

Found one Java-level deadlock:
=============================
"genericThreadPool-4":
waiting to lock monitor 0x0afacdf4 (object 0xa18ce308, a java.lang.Object),
which is held by "IoReceiver - localhost/127.0.0.1:5672"
"IoReceiver - localhost/127.0.0.1:5672":
waiting to lock monitor 0x0b153800 (object 0xa4665f80, a java.lang.Object),
which is held by "gribThreadPool-2"
"gribThreadPool-2":
waiting to lock monitor 0x09b05af0 (object 0xa472cac0, a java.lang.Object),
which is held by "IoReceiver - localhost/127.0.0.1:5672"

Java stack information for the threads listed above:
===================================================
"genericThreadPool-4":
at org.springframework.jms.connection.SingleConnectionFactory.createConnection(SingleConnectionFactory.java:226)

• waiting to lock <0xa18ce308> (a java.lang.Object)
  at org.springframework.jms.support.JmsAccessor.createConnection(JmsAccessor.java:184)
  at org.springframework.jms.listener.AbstractJmsListeningContainer.createSharedConnection(AbstractJmsListeningContainer.java:378)
  at org.springframework.jms.listener.AbstractJmsListeningContainer.refreshSharedConnection(AbstractJmsListeningContainer.java:363)
• locked <0xa4383d30> (a java.lang.Object)
  at org.springframework.jms.listener.DefaultMessageListenerContainer.refreshConnectionUntilSuccessful(DefaultMessageListenerContainer.java:785)
  at org.springframework.jms.listener.DefaultMessageListenerContainer.recoverAfterListenerSetupFailure(DefaultMessageListenerContainer.java:767)
  at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:898)
• locked <0xa4383d80> (a java.lang.Object)
  at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
  at java.lang.Thread.run(Thread.java:619)
  "IoReceiver - localhost/127.0.0.1:5672":
  at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1014)
• waiting to lock <0xa4665f80> (a java.lang.Object)
• locked <0xa4665f90> (a java.lang.Object)
  at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1005)
• locked <0xa41cec18> (a java.lang.Object)
• locked <0xa4665f90> (a java.lang.Object)
  at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1005)
• locked <0xa46660e0> (a java.lang.Object)
• locked <0xa4665f90> (a java.lang.Object)
  at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1005)
• locked <0xa472cac0> (a java.lang.Object)
• locked <0xa4665f90> (a java.lang.Object)
  at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1005)
• locked <0xa4771e00> (a java.lang.Object)
• locked <0xa4665f90> (a java.lang.Object)
  at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1005)
• locked <0xa4773c10> (a java.lang.Object)
• locked <0xa4665f90> (a java.lang.Object)
  at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:989)
  at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:980)
  at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:975)
  at org.springframework.jms.connection.SingleConnectionFactory.closeConnection(SingleConnectionFactory.java:427)
  at org.springframework.jms.connection.SingleConnectionFactory.resetConnection(SingleConnectionFactory.java:322)
• locked <0xa18ce308> (a java.lang.Object)
  at org.springframework.jms.connection.CachingConnectionFactory.resetConnection(CachingConnectionFactory.java:199)
  at org.springframework.jms.connection.SingleConnectionFactory.onException(SingleConnectionFactory.java:303)
  at org.springframework.jms.connection.ChainedExceptionListener.onException(ChainedExceptionListener.java:60)
  at org.apache.qpid.client.AMQConnectionDelegate_0_10.closed(AMQConnectionDelegate_0_10.java:279)
  at org.apache.qpid.transport.Connection.closed(Connection.java:462)
  at org.apache.qpid.transport.network.Assembler.closed(Assembler.java:113)
  at org.apache.qpid.transport.network.InputHandler.closed(InputHandler.java:202)
  at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:150)
  at java.lang.Thread.run(Thread.java:619)
  "gribThreadPool-2":
  at org.apache.qpid.client.AMQSession.close(AMQSession.java:671)
• waiting to lock <0xa472cac0> (a java.lang.Object)
• locked <0xa4665f80> (a java.lang.Object)
  at org.apache.qpid.client.AMQSession.close(AMQSession.java:648)
  at org.apache.qpid.client.AMQSession.close(AMQSession.java:510)
  at org.springframework.jms.connection.CachingConnectionFactory$CachedSessionInvocationHandler.physicalClose(CachingConnectionFactory.java:425)
  at org.springframework.jms.connection.CachingConnectionFactory$CachedSessionInvocationHandler.invoke(CachingConnectionFactory.java:305)
  at $Proxy73.close(Unknown Source)
  at org.springframework.jms.support.JmsUtils.closeSession(JmsUtils.java:108)
  at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.clearResources(DefaultMessageListenerContainer.java:1020)
• locked <0xa4505690> (a java.lang.Object)
  at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:887)
  at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
  at java.lang.Thread.run(Thread.java:619)

Found 1 deadlock.

Issue Links

• relates to: QPID-5050 Clients calling Connection#stop() (or #close()) from within an ExceptionListener have potential for deadlock