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 E81419A63 for ; Mon, 5 Mar 2012 22:32:19 +0000 (UTC) Received: (qmail 63771 invoked by uid 500); 5 Mar 2012 22:32:19 -0000 Delivered-To: apmail-activemq-dev-archive@activemq.apache.org Received: (qmail 63706 invoked by uid 500); 5 Mar 2012 22:32:19 -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 63693 invoked by uid 99); 5 Mar 2012 22:32:19 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 05 Mar 2012 22:32:19 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=5.0 tests=ALL_TRUSTED,T_RP_MATCHES_RCVD X-Spam-Check-By: apache.org Received: from [140.211.11.116] (HELO hel.zones.apache.org) (140.211.11.116) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 05 Mar 2012 22:32:17 +0000 Received: from hel.zones.apache.org (hel.zones.apache.org [140.211.11.116]) by hel.zones.apache.org (Postfix) with ESMTP id A5EB2A79C for ; Mon, 5 Mar 2012 22:31:57 +0000 (UTC) Date: Mon, 5 Mar 2012 22:31:57 +0000 (UTC) From: "Timothy Bish (Commented) (JIRA)" To: dev@activemq.apache.org Message-ID: <1562738939.24268.1330986717681.JavaMail.tomcat@hel.zones.apache.org> In-Reply-To: <1765802050.11656.1330691336987.JavaMail.tomcat@hel.zones.apache.org> Subject: [jira] [Commented] (AMQ-3755) receiveNoWait blocked on same mutex as sending threads MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 X-Virus-Checked: Checked by ClamAV on apache.org [ https://issues.apache.org/jira/browse/AMQ-3755?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13222687#comment-13222687 ] Timothy Bish commented on AMQ-3755: ----------------------------------- >From the stack trace it appears as though you VMTransport is configured for sync mode and it has reached its limit on the pending buffer (LinkedBlockingQueue) and that stalls the send operation until the broker has time to process the backed up messages. You can provide you config for the client uris to lets us see what you have setup. Since your producers and consumer appear to be sharing the same Connection instance they will block on the MutexTransport which is what you see in the stack trace. As far as I can tell things are working as designed. > receiveNoWait blocked on same mutex as sending threads > ------------------------------------------------------ > > Key: AMQ-3755 > URL: https://issues.apache.org/jira/browse/AMQ-3755 > Project: ActiveMQ > Issue Type: Bug > Components: Broker > Affects Versions: 5.5.0 > Reporter: Claudio Tagliola > > We have a server processing requests with an internal broker, connected with a vm transport. At a certain load and a high number of clients (approx. 350 clients) we see our server congested towards the internal VM broker. By looking at the stacktraces, it seems the incoming reading thread is waiting for a lock obtained by one of several other threads. This resulted in a short period (around 20-30 seconds) of very sluggish response times towards our clients. Response times of _any_ request through ActiveMQ go from a normal <50ms response time towards 2 seconds. > Below is an extract of a stackdump while this happened. The first stacktrace is the thread trying to read incoming messages with a receiveNoWait, but it is blocked by the first thread, which the second thread owns. The third and fourth are two other processes, all waiting for the same mutex. These four processes are - from our server's perspective - not related to each other: > {noformat} > "RoundRobinReceiver" prio=10 tid=0x00007f1030483800 nid=0x2a59 waiting for monitor entry [0x00007f1075f5b000] > java.lang.Thread.State: BLOCKED (on object monitor) > at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:39) > - waiting to lock <0x00000006bb6028b0> (a java.lang.Object) > at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) > at org.apache.activemq.ActiveMQConnection.doAsyncSendPacket(ActiveMQConnection.java:1265) > at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1259) > at org.apache.activemq.ActiveMQSession.asyncSendPacket(ActiveMQSession.java:1863) > at org.apache.activemq.ActiveMQSession.sendAck(ActiveMQSession.java:2029) > at org.apache.activemq.ActiveMQSession.sendAck(ActiveMQSession.java:2024) > at org.apache.activemq.ActiveMQMessageConsumer.afterMessageIsConsumed(ActiveMQMessageConsumer.java:871) > - locked <0x0000000715bda898> (a java.util.LinkedList) > at org.apache.activemq.ActiveMQMessageConsumer.receiveNoWait(ActiveMQMessageConsumer.java:617) > at com.foo.bar.impl.server.services.jms.JMSRoundRobinListener.readFromConsumer(JMSRoundRobinListener.java:200) > at com.foo.bar.impl.server.services.jms.JMSRoundRobinListener.roundRobinOverQueueConsumers(JMSRoundRobinListener.java:173) > at com.foo.bar.impl.server.services.jms.JMSRoundRobinListener.receiveMessagesUntilInterrupt(JMSRoundRobinListener.java:109) > at com.foo.bar.impl.server.services.jms.JMSRoundRobinListener.access$200(JMSRoundRobinListener.java:22) > at com.foo.bar.impl.server.services.jms.JMSRoundRobinListener$RoundRobinReceiver.run(JMSRoundRobinListener.java:248) > at java.lang.Thread.run(Thread.java:722) > "ResultPublisher1" prio=10 tid=0x00007f0f20003000 nid=0x2b31 waiting on condition [0x00007f1060d59000] > java.lang.Thread.State: WAITING (parking) > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <0x00000006bb600410> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) > at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:349) > at org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:94) > at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:40) > - locked <0x00000006bb6028b0> (a java.lang.Object) > at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) > at org.apache.activemq.ActiveMQConnection.doAsyncSendPacket(ActiveMQConnection.java:1265) > at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1259) > at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1744) > - locked <0x00000006bc4bd448> (a java.lang.Object) > at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:231) > at org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:241) > at com.foo.bar.impl.server.services.jms.MappingResultPublisher.publishResponse(MappingResultPublisher.java:66) > at com.foo.bar.impl.server.services.jms.QueuedMappingResultPublisher.executeJob(QueuedMappingResultPublisher.java:44) > at com.foo.bar.impl.server.services.mapper.AbstractQueuedMappingJobExecutor.processJob(AbstractQueuedMappingJobExecutor.java:120) > at com.foo.bar.impl.server.services.mapper.AbstractQueuedMappingJobExecutor.access$100(AbstractQueuedMappingJobExecutor.java:23) > at com.foo.bar.impl.server.services.mapper.AbstractQueuedMappingJobExecutor$1.run(AbstractQueuedMappingJobExecutor.java:105) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:722) > "RemoteResolveRequestService-ReplierThread-1" prio=10 tid=0x00007f1030485000 nid=0x2a5a waiting for monitor entry [0x00007f1075e5a000] > java.lang.Thread.State: BLOCKED (on object monitor) > at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:39) > - waiting to lock <0x00000006bb6028b0> (a java.lang.Object) > at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) > at org.apache.activemq.ActiveMQConnection.doAsyncSendPacket(ActiveMQConnection.java:1265) > at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1259) > at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1744) > - locked <0x00000006baf131f8> (a java.lang.Object) > at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:231) > at org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:300) > at com.foo.bar.remoteservices.server.RpcReplierTask.sendReply(RpcReplierTask.java:129) > at com.foo.bar.remoteservices.server.RpcReplierTask.run(RpcReplierTask.java:103) > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:722) > "PersistEntityMessagePublisherThread" daemon prio=10 tid=0x00007f1030b70800 nid=0x2a4b waiting for monitor entry [0x00007f1076c68000] > java.lang.Thread.State: BLOCKED (on object monitor) > at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:39) > - waiting to lock <0x00000006bb6028b0> (a java.lang.Object) > at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60) > at org.apache.activemq.ActiveMQConnection.doAsyncSendPacket(ActiveMQConnection.java:1265) > at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1259) > at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1744) > - locked <0x00000006bc542e90> (a java.lang.Object) > at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:231) > at org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:241) > at com.foo.bar.impl.server.services.PersistEntityMessageBackgroundPublisher.sendMessage(PersistEntityMessageBackgroundPublisher.java:140) > at com.foo.bar.impl.server.services.PersistEntityMessageBackgroundPublisher.sendMessage(PersistEntityMessageBackgroundPublisher.java:132) > at com.foo.bar.impl.server.services.PersistEntityMessageBackgroundPublisher.forwardMessagesToTopic(PersistEntityMessageBackgroundPublisher.java:101) > at com.foo.bar.impl.server.services.PersistEntityMessageBackgroundPublisher.access$000(PersistEntityMessageBackgroundPublisher.java:22) > at com.foo.bar.impl.server.services.PersistEntityMessageBackgroundPublisher$1.run(PersistEntityMessageBackgroundPublisher.java:49) > at java.lang.Thread.run(Thread.java:722) > {noformat} > My question is: why is the receiving of messages blocked by the other threads and why do they share a single mutex? Is there anything I can do to alleviate this problem? -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa For more information on JIRA, see: http://www.atlassian.com/software/jira