[jira] Created: (AMQ-1093) Client deadlock during failover

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

[jira] Created: (AMQ-1093) Client deadlock during failover

JIRA jira@apache.org
Client deadlock during failover
-------------------------------

                 Key: AMQ-1093
                 URL: https://issues.apache.org/activemq/browse/AMQ-1093
             Project: ActiveMQ
          Issue Type: Bug
          Components: Transport
    Affects Versions: 4.1.0
         Environment: Linux 2.6, java 1.5.0
            Reporter: Danielius Jurna
            Priority: Critical


In 4.1.0 there's deadlock on connection failover. There is the scenario:
1. Client consumes message using message listener
2. Conection is lost
3. Client sends message to another queue from messagle listener and waits until connection is restored.
4. Reconnect task blocks on reconnecting.
 
This bug is new to 4.1.0. The problem is in ActiveMQMessageConsumre.dispatch . There is new lock on unconsumedMessages.getMutex() . So the reconnect task cannot invoke ActiveMQMessageConsumre.clearMessagesInProgress(), because lock is acquired by message listener, which waits untill message is sent (untill connection is resumed). Here is stack traces:
 
"ActiveMQ Session Task" daemon prio=1 tid=0x0000002b27774260 nid=0x4778 in Object.wait() [0x0000000040ef3000..0x0000000040ef4db0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0x0000002b0020a7c8> (a edu.emory.mathcs.backport.java.util.concurrent.locks.CondVar)
        at java.lang.Object.wait(Object.java:474)
        at edu.emory.mathcs.backport.java.util.concurrent.locks.CondVar.await(CondVar.java:75)
        - locked <0x0000002b0020a7c8> (a edu.emory.mathcs.backport.java.util.concurrent.locks.CondVar)
        at edu.emory.mathcs.backport.java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:318)
        at org.apache.activemq.transport.FutureResponse.getResult(FutureResponse.java:42)
        at org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:75)
        at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1171)
        at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1548)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:465)
        at org.apache.activemq.pool.PooledProducer.send(PooledProducer.java:75)
        - locked <0x0000002b173fa480> (a org.apache.activemq.ActiveMQMessageProducer)
        at org.apache.activemq.pool.PooledProducer.send(PooledProducer.java:60)
        at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:537)
        at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:513)
        at org.springframework.jms.core.JmsTemplate$2.doInJms(JmsTemplate.java:479)
        at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:430)
        at org.springframework.jms.core.JmsTemplate.send(JmsTemplate.java:477)
        at lt.elitnet.dbp.das.impl.storage.HI2StorageImpl.storeHI2Message(HI2StorageImpl.java:57)
        at lt.elitnet.dbp.das.impl.hi2.HI2PersistanceBase.saveIRIContent(HI2PersistanceBase.java:77)
        at sun.reflect.GeneratedMethodAccessor185.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:203)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:162)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:104)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at lt.elitnet.dbp.das.impl.alarming.DataBaseConnectionAlarmsPublisher.invoke(DataBaseConnectionAlarmsPublisher.java:59)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:209)
        at $Proxy24.saveIRIContent(Unknown Source)
        at lt.elitnet.dbp.das.impl.hi2.HI2MessageListener.onMessage(HI2MessageListener.java:40)
        at lt.elitnet.dbp.commons.messaging.TextMessageListener.deliverMessage(TextMessageListener.java:84)
        at lt.elitnet.dbp.commons.messaging.TextMessageListener.onMessage(TextMessageListener.java:50)
        at org.springframework.jms.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:854)
        at org.springframework.jms.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:793)
        at org.springframework.jms.listener.AbstractMessageListenerContainer.doExecuteListener(AbstractMessageListenerContainer.java:763)
        at org.springframework.jms.listener.AbstractMessageListenerContainer.executeListener(AbstractMessageListenerContainer.java:743)
        at org.springframework.jms.listener.SimpleMessageListenerContainer$2.onMessage(SimpleMessageListenerContainer.java:190)
        at org.apache.activemq.ActiveMQMessageConsumer.dispatch(ActiveMQMessageConsumer.java:840)
        - locked <0x0000002b1771ddc0> (a java.lang.Object)
        at org.apache.activemq.ActiveMQSessionExecutor.dispatch(ActiveMQSessionExecutor.java:96)
        at org.apache.activemq.ActiveMQSessionExecutor.iterate(ActiveMQSessionExecutor.java:165)
        at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:111)
        at org.apache.activemq.thread.PooledTaskRunner.access$100(PooledTaskRunner.java:26)
        at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:44)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
 
"ActiveMQ Transport: tcp:///192.168.2.55:61616" prio=1 tid=0x0000002b2e814660 nid=0x4773 waiting for monitor entry [0x0000000040e82000..0x0000000040e82c30]
        at org.apache.activemq.MessageDispatchChannel.clear(MessageDispatchChannel.java:135)
        - waiting to lock <0x0000002b1771ddc0> (a java.lang.Object)
        at org.apache.activemq.ActiveMQMessageConsumer.clearMessagesInProgress(ActiveMQMessageConsumer.java:546)
        at org.apache.activemq.ActiveMQSession.clearMessagesInProgress(ActiveMQSession.java:524)
        at org.apache.activemq.ActiveMQConnection.transportInterupted(ActiveMQConnection.java:1547)
        at org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:100)
        at org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:100)
        at org.apache.activemq.transport.failover.FailoverTransport.handleTransportFailure(FailoverTransport.java:236)
        at org.apache.activemq.transport.failover.FailoverTransport.access$300(FailoverTransport.java:55)
        at org.apache.activemq.transport.failover.FailoverTransport$1.onException(FailoverTransport.java:120)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:96)
        at org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:147)
        at org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:150)
        at org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:97)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:150)
        at java.lang.Thread.run(Thread.java:595)

--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/activemq/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

       
Reply | Threaded
Open this post in threaded view
|

[jira] Resolved: (AMQ-1093) Client deadlock during failover

JIRA jira@apache.org
     [ https://issues.apache.org/activemq/browse/AMQ-1093?page=all ]

james strachan resolved AMQ-1093.
---------------------------------

    Fix Version/s: 4.2.0
       Resolution: Fixed

I've just committed a patch to trunk for this which I think resolves the issue.

There's no test case to easily verify its resolved though (its a tad hard to recreate) so I wonder could you try and see if this is now fixed - if not let us know and we can reopen this issue

> Client deadlock during failover
> -------------------------------
>
>                 Key: AMQ-1093
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1093
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Transport
>    Affects Versions: 4.1.0
>         Environment: Linux 2.6, java 1.5.0
>            Reporter: Danielius Jurna
>            Priority: Critical
>             Fix For: 4.2.0
>
>
> In 4.1.0 there's deadlock on connection failover. There is the scenario:
> 1. Client consumes message using message listener
> 2. Conection is lost
> 3. Client sends message to another queue from messagle listener and waits until connection is restored.
> 4. Reconnect task blocks on reconnecting.
>  
> This bug is new to 4.1.0. The problem is in ActiveMQMessageConsumre.dispatch . There is new lock on unconsumedMessages.getMutex() . So the reconnect task cannot invoke ActiveMQMessageConsumre.clearMessagesInProgress(), because lock is acquired by message listener, which waits untill message is sent (untill connection is resumed). Here is stack traces:
>  
> "ActiveMQ Session Task" daemon prio=1 tid=0x0000002b27774260 nid=0x4778 in Object.wait() [0x0000000040ef3000..0x0000000040ef4db0]
>         at java.lang.Object.wait(Native Method)
>         - waiting on <0x0000002b0020a7c8> (a edu.emory.mathcs.backport.java.util.concurrent.locks.CondVar)
>         at java.lang.Object.wait(Object.java:474)
>         at edu.emory.mathcs.backport.java.util.concurrent.locks.CondVar.await(CondVar.java:75)
>         - locked <0x0000002b0020a7c8> (a edu.emory.mathcs.backport.java.util.concurrent.locks.CondVar)
>         at edu.emory.mathcs.backport.java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:318)
>         at org.apache.activemq.transport.FutureResponse.getResult(FutureResponse.java:42)
>         at org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:75)
>         at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1171)
>         at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1548)
>         at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:465)
>         at org.apache.activemq.pool.PooledProducer.send(PooledProducer.java:75)
>         - locked <0x0000002b173fa480> (a org.apache.activemq.ActiveMQMessageProducer)
>         at org.apache.activemq.pool.PooledProducer.send(PooledProducer.java:60)
>         at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:537)
>         at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:513)
>         at org.springframework.jms.core.JmsTemplate$2.doInJms(JmsTemplate.java:479)
>         at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:430)
>         at org.springframework.jms.core.JmsTemplate.send(JmsTemplate.java:477)
>         at lt.elitnet.dbp.das.impl.storage.HI2StorageImpl.storeHI2Message(HI2StorageImpl.java:57)
>         at lt.elitnet.dbp.das.impl.hi2.HI2PersistanceBase.saveIRIContent(HI2PersistanceBase.java:77)
>         at sun.reflect.GeneratedMethodAccessor185.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>         at java.lang.reflect.Method.invoke(Method.java:585)
>         at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:203)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:162)
>         at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
>         at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:104)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
>         at lt.elitnet.dbp.das.impl.alarming.DataBaseConnectionAlarmsPublisher.invoke(DataBaseConnectionAlarmsPublisher.java:59)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
>         at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:209)
>         at $Proxy24.saveIRIContent(Unknown Source)
>         at lt.elitnet.dbp.das.impl.hi2.HI2MessageListener.onMessage(HI2MessageListener.java:40)
>         at lt.elitnet.dbp.commons.messaging.TextMessageListener.deliverMessage(TextMessageListener.java:84)
>         at lt.elitnet.dbp.commons.messaging.TextMessageListener.onMessage(TextMessageListener.java:50)
>         at org.springframework.jms.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:854)
>         at org.springframework.jms.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:793)
>         at org.springframework.jms.listener.AbstractMessageListenerContainer.doExecuteListener(AbstractMessageListenerContainer.java:763)
>         at org.springframework.jms.listener.AbstractMessageListenerContainer.executeListener(AbstractMessageListenerContainer.java:743)
>         at org.springframework.jms.listener.SimpleMessageListenerContainer$2.onMessage(SimpleMessageListenerContainer.java:190)
>         at org.apache.activemq.ActiveMQMessageConsumer.dispatch(ActiveMQMessageConsumer.java:840)
>         - locked <0x0000002b1771ddc0> (a java.lang.Object)
>         at org.apache.activemq.ActiveMQSessionExecutor.dispatch(ActiveMQSessionExecutor.java:96)
>         at org.apache.activemq.ActiveMQSessionExecutor.iterate(ActiveMQSessionExecutor.java:165)
>         at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:111)
>         at org.apache.activemq.thread.PooledTaskRunner.access$100(PooledTaskRunner.java:26)
>         at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:44)
>         at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Thread.java:595)
>  
> "ActiveMQ Transport: tcp:///192.168.2.55:61616" prio=1 tid=0x0000002b2e814660 nid=0x4773 waiting for monitor entry [0x0000000040e82000..0x0000000040e82c30]
>         at org.apache.activemq.MessageDispatchChannel.clear(MessageDispatchChannel.java:135)
>         - waiting to lock <0x0000002b1771ddc0> (a java.lang.Object)
>         at org.apache.activemq.ActiveMQMessageConsumer.clearMessagesInProgress(ActiveMQMessageConsumer.java:546)
>         at org.apache.activemq.ActiveMQSession.clearMessagesInProgress(ActiveMQSession.java:524)
>         at org.apache.activemq.ActiveMQConnection.transportInterupted(ActiveMQConnection.java:1547)
>         at org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:100)
>         at org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:100)
>         at org.apache.activemq.transport.failover.FailoverTransport.handleTransportFailure(FailoverTransport.java:236)
>         at org.apache.activemq.transport.failover.FailoverTransport.access$300(FailoverTransport.java:55)
>         at org.apache.activemq.transport.failover.FailoverTransport$1.onException(FailoverTransport.java:120)
>         at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:96)
>         at org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:147)
>         at org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:150)
>         at org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:97)
>         at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:150)
>         at java.lang.Thread.run(Thread.java:595)

--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/activemq/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira