activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Rob Davies <rajdav...@gmail.com>
Subject Re: Queue "hangs" when Kaha Store kicks in. Restart required.
Date Mon, 10 Dec 2007 19:46:54 GMT
use the latest snapshot - some problems in this area were resolved  
last week


On Dec 10, 2007, at 5:46 PM, mrh wrote:

>
> I believe I've noticed something similar using a topic... any ideas?
>
> Thanks,
> mrh
>
>
>
> DominicTulley wrote:
>>
>> Hi, I've been investigating Camel recently and today I was taking a  
>> look
>> at message throughput in ActiveMQ when Camel routing is being used.
>>
>> I have been doing simplistic testing so far, just using the example
>> message Producer class to pump lots of text messages through a queue.
>> When it's a simple queue with no consumer, things seem fine.
>>
>> However, if I have a Camel RouteBuilder as a consumer of this queue,
>> forwarding to another queue in the same ActiveMQ instance then it  
>> seems
>> possible to reproducibly make the queue hang.  This is a permanent  
>> hang,
>> with a restart of activemq required to fix the problem as far as I  
>> can
>> tell.
>>
>> I was in two minds about if this should be raised in the Camel  
>> forum or
>> this one, but the problem seems to lie in ActiveMQ (judging by the  
>> absence
>> of camel classes in any of the stack traces) and I suspect Camel is  
>> just a
>> useful way to introduce an unknown situation which causes the  
>> problem.
>>
>> The story briefly is:
>>
>> Start ActiveMQ (see version info later) with a simple camel route  
>> enabled
>> (from activemq:a to activemq:b for instance)
>> Start up a modified Producer class that just sends lots of messages  
>> (flat
>> out) to "a".
>> Each message is 25500 characters (~50KB)
>> After a while the ActiveMQ console will indicate that the Kaha  
>> store is
>> being used. (happens after a few thousand for me but will be machine
>> specific)
>> Shortly after this, the producer will stall.
>> Restarting the producer does not help.
>> Running a consumer to clear the queue does not help.
>> Restarting ActiveMQ does help (of course!).
>>
>> I have tried this with three AMQs so far (4.1.1 hangs with no  
>> apparent
>> reason, 5.0 Snapshot from 12th august gets a thread deadlock and 5.0
>> snapshot from 15th august hangs for no apparent reason).
>>
>> In each case, the producer is stuck writing to a socket (I've seen  
>> this
>> reported against AMQ 4.0.1 but no fix was put in place as the cause  
>> was
>> not identified).  Stacktrace is :
>>
>> "main" prio=6 tid=0x00038278 nid=0xe9c runnable  
>> [0x0007f000..0x0007fc3c]
>>        at java.net.SocketOutputStream.socketWrite0(Native Method)
>>        at
>> java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
>>        at java.net.SocketOutputStream.write(SocketOutputStream.java: 
>> 136)
>>        at
>> org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBu
>> fferedOutputStream.java:105)
>>        at java.io.DataOutputStream.flush(DataOutputStream.java:106)
>>        at
>> org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.ja
>> va:120)
>>        at
>> org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMoni
>> tor.java:144)
>>        - locked <0x22f99060> (a
>> org.apache.activemq.transport.InactivityMonitor
>> $2)
>>        at
>> org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.
>> java:82)
>>        at
>> org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatN
>> egotiator.java:90)
>>        at
>> org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.ja
>> va:40)
>>        - locked <0x22f9c5f0> (a java.lang.Object)
>>        at
>> org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorre
>> lator.java:59)
>>        at
>> org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnec
>> tion.java:1148)
>>        at
>> org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1583)
>>        - locked <0x22fa0118> (a java.lang.Object)
>>        at
>> org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProdu
>> cer.java:226)
>>        at
>> org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessa
>> geProducerSupport.java:240)
>>        at ProducerTool.sendLoop(ProducerTool.java:137)
>>        at ProducerTool.run(ProducerTool.java:99)
>>        at ProducerTool.main(ProducerTool.java:60)
>>
>>
>> The deadlock found in AMQ 5 from 12th august is as follows:
>>
>> Found one Java-level deadlock:
>> =============================
>> "ActiveMQ Transport: tcp:///127.0.0.1:4445":
>>  waiting to lock monitor 0x0003f84c (object 0x094f3700, a
>> java.lang.Object),
>>  which is held by "ActiveMQ Transport: tcp:///127.0.0.1:4443"
>> "ActiveMQ Transport: tcp:///127.0.0.1:4443":
>>  waiting to lock monitor 0x0003f72c (object 0x094f5ee8, a
>> org.apache.activemq.b
>> roker.region.cursors.FilePendingMessageCursor),
>>  which is held by "ActiveMQ Transport: tcp:///127.0.0.1:4445"
>>
>> Java stack information for the threads listed above:
>> ===================================================
>> "ActiveMQ Transport: tcp:///127.0.0.1:4445":
>>        at
>> org.apache.activemq.memory.UsageManager.increaseUsage(UsageManager.ja
>> va:157)
>>        - waiting to lock <0x094f3700> (a java.lang.Object)
>>        at
>> org.apache.activemq.command.Message.incrementReferenceCount(Message.j
>> ava:585)
>>        at
>> org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.ne
>> xt(FilePendingMessageCursor.java:192)
>>        - locked <0x094f5ee8> (a
>> org.apache.activemq.broker.region.cursors.FileP
>> endingMessageCursor)
>>        at
>> org.apache.activemq.broker.region.cursors.StoreQueueCursor.next(Store
>> QueueCursor.java:129)
>>        - locked <0x094f3908> (a
>> org.apache.activemq.broker.region.cursors.Store
>> QueueCursor)
>>        at
>> org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1015)
>>        - locked <0x094f3908> (a
>> org.apache.activemq.broker.region.cursors.Store
>> QueueCursor)
>>        at
>> org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:106
>> 4)
>>        - locked <0x094f3998> (a java.lang.Object)
>>        at
>> org.apache.activemq.broker.region.Queue.sendMessage(Queue.java:993)
>>        at
>> org.apache.activemq.broker.region.Queue.doMessageSend(Queue.java:478)
>>
>>        at org.apache.activemq.broker.region.Queue.send(Queue.java: 
>> 436)
>>        at
>> org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.
>> java:328)
>>        at
>> org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java
>> :402)
>>        at
>> org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.j
>> ava:221)
>>        at
>> org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:125)
>>        at
>> org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeD
>> estinationBroker.java:95)
>>        at
>> org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilt
>> er.java:135)
>>        at
>> org.apache.activemq.broker.TransportConnection.processMessage(Transpo
>> rtConnection.java:474)
>>        at
>> org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.jav
>> a:623)
>>        at
>> org.apache.activemq.broker.TransportConnection.service(TransportConne
>> ction.java:320)
>>        at
>> org.apache.activemq.broker.TransportConnection$1.onCommand(TransportC
>> onnection.java:216)
>>        at
>> org.apache.activemq.transport.TransportFilter.onCommand(TransportFilt
>> er.java:67)
>>        at
>> org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireForm
>> atNegotiator.java:129)
>>        at
>> org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityM
>> onitor.java:124)
>>        - locked <0x09502968> (a
>> org.apache.activemq.transport.InactivityMonitor
>> $1)
>>        at
>> org.apache.activemq.transport.TransportSupport.doConsume(TransportSup
>> port.java:83)
>>        at
>> org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.jav
>> a:150)
>>        at
>> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:
>> 137)
>>        at java.lang.Thread.run(Thread.java:595)
>> "ActiveMQ Transport: tcp:///127.0.0.1:4443":
>>        at
>> org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.on
>> MemoryUseChanged(FilePendingMessageCursor.java:249)
>>        - waiting to lock <0x094f5ee8> (a
>> org.apache.activemq.broker.region.curs
>> ors.FilePendingMessageCursor)
>>        at
>> org.apache.activemq.memory.UsageManager.fireEvent(UsageManager.java:3
>> 58)
>>        at
>> org.apache.activemq.memory.UsageManager.setPercentUsage(UsageManager.
>> java:328)
>>        - locked <0x094f3700> (a java.lang.Object)
>>        at
>> org.apache.activemq.memory.UsageManager.decreaseUsage(UsageManager.ja
>> va:181)
>>        at
>> org.apache.activemq.command.Message.decrementReferenceCount(Message.j
>> ava:602)
>>        - locked <0x0961f980> (a
>> org.apache.activemq.command.ActiveMQTextMessage
>> )
>>        at
>> org.apache.activemq.broker.region.IndirectMessageReference.drop(Indir
>> ectMessageReference.java:137)
>>        - locked <0x09612fe0> (a
>> org.apache.activemq.broker.region.IndirectMessa
>> geReference)
>>        at
>> org.apache.activemq.broker.region.QueueSubscription.acknowledge(Queue
>> Subscription.java:56)
>>        at
>> org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(Pr
>> efetchSubscription.java:193)
>>        - locked <0x094f0178> (a
>> org.apache.activemq.broker.region.QueueSubscrip
>> tion)
>>        at
>> org.apache.activemq.broker.region.AbstractRegion.acknowledge(Abstract
>> Region.java:340)
>>        at
>> org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBrok
>> er.java:427)
>>        at
>> org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionB
>> roker.java:191)
>>        at
>> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java
>> :73)
>>        at
>> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java
>> :73)
>>        at
>> org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBro
>> kerFilter.java:87)
>>        at
>> org.apache.activemq.broker.TransportConnection.processMessageAck(Tran
>> sportConnection.java:480)
>>        at
>> org.apache.activemq.command.MessageAck.visit(MessageAck.java:184)
>>        at
>> org.apache.activemq.broker.TransportConnection.service(TransportConne
>> ction.java:320)
>>        at
>> org.apache.activemq.broker.TransportConnection$1.onCommand(TransportC
>> onnection.java:216)
>>        at
>> org.apache.activemq.transport.TransportFilter.onCommand(TransportFilt
>> er.java:67)
>>        at
>> org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireForm
>> atNegotiator.java:129)
>>        at
>> org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityM
>> onitor.java:124)
>>        - locked <0x094e9eb0> (a
>> org.apache.activemq.transport.InactivityMonitor
>> $1)
>>        at
>> org.apache.activemq.transport.TransportSupport.doConsume(TransportSup
>> port.java:83)
>>        at
>> org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.jav
>> a:150)
>>        at
>> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:
>> 137)
>>        at java.lang.Thread.run(Thread.java:595)
>>
>> Found 1 deadlock.
>>
>> The "Hang for no reason" thread dump is in this file
>> http://www.nabble.com/file/p12181133/AMQ5%2BThreadDump.txt
>> AMQ5+ThreadDump.txt . In this one, I am posting to a queue called
>> DataQueue and this is being forwarded to a queue called TOOL.DEFAULT.
>>
>> I'm not an expert on AMQ so perhaps I've just not configured  
>> something
>> correctly.  It seems to me that when the number of entries in the "a"
>> queue gets too long, AMQ decides to buffer them in a persistent store
>> (kaha) and this is where things fall over.  The use of Camel as a  
>> router
>> slows down the consumption of messages from queue "a" sufficiently to
>> allow the backlog to build up and cause kaha to kick in.
>>
>> Some things don't make sense to me though - for instance if I just  
>> send
>> messages to a queue and don't consume them then should they not  
>> also end
>> up in a kaha store once I've sent enough?  My first experiment once I
>> found this problem was to send messages to queue "a" without any  
>> consumer
>> - this didn't cause a problem until AMQ ran out of memory.  This  
>> suggests
>> that kaha didn't kick in at all?
>>
>> Anyhow, sorry for the long post but this seems a significant  
>> problem.  I
>> realise the message throughput I have used is pretty extreme but  
>> there
>> does seem to be some nasty race condition between message arrival,
>> consumption and the kaha store which could perhaps arise at any time.
>>
>> Thanks,
>>
>> -Dominic
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>
> -- 
> View this message in context: http://www.nabble.com/Queue-%22hangs%22-when-Kaha-Store-kicks-in.-Restart-required.-tp12181133s2354p14257739.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>



Rob Davies
'Go further faster with Apache Camel!'
http://rajdavies.blogspot.com/




Mime
View raw message