Problems while upgrading to JBossCache1.2.4

[jaikiran]

Hi,
We have an J2EE application in JBoss-3.2.3, which uses Hibernate as a MBean. The version of Hibernate that we are using is 2.1.3. Till sometime back we were using JBossCache1.2 with Hibernate.

Our application has several SLSB(with container managed transactions) which give a call to Persistence manager which internally uses the Hibernate service to do any database operations like save,update,delete etc... We have enabled second level cache in Hibernate. The application was running fine(except for some frequent cache locking issues because of PESSIMISTIC locking)

Some days back we shifted from JBossCache1.2 to JBossCache1.2.4, to avoid some cache locking issues that we were facing because of PESSIMISTIC locking.

We have specified OPTIMISTIC locking for JBossCache1.2.4 in our config files. Now all of a sudden we are seeing the following exception being thrown in the application:

16:10:18,330 WARN [OptimisticTxInterceptor] runPreparePhase() failed. Transaction is marked as rolled back
org.jboss.cache.CacheException: unable to validate nodes
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.validateNodes(OptimisticValidatorInterceptor.java:115)
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(OptimisticValidatorInterceptor.java:70)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
 at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:87)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor.handleLocalPrepare(OptimisticTxInterceptor.java:262)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor.access$000(OptimisticTxInterceptor.java:30)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor$SynchronizationHandler.beforeCompletion(OptimisticTxInterceptor.java:600)
 at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:72)
 at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1308)
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:347)
 at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:398)
 at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:277)
 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:375)
 at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:83)
 at $Proxy159.getByObjectId(Unknown Source)
 at com.dbdata.processingengine.hibernateobject.CrExecutionList.getComponent(CrExecutionList.java:415)
 at com.dbdata.analysis.customerbehavioranalysis.processingengine.GenerateAndRunSQLForCustomerBehaviorAnalysis.execute(GenerateAndRunSQLForCustomerBehaviorAnalysis.java:90)
 at com.dbdata.processingengine.TaskNode.execute(TaskNode.java:85)
 at com.dbdata.processingengine.SequenceExecutionController.executeProcessingSequence(SequenceExecutionController.java:144)
 at com.dbdata.processingengine.ejb.ProcessingEngineParallelExecutorMDBean.onMessage(ProcessingEngineParallelExecutorMDBean.java:116)
 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:185)
 at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
 at org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:144)
 at org.jboss.ejb.plugins.MessageDrivenTxInterceptorBMT.invoke(MessageDrivenTxInterceptorBMT.java:32)
 at org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:62)
 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:824)
 at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1114)
 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:727)
 at java.lang.Thread.run(Thread.java:534)
16:10:31,404 INFO [OptimisticNodeInterceptor] read Method _evict(/com/teradata/tap/system/folder/FolderService#SecurityNS/8acd4600078dfeaf01078e07d4d20001/tap/admin/FSPCKP#FOLDER/PERM/TYPE) called -
don't know how to handle, passing on!
16:10:31,404 INFO [OptimisticNodeInterceptor] read Method _evict(/com/teradata/tap/system/folder/FolderService#SecurityNS/FSECK) called - don't know how to handle, passing on!
16:11:05,982 ERROR [LogInterceptor] TransactionRolledbackLocalException in method: public abstract com.dbdata.tap.component.TAPIdentifierInterface com.dbdata.businessinterface.CRMProviderBusin
essInterface.getByObjectId(java.lang.String,java.lang.Class,java.lang.Object) throws com.dbdata.tap.system.beansupport.TAPComponentException, causedBy:
org.jboss.tm.JBossRollbackException: Unable to commit, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=ps2944//3683, BranchQual=] status=STATUS_NO_TRANSACTION; - nested throwable: (org.jboss.util.N
estedRuntimeException: ; - nested throwable: (org.jboss.cache.CacheException: unable to validate nodes))
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:413)
 at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:398)
 at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:277)
 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:375)
 at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:83)
 at $Proxy159.getByObjectId(Unknown Source)
 at com.dbdata.processingengine.hibernateobject.CrExecutionList.getComponent(CrExecutionList.java:415)
 at com.dbdata.analysis.customerbehavioranalysis.processingengine.GenerateAndRunSQLForCustomerBehaviorAnalysis.execute(GenerateAndRunSQLForCustomerBehaviorAnalysis.java:90)
 at com.dbdata.processingengine.TaskNode.execute(TaskNode.java:85)
 at com.dbdata.processingengine.SequenceExecutionController.executeProcessingSequence(SequenceExecutionController.java:144)
 at com.dbdata.processingengine.ejb.ProcessingEngineParallelExecutorMDBean.onMessage(ProcessingEngineParallelExecutorMDBean.java:116)
 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:185)
 at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
 at org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:144)
 at org.jboss.ejb.plugins.MessageDrivenTxInterceptorBMT.invoke(MessageDrivenTxInterceptorBMT.java:32)
 at org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:62)
 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:824)
 at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1114)
 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:727)
 at java.lang.Thread.run(Thread.java:534)
Caused by: org.jboss.util.NestedRuntimeException: ; - nested throwable: (org.jboss.cache.CacheException: unable to validate nodes)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor$SynchronizationHandler.beforeCompletion(OptimisticTxInterceptor.java:631)
 at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:72)
 at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1308)
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:347)
 ... 40 more
Caused by: org.jboss.cache.CacheException: unable to validate nodes
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.validateNodes(OptimisticValidatorInterceptor.java:115)
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(OptimisticValidatorInterceptor.java:70)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
 at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:87)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor.handleLocalPrepare(OptimisticTxInterceptor.java:262)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor.access$000(OptimisticTxInterceptor.java:30)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor$SynchronizationHandler.beforeCompletion(OptimisticTxInterceptor.java:600)
 ... 43 more
16:11:06,060 INFO [TaskNode] Task: null failed
16:11:06,060 INFO [SequenceExecutionController] Task: null failed
16:11:06,060 ERROR [SequenceExecutionController] Exception during executing Task: null
16:11:06,060 ERROR [SequenceExecutionController] org.jboss.tm.JBossTransactionRolledbackLocalException: null; CausedByException is:
 Unable to commit, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=ps2944//3683, BranchQual=] status=STATUS_NO_TRANSACTION; - nested throwable: (org.jboss.util.NestedRuntimeException: ; - ne
sted throwable: (org.jboss.cache.CacheException: unable to validate nodes)); - nested throwable: (org.jboss.tm.JBossRollbackException: Unable to commit, tx=TransactionImpl:XidImpl [FormatId=257, Globa
lId=ps2944//3683, BranchQual=] status=STATUS_NO_TRANSACTION; - nested throwable: (org.jboss.util.NestedRuntimeException: ; - nested throwable: (org.jboss.cache.CacheException: unable to validate nodes
)))
 at org.jboss.ejb.plugins.TxInterceptorCMT.throwJBossException(TxInterceptorCMT.java:485)
 at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:403)
 at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:277)
 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:375)
 at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:83)
 at $Proxy159.getByObjectId(Unknown Source)
 at com.dbdata.processingengine.hibernateobject.CrExecutionList.getComponent(CrExecutionList.java:415)
 at com.dbdata.analysis.customerbehavioranalysis.processingengine.GenerateAndRunSQLForCustomerBehaviorAnalysis.execute(GenerateAndRunSQLForCustomerBehaviorAnalysis.java:90)
 at com.dbdata.processingengine.TaskNode.execute(TaskNode.java:85)
 at com.dbdata.processingengine.SequenceExecutionController.executeProcessingSequence(SequenceExecutionController.java:144)
 at com.dbdata.processingengine.ejb.ProcessingEngineParallelExecutorMDBean.onMessage(ProcessingEngineParallelExecutorMDBean.java:116)
 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:185)
 at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
 at org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:144)
 at org.jboss.ejb.plugins.MessageDrivenTxInterceptorBMT.invoke(MessageDrivenTxInterceptorBMT.java:32)
 at org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:62)
 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:824)
 at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1114)
 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:727)
 at java.lang.Thread.run(Thread.java:534)
Caused by: org.jboss.tm.JBossRollbackException: Unable to commit, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=ps2944//3683, BranchQual=] status=STATUS_NO_TRANSACTION; - nested throwable: (org.j
boss.util.NestedRuntimeException: ; - nested throwable: (org.jboss.cache.CacheException: unable to validate nodes))
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:413)
 at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:398)
 ... 39 more
Caused by: org.jboss.util.NestedRuntimeException: ; - nested throwable: (org.jboss.cache.CacheException: unable to validate nodes)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor$SynchronizationHandler.beforeCompletion(OptimisticTxInterceptor.java:631)
 at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:72)
 at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1308)
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:347)
 ... 40 more
Caused by: org.jboss.cache.CacheException: unable to validate nodes
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.validateNodes(OptimisticValidatorInterceptor.java:115)
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(OptimisticValidatorInterceptor.java:70)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
 at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:87)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor.handleLocalPrepare(OptimisticTxInterceptor.java:262)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor.access$000(OptimisticTxInterceptor.java:30)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor$SynchronizationHandler.beforeCompletion(OptimisticTxInterceptor.java:600)
 ... 43 more
org.jboss.tm.JBossRollbackException: Unable to commit, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=ps2944//3683, BranchQual=] status=STATUS_NO_TRANSACTION; - nested throwable: (org.jboss.util.N
estedRuntimeException: ; - nested throwable: (org.jboss.cache.CacheException: unable to validate nodes))
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:413)
 at org.jboss.ejb.plugins.TxInterceptorCMT.endTransaction(TxInterceptorCMT.java:398)
 at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:277)
 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:375)
 at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:83)
 at $Proxy159.getByObjectId(Unknown Source)
 at com.dbdata.processingengine.hibernateobject.CrExecutionList.getComponent(CrExecutionList.java:415)
 at com.dbdata.analysis.customerbehavioranalysis.processingengine.GenerateAndRunSQLForCustomerBehaviorAnalysis.execute(GenerateAndRunSQLForCustomerBehaviorAnalysis.java:90)
 at com.dbdata.processingengine.TaskNode.execute(TaskNode.java:85)
 at com.dbdata.processingengine.SequenceExecutionController.executeProcessingSequence(SequenceExecutionController.java:144)
 at com.dbdata.processingengine.ejb.ProcessingEngineParallelExecutorMDBean.onMessage(ProcessingEngineParallelExecutorMDBean.java:116)
 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:185)
 at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
 at org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:144)
 at org.jboss.ejb.plugins.MessageDrivenTxInterceptorBMT.invoke(MessageDrivenTxInterceptorBMT.java:32)
 at org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:62)
 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:824)
 at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1114)
 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:727)
 at java.lang.Thread.run(Thread.java:534)
Caused by: org.jboss.util.NestedRuntimeException: ; - nested throwable: (org.jboss.cache.CacheException: unable to validate nodes)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor$SynchronizationHandler.beforeCompletion(OptimisticTxInterceptor.java:631)
 at org.jboss.cache.interceptors.OrderedSynchronizationHandler.beforeCompletion(OrderedSynchronizationHandler.java:72)
 at org.jboss.tm.TransactionImpl.doBeforeCompletion(TransactionImpl.java:1308)
 at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:347)
 ... 40 more
Caused by: org.jboss.cache.CacheException: unable to validate nodes
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.validateNodes(OptimisticValidatorInterceptor.java:115)
 at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(OptimisticValidatorInterceptor.java:70)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
 at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:87)
 at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:41)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor.handleLocalPrepare(OptimisticTxInterceptor.java:262)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor.access$000(OptimisticTxInterceptor.java:30)
 at org.jboss.cache.interceptors.OptimisticTxInterceptor$SynchronizationHandler.beforeCompletion(OptimisticTxInterceptor.java:600)
 ... 43 more

We also see a lot of these messages being displayed just before the exception:

INFO [OptimisticNodeInterceptor] read Method _evict(//com/dbdata/metadata/hibernateobject/CrDivision) called - don't know how to handle, passing on!
INFO [OptimisticNodeInterceptor] read Method _evict(//com/dbdata/metadata/hibernateobject/CrDivision/com.teradata.crm.metadata.hibernateobject.CrDivisionId@16e3a7e[divisionId=1,divisionVersionId=1]) called - don't know how to handle, passing on!

I saw an post on this forum by "DashV", which talks about the same. So, my questions regarding this are:

1) Is this case similar to the one mentioned by "DashV" at:

http://www.jboss.org/index.html?module=bb&op=viewtopic&t=71394&postdays=0&postorder=asc&start=0

2) If yes, is my appplication required to catch these exceptions and do appropriate action(again, what would be an approproiate action in this case)? P.S.: Since my SLSB are having container managed transactions, i am never dealing with transactions in my code. So, if at all i have to handle these exceptions in our code, is this the appropriate thing to do?

3) Are there any known operations that are going to result in these exceptions(so that our code can handle only those cases).

4) If the answer to the question 3 is NO, then do we have to handle these exception in each method in the SLSB, that does a database operation through Hibernate?

5) And finally, if at all our code is to handle these exceptions, what would the appropriate action be? Re-invoke the same operation again?

I hope that someone answers these questions.
Thank you.

[manik]

Hi.

Re: the "Method _evict" messages you see, ignore these. The NodeInterceptor should not deal with _evict calls, this should be TRACE level logging, not INFO.

You're correct, this is very similar to the discussion thread started by DashV. If you read through my comments on that thread, you'll see that the problem relly has to do with concurrent updates on a cached node. With optimistic locking, when this happens, the cache throws a rollback exception when you try and commit the tx. This is normal behaviour.

I presume that these exceptions are fairly infrequent?

Cheers,
Manik

[jaikiran]

Hi Manik,
First of all, thanks for the reply.

I presume that these exceptions are fairly infrequent?

The CacheException that i am seeing is VERY FREQUENT.

We even tried out a few things, to try and find out the issue. In our configurations we changed the "maxNodes" attribute value to 10000 from the initial 5000, in the EvictionPolicyConfig. We also changed the implementation of the toString( ) method of the composite id classes of our hibernate objects. After these changes the application started working.
We tried out executing 3-4 times and it worked.
But, let me not jump to any conclusions.

I am NOT sure whether these are related. You may be a better person to tell, whether these config settings and the implementation of the toString( )
method, has anything to do with the CacheException.

We are still trying out a few things, to see whether these changes affect the application.

[manik]

First, I hope you understand that optimistic locking in 1.2.4 is an ALPHA release and is full of bugs! :)

Optimistic locking in 1.3 has a lot of new fixes which will help solve these issues.

The specific problem you see is due to node eviction. A node is evicted, and ongoing transactions try and commit and fail due to incompatible node versioning. This is why you see things improve when you increase the maxNodes setting, because eviction doesn't occur as frequently then.

This problem will be solved in future versions of JBossCache and Hibernate when we expose our versioning API to Hibernate and Hibernate pulls version info from the database directly. This will allow for proper validation even after a node has been evicted.

For now, there is little I can recommend except:

1) Don't use opt locking in 1.2.4 in production!
2) Increase the maxNodes setting. Or even remove the eviction policy if it is not critical. Or use an LRU eviction policy so nodes that are unlikely to be used again get evicted, minimising the possibility of this happening.

Thanks for trying this out though, it is great to see feedback on this. Optimistic locking is a major feature of 1.3 and we'd like to learn as much as we can from what we released in 1.2.4.

Cheers,
Manik

[jaikiran]

Thanks Manik, for those replies. Will try out your suggestions.

-Jaikiran