activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From badavis <brian.alexander.da...@gmail.com>
Subject Re: ActiveMQ message dequeuing hangs
Date Fri, 04 Jul 2014 13:47:23 GMT
I ran into the same issue.  The good thing is I figured out what was causing
the issue.  I believe the issue is two issues.  There is a deadlock in the
processing of async jobs that is blocking a job that can unblock the
deadlock.

The two threads that are important are:

Thread 43139: (state = BLOCKED)
 - sun.misc.Unsafe.park(boolean, long) @bci=0 (Compiled frame; information
may be imprecise)
 - java.util.concurrent.locks.LockSupport.park(java.lang.Object) @bci=20,
line=186 (Compiled frame [deoptimized])
 -
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt()
@bci=7, line=834 (Compiled frame [deoptimized])
 -
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(int)
@bci=89, line=994 (Compiled frame [deoptimized])
 -
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(int)
@bci=47, line=1303 (Interpreted frame)
 - java.util.concurrent.CountDownLatch.await() @bci=11, line=236
(Interpreted frame)
 -
org.apache.activemq.leveldb.LevelDBStore.rollback(org.apache.activemq.command.TransactionId)
@bci=152, line=498 (Interpreted frame)
 *-> org.apache.activemq.transaction.LocalTransaction.rollback() @bci=111,
line=94 (Interpreted frame)*
 -
org.apache.activemq.broker.TransactionBroker.rollbackTransaction(org.apache.activemq.broker.ConnectionContext,
org.apache.activemq.command.TransactionId) @bci=15, line=258 (Interpreted
frame)
 -
org.apache.activemq.broker.BrokerFilter.rollbackTransaction(org.apache.activemq.broker.ConnectionContext,
org.apache.activemq.command.TransactionId) @bci=12, line=142 (Interpreted
frame)
 -
org.apache.activemq.broker.MutableBrokerFilter.rollbackTransaction(org.apache.activemq.broker.ConnectionContext,
org.apache.activemq.command.TransactionId) @bci=12, line=147 (Interpreted
frame)
 -
org.apache.activemq.broker.TransportConnection.processRollbackTransaction(org.apache.activemq.command.TransactionInfo)
@bci=44, line=442 (Interpreted frame)
 -
org.apache.activemq.command.TransactionInfo.visit(org.apache.activemq.state.CommandVisitor)
@bci=146, line=104 (Compiled frame [deoptimized])
 -
org.apache.activemq.broker.TransportConnection.service(org.apache.activemq.command.Command)
@bci=52, line=292 (Compiled frame [deoptimized])
 -
org.apache.activemq.broker.TransportConnection$1.onCommand(java.lang.Object)
@bci=95, line=149 (Compiled frame [deoptimized])
 - org.apache.activemq.transport.MutexTransport.onCommand(java.lang.Object)
@bci=58, line=50 (Compiled frame [deoptimized])
 -
org.apache.activemq.transport.WireFormatNegotiator.onCommand(java.lang.Object)
@bci=35, line=113 (Compiled frame [deoptimized])
 -
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(java.lang.Object)
@bci=162, line=270 (Compiled frame [deoptimized])
 -
org.apache.activemq.transport.TransportSupport.doConsume(java.lang.Object)
@bci=27, line=83 (Compiled frame [deoptimized])
 - org.apache.activemq.transport.tcp.TcpTransport.doRun() @bci=13, line=214
(Compiled frame [deoptimized])
 - org.apache.activemq.transport.tcp.TcpTransport.run() @bci=70, line=196
(Compiled frame [deoptimized])
 - java.lang.Thread.run() @bci=17, line=724 (Interpreted frame) 



Thread 38184: (state = BLOCKED)
* -> org.apache.activemq.leveldb.LevelDBStore.getTopicGCPositions() @bci=15,
line=768 (Interpreted frame)*
 - org.apache.activemq.leveldb.DBManager$$anonfun$pollGc$1.apply$mcV$sp()
@bci=28, line=640 (Interpreted frame)
 - org.fusesource.hawtdispatch.package$$anon$4.run() @bci=10, line=357
(Compiled frame [deoptimized])
 - org.fusesource.hawtdispatch.internal.SerialDispatchQueue.run() @bci=317,
line=100 (Compiled frame [deoptimized])
 - org.fusesource.hawtdispatch.internal.pool.SimpleThread.run() @bci=105,
line=77 (Compiled frame [deoptimized])


I bolded and -> the lines that are important with the deadlock.  The
rollback thread holds the lock of the message store and the
getTopicGCPositions needs to get the lock of the message store (the
identified lines in the stack trace).  That may not seem that important but
the more important thing is where the getTopicGCPositions is running.  It is
running in the hawtdispatcher.  If you could look at the SerialDispatchQueue
you would see that it tries to run all the jobs in one run.  Well this is a
problem if one of the front jobs is blocked until a job behind it runs. 
That is where we are.  The job that the rollback is waiting on is scheduled
to run behind the pollGc job.

My belief is their are two issues:

* the LevelDBStore class does not fully own its lock
* the hawtdispatcher does not distribute the jobs over the dispatcher's
threads, but chooses to run many jobs in one thread when other threads are
available.
 
Hope this helps.

You have a good one.

Brian

P.S. The only mitigation is a code change.  You cannot change the polling
interval to lower the likely hood of it happening because it is hard coded
to every 10 seconds.




--
View this message in context: http://activemq.2283324.n4.nabble.com/ActiveMQ-message-dequeuing-hangs-tp4681366p4682806.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Mime
View raw message