[
https://issues.apache.org/jira/browse/QPIDJMS-458?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Christian Danner updated QPIDJMS-458:
-------------------------------------
Description:
It seems there is a race condition when attempting to close a
JmsMessageProducer as indicated by the stack trace below. The corresponding
Thread is stuck waiting for the JmsMessageProducer to be destroyed for a
JmsConnection.
This behaviour was observed while testing Apache Artemis with low disk space.
In the provided trace we attempt to close a broker connection due to a
JMSException (TransactionRolledBackException caused by a duplicate message ID),
however the Thread gets stuck indefinitely waiting for the JmsMessageProducer
to be destroyed.
We keep track of all sessions for a JmsConnection (one session per Thread) and
attempt to perform a graceful connection shutdown by closing all producers and
consumers, followed by each session before finally calling close on the
connection.
We use external synchronization to ensure that the connection can only be
closed by a single Thread (so in this example all other Threads attempting to
use the broker connection are blocked waiting for the lock from the closing
Thread to be released).
Stack Trace:
{{"Replicator_node1-->node2_[0ms]" #25 prio=5 os_prio=0 tid=0x49383c00
nid=0x3918 in Object.wait() [0x4b1ef000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at
org.apache.qpid.jms.provider.BalancedProviderFuture.sync(BalancedProviderFuture.java:137)
- locked <0x04e60300> (a
org.apache.qpid.jms.provider.BalancedProviderFuture)
at
org.apache.qpid.jms.JmsConnection.destroyResource(JmsConnection.java:755)
at
org.apache.qpid.jms.JmsConnection.destroyResource(JmsConnection.java:744)
at
org.apache.qpid.jms.JmsMessageProducer.doClose(JmsMessageProducer.java:103)
at
org.apache.qpid.jms.JmsMessageProducer.close(JmsMessageProducer.java:89)
at
acme.broker.client.jms.impl.JMSMessageProducer.closeInternal(JMSMessageProducer.java:48)
at
acme.broker.client.jms.impl.JMSMessageProducer.close(JMSMessageProducer.java:43)
at acme.broker.client.AbstractSession.tryClose(AbstractSession.java:108)
at acme.broker.client.AbstractSession.close(AbstractSession.java:90)
at
acme.broker.client.AbstractThreadedSessionManager.close(AbstractThreadedSessionManager.java:108)
- locked <0x1d321078> (a java.util.concurrent.ConcurrentHashMap)
at
acme.broker.client.AbstractBrokerConnection.closeInternal(AbstractBrokerConnection.java:204)
at
acme.broker.client.AbstractBrokerConnection.close(AbstractBrokerConnection.java:84)
at
acme.replication.jms.JMSMessageBridge.trySend(JMSMessageBridge.java:109)
at
acme.replication.jms.JMSMessageBridge.access$6(JMSMessageBridge.java:99)
at
acme.replication.jms.JMSMessageBridge$ReplicatorRunnable.run(JMSMessageBridge.java:62)
at java.lang.Thread.run(Thread.java:745)
Locked ownable synchronizers:
- <0x1cfa76b0> (a
java.util.concurrent.locks.ReentrantLock$NonfairSync)}}
was:
It seems there is a race condition when attempting to close a
JmsMessageProducer as indicated by the stack trace below. The corresponding
Thread is stuck waiting for the JmsMessageProducer to be destroyed for a
JmsConnection.
This behaviour was observed while testing Apache Artemis with low disk space.
In the provided trace we attempt to close a broker connection due to a
JMSException (TransactionRolledBackException caused by a duplicate message ID),
however the Thread gets stuck indefinitely waiting for the JmsMessageProducer
to be destroyed.
We keep track of all sessions for a JmsConnection (one session per Thread) and
attempt to perform a graceful connection shutdown by closing all producers and
consumers, followed by each session before finally calling close on the
connection.
We use external synchronization to ensure that the connection can only be
closed by a single Thread (so in this example all other Threads attempting to
use the broker connection are blocked waiting for the lock from the closing
Thread to be released).
Stack Trace:
{{"Replicator_node1-->node2_[0ms]" #25 prio=5 os_prio=0 tid=0x49383c00
nid=0x3918 in Object.wait() [0x4b1ef000]}}
{{ java.lang.Thread.State: WAITING (on object monitor)}}
{{ at java.lang.Object.wait(Native Method)}}
{{ at java.lang.Object.wait(Object.java:502)}}
{{ at
org.apache.qpid.jms.provider.BalancedProviderFuture.sync(BalancedProviderFuture.java:137)}}
{{ - locked <0x04e60300> (a
org.apache.qpid.jms.provider.BalancedProviderFuture)}}
{{ at
org.apache.qpid.jms.JmsConnection.destroyResource(JmsConnection.java:755)}}
{{ at
org.apache.qpid.jms.JmsConnection.destroyResource(JmsConnection.java:744)}}
{{ at
org.apache.qpid.jms.JmsMessageProducer.doClose(JmsMessageProducer.java:103)}}
{{ at org.apache.qpid.jms.JmsMessageProducer.close(JmsMessageProducer.java:89)}}
{{ at
acme.broker.client.jms.impl.JMSMessageProducer.closeInternal(JMSMessageProducer.java:48)}}
{{ at
acme.broker.client.jms.impl.JMSMessageProducer.close(JMSMessageProducer.java:43)}}
{{ at acme.broker.client.AbstractSession.tryClose(AbstractSession.java:108)}}
{{ at acme.broker.client.AbstractSession.close(AbstractSession.java:90)}}
{{ at
acme.broker.client.AbstractThreadedSessionManager.close(AbstractThreadedSessionManager.java:108)}}
{{ - locked <0x1d321078> (a java.util.concurrent.ConcurrentHashMap)}}
{{ at
acme.broker.client.AbstractBrokerConnection.closeInternal(AbstractBrokerConnection.java:204)}}
{{ at
acme.broker.client.AbstractBrokerConnection.close(AbstractBrokerConnection.java:84)}}
{{ at acme.replication.jms.JMSMessageBridge.trySend(JMSMessageBridge.java:109)}}
{{ at acme.replication.jms.JMSMessageBridge.access$6(JMSMessageBridge.java:99)}}
{{ at
acme.replication.jms.JMSMessageBridge$ReplicatorRunnable.run(JMSMessageBridge.java:62)}}
{{ at java.lang.Thread.run(Thread.java:745)}}{{Locked ownable synchronizers:}}
{{ - <0x1cfa76b0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)}}
> Potential race condition in JmsConnection.destroyResource
> ---------------------------------------------------------
>
> Key: QPIDJMS-458
> URL: https://issues.apache.org/jira/browse/QPIDJMS-458
> Project: Qpid JMS
> Issue Type: Bug
> Components: qpid-jms-client
> Affects Versions: 0.42.0
> Environment: OS: Windows 10 64Bit
> Broker: Apache Artemis 2.8.0
> JVM: Java HotSpot(TM) Client VM (25.40-b25, mixed mode)
> Java: version 1.8.0_40, vendor Oracle Corporation
> Reporter: Christian Danner
> Priority: Blocker
>
> It seems there is a race condition when attempting to close a
> JmsMessageProducer as indicated by the stack trace below. The corresponding
> Thread is stuck waiting for the JmsMessageProducer to be destroyed for a
> JmsConnection.
> This behaviour was observed while testing Apache Artemis with low disk space.
> In the provided trace we attempt to close a broker connection due to a
> JMSException (TransactionRolledBackException caused by a duplicate message
> ID), however the Thread gets stuck indefinitely waiting for the
> JmsMessageProducer to be destroyed.
> We keep track of all sessions for a JmsConnection (one session per Thread)
> and attempt to perform a graceful connection shutdown by closing all
> producers and consumers, followed by each session before finally calling
> close on the connection.
> We use external synchronization to ensure that the connection can only be
> closed by a single Thread (so in this example all other Threads attempting to
> use the broker connection are blocked waiting for the lock from the closing
> Thread to be released).
>
> Stack Trace:
> {{"Replicator_node1-->node2_[0ms]" #25 prio=5 os_prio=0 tid=0x49383c00
> nid=0x3918 in Object.wait() [0x4b1ef000]
> java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> at java.lang.Object.wait(Object.java:502)
> at
> org.apache.qpid.jms.provider.BalancedProviderFuture.sync(BalancedProviderFuture.java:137)
> - locked <0x04e60300> (a
> org.apache.qpid.jms.provider.BalancedProviderFuture)
> at
> org.apache.qpid.jms.JmsConnection.destroyResource(JmsConnection.java:755)
> at
> org.apache.qpid.jms.JmsConnection.destroyResource(JmsConnection.java:744)
> at
> org.apache.qpid.jms.JmsMessageProducer.doClose(JmsMessageProducer.java:103)
> at
> org.apache.qpid.jms.JmsMessageProducer.close(JmsMessageProducer.java:89)
> at
> acme.broker.client.jms.impl.JMSMessageProducer.closeInternal(JMSMessageProducer.java:48)
> at
> acme.broker.client.jms.impl.JMSMessageProducer.close(JMSMessageProducer.java:43)
> at acme.broker.client.AbstractSession.tryClose(AbstractSession.java:108)
> at acme.broker.client.AbstractSession.close(AbstractSession.java:90)
> at
> acme.broker.client.AbstractThreadedSessionManager.close(AbstractThreadedSessionManager.java:108)
> - locked <0x1d321078> (a java.util.concurrent.ConcurrentHashMap)
> at
> acme.broker.client.AbstractBrokerConnection.closeInternal(AbstractBrokerConnection.java:204)
> at
> acme.broker.client.AbstractBrokerConnection.close(AbstractBrokerConnection.java:84)
> at
> acme.replication.jms.JMSMessageBridge.trySend(JMSMessageBridge.java:109)
> at
> acme.replication.jms.JMSMessageBridge.access$6(JMSMessageBridge.java:99)
> at
> acme.replication.jms.JMSMessageBridge$ReplicatorRunnable.run(JMSMessageBridge.java:62)
> at java.lang.Thread.run(Thread.java:745)
> Locked ownable synchronizers:
> - <0x1cfa76b0> (a
> java.util.concurrent.locks.ReentrantLock$NonfairSync)}}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
