Return-Path: X-Original-To: apmail-activemq-dev-archive@www.apache.org Delivered-To: apmail-activemq-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 933A310B71 for ; Fri, 11 Jul 2014 08:38:06 +0000 (UTC) Received: (qmail 61847 invoked by uid 500); 11 Jul 2014 08:38:06 -0000 Delivered-To: apmail-activemq-dev-archive@activemq.apache.org Received: (qmail 61801 invoked by uid 500); 11 Jul 2014 08:38:06 -0000 Mailing-List: contact dev-help@activemq.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@activemq.apache.org Delivered-To: mailing list dev@activemq.apache.org Received: (qmail 61790 invoked by uid 99); 11 Jul 2014 08:38:06 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 11 Jul 2014 08:38:06 +0000 Date: Fri, 11 Jul 2014 08:38:06 +0000 (UTC) From: "matteo rulli (JIRA)" To: dev@activemq.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (AMQ-5260) Cross talk over duplex network connection can lead to blocking (alternative take) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/AMQ-5260?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14058553#comment-14058553 ] matteo rulli commented on AMQ-5260: ----------------------------------- I tried to fix the second deadlock with the patch contained in *AMQ_5260_2.patch*. After few hours I run into another deadlock: this is due to the fact that _org.apache.activemq.transport.MutexTransport.writeLock_ is not static. This cause different instances of transports (in our case VMTransport and Failover/Openwire Transport) to cross different writeLock barriers in different order (see stacktraces below) STACKTRACE 1 {noformat} Name: ActiveMQ BrokerService[master2] Task-119 State: WAITING on java.util.concurrent.locks.ReentrantLock$NonfairSync@766eae77 owned by: ActiveMQ Transport: tcp:///10.0.1.219:61616@64702 Total blocked: 1 Total waited: 94 Stack trace: sun.misc.Unsafe.park(Native Method) java.util.concurrent.locks.LockSupport.park(Unknown Source) java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Unknown Source) java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(Unknown Source) java.util.concurrent.locks.ReentrantLock.lock(Unknown Source) org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:66) org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) org.apache.activemq.network.DemandForwardingBridgeSupport.serviceLocalCommand(DemandForwardingBridgeSupport.java:930) org.apache.activemq.network.DemandForwardingBridgeSupport$2.onCommand(DemandForwardingBridgeSupport.java:177) org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) org.apache.activemq.transport.vm.VMTransport.doDispatch(VMTransport.java:170) org.apache.activemq.transport.vm.VMTransport.dispatch(VMTransport.java:157) org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:112) org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:68) org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:1339) org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:858) org.apache.activemq.broker.TransportConnection.iterate(TransportConnection.java:904) org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:129) org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:47) java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) java.lang.Thread.run(Unknown Source) {noformat} ---- STACKTRACE 2 {noformat} Name: ActiveMQ Transport: tcp:///10.0.1.219:61616@64702 State: WAITING on java.util.concurrent.locks.ReentrantLock$NonfairSync@61e2cf66 owned by: ActiveMQ BrokerService[master2] Task-119 Total blocked: 8 Total waited: 22 Stack trace: sun.misc.Unsafe.park(Native Method) java.util.concurrent.locks.LockSupport.park(Unknown Source) java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source) java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Unknown Source) java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(Unknown Source) java.util.concurrent.locks.ReentrantLock.lock(Unknown Source) org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:66) org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:1339) org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:858) org.apache.activemq.broker.TransportConnection.dispatchSync(TransportConnection.java:818) org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:151) org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) org.apache.activemq.transport.vm.VMTransport.doDispatch(VMTransport.java:170) org.apache.activemq.transport.vm.VMTransport.dispatch(VMTransport.java:157) org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:112) org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:68) org.apache.activemq.transport.ResponseCorrelator.asyncRequest(ResponseCorrelator.java:81) org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:86) org.apache.activemq.network.DemandForwardingBridgeSupport.addSubscription(DemandForwardingBridgeSupport.java:865) org.apache.activemq.network.DemandForwardingBridgeSupport.addConsumerInfo(DemandForwardingBridgeSupport.java:1149) org.apache.activemq.network.DemandForwardingBridgeSupport.serviceRemoteConsumerAdvisory(DemandForwardingBridgeSupport.java:722) org.apache.activemq.network.DemandForwardingBridgeSupport.serviceRemoteCommand(DemandForwardingBridgeSupport.java:585) org.apache.activemq.network.DemandForwardingBridgeSupport$3.onCommand(DemandForwardingBridgeSupport.java:195) org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) org.apache.activemq.transport.failover.FailoverTransport$3.onCommand(FailoverTransport.java:196) org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113) org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270) org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214) org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196) java.lang.Thread.run(Unknown Source) {noformat} To solve this last deadlock I applied the *AMQ_5260_3.patch*: {noformat} --- activemq-parent-5.9.0-orig\activemq-client\src\main\java\org\apache\activemq\transport\MutexTransport.java Tue Oct 15 00:41:46 2013 +++ activemq-parent-5.9.0\activemq-client\src\main\java\org\apache\activemq\transport\MutexTransport.java Fri Jul 11 08:43:22 2014 @@ -24,7 +24,7 @@ */ public class MutexTransport extends TransportFilter { - private final ReentrantLock writeLock = new ReentrantLock(); + private static final ReentrantLock writeLock = new ReentrantLock(); private boolean syncOnCommand; public MutexTransport(Transport next) { {noformat} I don't know if this is a good idead... any advice would be welcome here. > Cross talk over duplex network connection can lead to blocking (alternative take) > --------------------------------------------------------------------------------- > > Key: AMQ-5260 > URL: https://issues.apache.org/jira/browse/AMQ-5260 > Project: ActiveMQ > Issue Type: Bug > Affects Versions: 5.9.0 > Reporter: matteo rulli > Attachments: AMQ_5260.patch, AMQ_5260_2.patch, AMQ_5260_3.patch, deadlock.jpg, debug.jpg > > > Pretty the same description with respect to AMQ-4328. > ---- > !deadlock.jpg! > h2. Stacktraces: > Stacktrace no.1: > {noformat} > Name: ActiveMQ NIO Worker 12 > State: BLOCKED on java.net.URI@1bae2b28 owned by: ActiveMQ Transport: tcp:///10.0.1.219:61616@57789 > Total blocked: 2 Total waited: 67 > Stack trace: > org.apache.activemq.network.DemandForwardingBridgeSupport.serviceRemoteConsumerAdvisory(DemandForwardingBridgeSupport.java:714) > org.apache.activemq.network.DemandForwardingBridgeSupport.serviceRemoteCommand(DemandForwardingBridgeSupport.java:581) > org.apache.activemq.network.DemandForwardingBridgeSupport$3.onCommand(DemandForwardingBridgeSupport.java:191) > org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) > org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) > org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113) > org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270) > org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) > org.apache.activemq.transport.nio.NIOTransport.serviceRead(NIOTransport.java:138) > org.apache.activemq.transport.nio.NIOTransport$1.onSelect(NIOTransport.java:69) > org.apache.activemq.transport.nio.SelectorSelection.onSelect(SelectorSelection.java:94) > org.apache.activemq.transport.nio.SelectorWorker$1.run(SelectorWorker.java:119) > java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) > java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) > java.lang.Thread.run(Unknown Source) > {noformat} > ---- > stack trace no.2 > {noformat} > Name: ActiveMQ Transport: tcp:///10.0.1.219:61616@57789 > State: WAITING on java.util.concurrent.locks.ReentrantLock$NonfairSync@3cdbfa3e owned by: ActiveMQ BrokerService[master2] Task-4 > Total blocked: 19 Total waited: 3 > Stack trace: > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(Unknown Source) > java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source) > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source) > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Unknown Source) > java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(Unknown Source) > java.util.concurrent.locks.ReentrantLock.lock(Unknown Source) > org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:66) > org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) > org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:1339) > org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:858) > org.apache.activemq.broker.TransportConnection.dispatchSync(TransportConnection.java:818) > org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:151) > org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) > org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) > org.apache.activemq.transport.vm.VMTransport.doDispatch(VMTransport.java:138) > org.apache.activemq.transport.vm.VMTransport.dispatch(VMTransport.java:127) > - locked java.util.concurrent.atomic.AtomicBoolean@689389da > org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:104) > org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:68) > org.apache.activemq.transport.ResponseCorrelator.asyncRequest(ResponseCorrelator.java:81) > org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:86) > org.apache.activemq.network.DemandForwardingBridgeSupport.addSubscription(DemandForwardingBridgeSupport.java:856) > org.apache.activemq.network.DemandForwardingBridgeSupport.addConsumerInfo(DemandForwardingBridgeSupport.java:1128) > org.apache.activemq.network.DemandForwardingBridgeSupport.serviceRemoteConsumerAdvisory(DemandForwardingBridgeSupport.java:714) > - locked java.net.URI@1bae2b28 > org.apache.activemq.network.DemandForwardingBridgeSupport.serviceRemoteCommand(DemandForwardingBridgeSupport.java:581) > org.apache.activemq.network.DemandForwardingBridgeSupport$3.onCommand(DemandForwardingBridgeSupport.java:191) > org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) > org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) > org.apache.activemq.transport.failover.FailoverTransport$3.onCommand(FailoverTransport.java:196) > org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113) > org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270) > org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) > org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214) > org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196) > java.lang.Thread.run(Unknown Source) > {noformat} > ---- > stack trace no.3 > {noformat} > Name: ActiveMQ BrokerService[master2] Task-4 > State: WAITING on java.util.concurrent.locks.ReentrantLock$NonfairSync@717bb9c owned by: ActiveMQ Transport: tcp:///10.0.1.219:61616@57789 > Total blocked: 19 Total waited: 117 > Stack trace: > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.park(Unknown Source) > java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source) > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(Unknown Source) > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Unknown Source) > java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(Unknown Source) > java.util.concurrent.locks.ReentrantLock.lock(Unknown Source) > org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:66) > org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) > org.apache.activemq.network.DemandForwardingBridgeSupport.serviceLocalCommand(DemandForwardingBridgeSupport.java:921) > org.apache.activemq.network.DemandForwardingBridgeSupport$2.onCommand(DemandForwardingBridgeSupport.java:173) > org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) > org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) > org.apache.activemq.transport.vm.VMTransport.doDispatch(VMTransport.java:138) > org.apache.activemq.transport.vm.VMTransport.dispatch(VMTransport.java:127) > - locked java.util.concurrent.atomic.AtomicBoolean@453bb109 > org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:104) > org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:68) > org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) > org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:1339) > org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:858) > org.apache.activemq.broker.TransportConnection.iterate(TransportConnection.java:904) > org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:129) > org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:47) > java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) > java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) > java.lang.Thread.run(Unknown Source) > {noformat} -- This message was sent by Atlassian JIRA (v6.2#6252)