[JBoss-user] Deadlock following rollout to 3.2.2 (RC2 or RC3)

[Stephane Nicoll]

Hi,

Our application runs 'fine' on JBoss 3.2.1 using intensively JMS and Entity beans in CMP mode. I tried to rollout this application on both 3.2.2 RC2 and RC3 but we have deadlocks very quickly.

I don't know exactly what kind of information is relevant. Could you please, in a first stage, help me figuring out what could be relevant? Anyway It seems that the deadlock occurs on read only data! (I mean read only in our mind but maybe not declared as read only)

The part of the application which crashes is quite simple.

An MBean pools a directory containing XML file and sends one TextMessage per XML file to a queue. Then an MDB proceses the TextMessage, translate the XML into an instruction and create an entity. An entity has some link to other entity so the MDB makes sure those link (id) refers to existing entities (theses are the read only stuff)

With RC2 deadlock occurs after 5 min of load:

2003-08-20 16:36:39,827 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=10
2003-08-20 16:37:06,132 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=354
2003-08-20 16:37:15,677 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=1
2003-08-20 16:37:45,228 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=31999996
2003-08-20 16:37:49,308 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=1
2003-08-20 16:37:54,480 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=1fc48af1c0a8062100476e345d7090a8
2003-08-20 16:38:00,548 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=1
2003-08-20 16:38:02,328 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=9980001
2003-08-20 16:38:11,878 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=1
2003-08-20 16:38:19,818 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=NL
2003-08-20 16:40:39,076 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=9980001
2003-08-20 16:40:39,076 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=31999996
2003-08-20 16:40:39,080 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=NL
2003-08-20 16:40:39,082 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=31999996
2003-08-20 16:40:39,120 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=1
2003-08-20 16:40:39,121 WARN  [org.jboss.ejb.plugins.AbstractInstanceCache] Unable to passivate due to ctx lock, id=9980001

where 9980001 is the ID of an existing entity (DSP), 31999996 the ID of another existing entity (KP) and NL the ID of one existing Language entity.

With RC3 deadlock occurs at the very start of the processing:

2003-08-26 11:43:47,412 ERROR [com.kiala.kialapointserver.jms.AdminMDB] Could not process admin instruction [Create [translation] instruction].
com.kiala.kialapointserver.admin.processor.ProcessorException: Remote error [Application deadlock detected]
Caused by: org.jboss.util.deadlock.ApplicationDeadlockException: Application deadlock detected
at org.jboss.util.deadlock.DeadlockDetector.deadlockDetection(DeadlockDetector.java:45)
at org.jboss.ejb.plugins.lock.QueuedPessimisticEJBLock.waitForTx(QueuedPessimisticEJBLock.java:276)
at org.jboss.ejb.plugins.lock.QueuedPessimisticEJBLock.doSchedule(QueuedPessimisticEJBLock.java:212)
at org.jboss.ejb.plugins.lock.QueuedPessimisticEJBLock.schedule(QueuedPessimisticEJBLock.java:159)
at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:85)
at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:53)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:320)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:118)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:490)
at org.jboss.ejb.Container.invoke(Container.java:700)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:353)
at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:38)
at $Proxy332.getValueAfterIncrementingBy(Unknown Source)
at com.kiala.kialapointserver.entity.SequenceSessionBean.getNextSequenceNumber(SequenceSessionBean.java:98)
at com.kiala.kialapointserver.entity.SequenceSessionBean.getNextSequenceNumber(SequenceSessionBean.java:50)
at sun.reflect.GeneratedMethodAccessor104.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:118)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
at org.jboss.ejb.Container.invoke(Container.java:700)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:353)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:83)
at $Proxy331.getNextSequenceNumber(Unknown Source)
at com.kiala.kialapointserver.entity.TranslationBean.ejbCreate(TranslationBean.java:297)
at sun.reflect.GeneratedMethodAccessor103.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.ejb.plugins.CMPPersistenceManager.createEntity(CMPPersistenceManager.java:188)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.createEntity(CachedConnectionInterceptor.java:270)
at org.jboss.ejb.EntityContainer.createLocalHome(EntityContainer.java:580)
at sun.reflect.GeneratedMethodAccessor85.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.ejb.EntityContainer$ContainerInterceptor.invokeHome(EntityContainer.java:1042)
at org.jboss.ejb.plugins.AbstractInterceptor.invokeHome(AbstractInterceptor.java:88)
at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invokeHome(EntitySynchronizationInterceptor.java:188)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invokeHome(CachedConnectionInterceptor.java:215)
at org.jboss.ejb.plugins.AbstractInterceptor.invokeHome(AbstractInterceptor.java:88)
at org.jboss.ejb.plugins.EntityInstanceInterceptor.invokeHome(EntityInstanceInterceptor.java:91)
at org.jboss.ejb.plugins.EntityLockInterceptor.invokeHome(EntityLockInterceptor.java:61)
at org.jboss.ejb.plugins.EntityCreationInterceptor.invokeHome(EntityCreationInterceptor.java:28)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:88)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
at org.jboss.ejb.plugins.TxInterceptorCMT.invokeHome(TxInterceptorCMT.java:98)
at org.jboss.ejb.plugins.SecurityInterceptor.invokeHome(SecurityInterceptor.java:92)
at org.jboss.ejb.plugins.LogInterceptor.invokeHome(LogInterceptor.java:120)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invokeHome(ProxyFactoryFinderInterceptor.java:93)
at org.jboss.ejb.EntityContainer.internalInvokeHome(EntityContainer.java:484)
at org.jboss.ejb.Container.invoke(Container.java:720)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invokeHome(BaseLocalProxyFactory.java:272)
at org.jboss.ejb.plugins.local.LocalHomeProxy.invoke(LocalHomeProxy.java:110)
at $Proxy150.create(Unknown Source)
at com.kiala.kialapointserver.entity.facades.TranslationFacadeEJB.create(TranslationFacadeEJB.java:175)
at com.kiala.kialapointserver.entity.facades.TranslationFacadeEJB.create(TranslationFacadeEJB.java:226)
at sun.reflect.GeneratedMethodAccessor100.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:118)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
at org.jboss.ejb.Container.invoke(Container.java:700)
at sun.reflect.GeneratedMethodAccessor84.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:546)
at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:101)
at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:90)
at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:45)
at org.jboss.proxy.ejb.StatelessSessionInterceptor.invoke(StatelessSessionInterceptor.java:100)
at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:85)
at $Proxy275.create(Unknown Source)
at com.kiala.kialapointserver.admin.processor.TranslationInstructionProcessor.createEntity(TranslationInstructionProcessor.java:66)
... 44 more
2003-08-26 11:43:47,425 ERROR [org.jboss.ejb.BeanLock] Saw rolled back tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=biohazard.dev.kiala.com//75, BranchQual=]
2003-08-26 11:43:47,426 ERROR [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackLocalException in method: public abstract com.kiala.kialapointserver.entity.interfaces.CountryValue com.kiala.kialapointserver.entity.interfaces.CountryLocal.getCountryValue(), causedBy:
java.lang.RuntimeException: Transaction marked for rollback, possibly a timeout
at org.jboss.ejb.plugins.lock.QueuedPessimisticEJBLock.doSchedule(QueuedPessimisticEJBLock.java:204)
at org.jboss.ejb.plugins.lock.QueuedPessimisticEJBLock.schedule(QueuedPessimisticEJBLock.java:159)
at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:85)
at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:53)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:118)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:490)
at org.jboss.ejb.Container.invoke(Container.java:700)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:353)
at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:38)
at $Proxy329.getCountryValue(Unknown Source)
at com.kiala.kialapointserver.admin.processor.AbstractInstructionProcessor.getCountry(AbstractInstructionProcessor.java:219)
at com.kiala.kialapointserver.admin.processor.TranslationInstructionProcessor.setValueObject(TranslationInstructionProcessor.java:180)
at com.kiala.kialapointserver.admin.processor.TranslationInstructionProcessor.createEntity(TranslationInstructionProcessor.java:62)
at com.kiala.kialapointserver.admin.processor.AbstractInstructionProcessor.processInstruction(AbstractInstructionProcessor.java:40)
at com.kiala.kialapointserver.admin.AdminInstructionProcessorBean.processInstruction(AdminInstructionProcessorBean.java:60)
at sun.reflect.GeneratedMethodAccessor87.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:118)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
at org.jboss.ejb.Container.invoke(Container.java:700)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:353)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:83)
at $Proxy316.processInstruction(Unknown Source)
at com.kiala.kialapointserver.jms.AdminMDB.onMessage(AdminMDB.java:143)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.jboss.ejb.MessageDrivenContainer$ContainerInterceptor.invoke(MessageDrivenContainer.java:460)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
at org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:62)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:267)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
at org.jboss.ejb.plugins.RunAsSecurityInterceptor.invoke(RunAsSecurityInterceptor.java:90)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.MessageDrivenContainer.internalInvoke(MessageDrivenContainer.java:374)
at org.jboss.ejb.Container.invoke(Container.java:700)
at org.jboss.ejb.plugins.jms.JMSContainerInvoker.invoke(JMSContainerInvoker.java:827)
at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1117)
at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:256)
at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:633)
at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:433)
at org.jboss.mq.SpySession.run(SpySession.java:298)
at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:180)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:732)
at java.lang.Thread.run(Thread.java:536)


Sory for the long stacktrace. If you need additional info, please ask!

Thanks,

Stéphane Nicoll