[jboss-user] [JBoss Cache Users] - bulkUpdate - could not release cache lock
jbosscacheuser1
do-not-reply at jboss.com
Wed Oct 14 11:46:57 EDT 2009
Hi,
We are using Hibernate-3.3.2 and JBossCache-3.1.0. We are running into issues on bulk update, the operation runs longer time trying, to acquire locks on the nodes. The issue happens only in Websphere 6.1 and now issues with the bulk update in JBoss.
1. The hibernate session is flushed on the transaction synchronization
( Flushing Hibernate Session on transaction synchronization)
2. Acquiring write locks on all nodes (commit is issued, prepare phase is entered which locks all the nodes in the workspace and validates that all changes can be applied to the cache itself).
3. Acquired write locks on nodes. Validating nodes completed (example: Validating 74 nodes).
4. If nodes are validated then a commit is invoked - this applies the changes and unlocks all the locks acquired in the prepare. (I guess this is where we are running into issues, the locks are not freed up on successful validation. )
5. RemoveNodeCommand is Issued. (This happens in a separate transaction; created new GTX: GlobalTransaction:<10.10.21.72:33898>:6849)
6. Acquiring lock failure from item 5 above with below message
(failure acquiring lock: fqn=/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY
caller=GlobalTransaction:<10.10.21.72:33898>:6849, lock=write owner=GlobalTransaction:<10.10.21.72:33898>:6847)
8. There are several tries to acquire locks on several nodes above on the RemoveNodeCommad for at least, 10 minutes
9. Original transaction started is commited
(calling aftercompletion for GlobalTransaction:<10.10.21.72:33898>:6847
Running commit phase. One phase? False
Running commit for GlobalTransaction:<10.10.21.72:33898>:6847
Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<10.10.21.72:33898>:6847
10.The write locks are released (after the transaction complete) finally.
Below are the logs.
DEBUG 1179976 [WebContainer : 2] (org.hibernate.SQL) 2009-10-08 09:52:29,775 - delete from BILL_OF_WORK where BILL_OF_WORK_ID=?
DEBUG 1180035 [WebContainer : 2] (org.springframework.orm.hibernate3.HibernateTemplate) 2009-10-08 09:52:29,834 - Not closing pre-bound Hibernate Session after HibernateTemplate
DEBUG 1180038 [WebContainer : 2] (org.springframework.orm.hibernate3.SessionFactoryUtils) 2009-10-08 09:52:29,837 - Flushing Hibernate Session on transaction synchronization
TRACE 1180044 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,843 - Running beforeCompletion on gtx GlobalTransaction:<10.10.21.72:33898>:6847
DEBUG 1180045 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticLockingInterceptor) 2009-10-08 09:52:29,844 - Locking nodes in transaction workspace for GlobalTransaction GlobalTransaction:<10.10.21.72:33898>:6847
(org.jboss.cache.lock.IdentityLock) 2009-10-08 09:52:29,853 - acquiring WL: fqn=/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY, caller=GlobalTransaction:<10.10.21.72:33898>:6847, lock=
TRACE 1180054 [WebContainer : 2] (org.jboss.cache.lock.IdentityLock) 2009-10-08 09:52:29,853 - acquired WL: fqn=/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY, caller=GlobalTransaction:<10.10.21.72:33898>:6847, lock=write owner=GlobalTransaction:<10.10.21.72:33898>:6847
TRACE 1180054 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticLockingInterceptor) 2009-10-08 09:52:29,853 - Acquired lock on node /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY
TRACE 1180053 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticLockingInterceptor) 2009-10-08 09:52:29,852 - Acquired lock on node /
DEBUG 1180064 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticValidatorInterceptor) 2009-10-08 09:52:29,863 - Validating 74 nodes.
(org.jboss.cache.interceptors.OptimisticValidatorInterceptor) 2009-10-08 09:52:29,864 - Node [/fleetcycle/domain/billing/invoicing/InvoiceStatus] doesn't need validating as it isn't dirty
TRACE 1180067 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticValidatorInterceptor) 2009-10-08 09:52:29,866 - Validating version for node [/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY]
TRACE 1180067 [WebContainer : 2] (org.jboss.cache.DataContainerImpl) 2009-10-08 09:52:29,866 - peek /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY, includeDeletedNodes:true, includeInvalidNodes:true
DEBUG 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticValidatorInterceptor) 2009-10-08 09:52:29,867 - Successfully validated nodes
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.CallInterceptor) 2009-10-08 09:52:29,867 - Suppressing invocation of method handleOptimisticPrepareCommand.
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,867 - Setting up transactional context.
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,867 - Setting tx as null and gtx as null
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,867 - Running beforeCompletion on gtx GlobalTransaction:<10.10.21.72:33898>:6848
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,867 - Setting up transactional context.
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,867 - Setting tx as com.ibm.ws.Transaction.JTA.TransactionImpl at 45bb45bb#tid=7417 and gtx as GlobalTransaction:<10.10.21.72:33898>:6848
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.factories.ComponentRegistry) 2009-10-08 09:52:29,867 - Testing if invocations are allowed.
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,867 - Setting up transactional context.
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,867 - Setting tx as com.ibm.ws.Transaction.JTA.TransactionImpl at 45bb45bb#tid=7417 and gtx as GlobalTransaction:<10.10.21.72:33898>:6848
TRACE 1180068 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,867 - No modifications in this tx. Skipping beforeCompletion()
TRACE 1180070 [WebContainer : 2] (org.jboss.cache.factories.ComponentRegistry) 2009-10-08 09:52:29,869 - Testing if invocations are allowed.
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.interceptors.InvocationContextInterceptor) 2009-10-08 09:52:29,870 - Invoked with command RemoveNodeCommand{fqn=/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=org.hibernate.cache.jbc2.util.NonLockingDataVersion at 230b230b, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false, suppressPersistence=false, suppressEventNotification=false}, originLocal=true, bypassUnmarshalling=false}]
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.interceptors.InvocationContextInterceptor) 2009-10-08 09:52:29,870 - Setting up transactional context.
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.interceptors.InvocationContextInterceptor) 2009-10-08 09:52:29,870 - Setting tx as null and gtx as null
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,870 - Creating transaction for thread Thread[WebContainer : 2,5,main]
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,870 - local transaction exists - registering global tx if not present for Thread[WebContainer : 2,5,main]
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,870 - Associated gtx in txTable is null
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.transaction.TransactionTable) 2009-10-08 09:52:29,870 - created new GTX: GlobalTransaction:<10.10.21.72:33898>:6849, local TX=com.ibm.ws.Transaction.JTA.TransactionImpl at 617e617e#tid=7418
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,870 - Registering sync handler for tx com.ibm.ws.Transaction.JTA.TransactionImpl at 617e617e#tid=7418, gtx GlobalTransaction:<10.10.21.72:33898>:6849
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:29,870 - registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<10.10.21.72:33898>:6849, tx=com.ibm.ws.Transaction.JTA.TransactionImpl at 1635672446))
TRACE 1180071 [WebContainer : 2] (org.jboss.cache.DataContainerImpl) 2009-10-08 09:52:29,870 - peek /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY, includeDeletedNodes:true, includeInvalidNodes:true
TRACE 1180072 [WebContainer : 2] (org.jboss.cache.lock.IdentityLock) 2009-10-08 09:52:29,871 - acquiring RL: fqn=/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY, caller=GlobalTransaction:<10.10.21.72:33898>:6849, lock=write owner=GlobalTransaction:<10.10.21.72:33898>:6847
TRACE 1195074 [WebContainer : 2] (org.jboss.cache.lock.IdentityLock) 2009-10-08 09:52:44,873 - read lock for /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY could not be acquired by GlobalTransaction:<10.10.21.72:33898>:6849 after 15000 ms. Locks: Read lock owners: []
Write lock owner: GlobalTransaction:<10.10.21.72:33898>:6847
, lock info: write owner=GlobalTransaction:<10.10.21.72:33898>:6847 (activeReaders=0, activeWriter=Thread[WebContainer : 2,5,main], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
TRACE 1195075 [WebContainer : 2] (org.jboss.cache.lock.IdentityLock) 2009-10-08 09:52:44,874 - failure acquiring lock: fqn=/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY, caller=GlobalTransaction:<10.10.21.72:33898>:6849, lock=write owner=GlobalTransaction:<10.10.21.72:33898>:6847 (activeReaders=0, activeWriter=Thread[WebContainer : 2,5,main], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
WARN 1195075 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 09:52:44,874 - Rolling back, exception encountered
org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY, caller=GlobalTransaction:<10.10.21.72:33898>:6849, lock=write owner=GlobalTransaction:<10.10.21.72:33898>:6847 (activeReaders=0, activeWriter=Thread[WebContainer : 2,5,main], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:534)
at org.jboss.cache.lock.NodeBasedLockManager.acquireLock(NodeBasedLockManager.java:87)
at org.jboss.cache.lock.NodeBasedLockManager.lock(NodeBasedLockManager.java:117)
at org.jboss.cache.interceptors.OptimisticInterceptor.lockAndCreateWorkspaceNode(OptimisticInterceptor.java:134)
at org.jboss.cache.interceptors.OptimisticNodeInterceptor.fetchWorkspaceNode(OptimisticNodeInterceptor.java:583)
at org.jboss.cache.interceptors.OptimisticNodeInterceptor.visitRemoveNodeCommand(OptimisticNodeInterceptor.java:103)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.EvictionInterceptor.visitRemoveNodeCommand(EvictionInterceptor.java:223)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
at org.jboss.cache.commands.AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
at org.jboss.cache.commands.AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
at org.jboss.cache.commands.AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.InvalidationInterceptor.handleWriteMethod(InvalidationInterceptor.java:241)
at org.jboss.cache.interceptors.InvalidationInterceptor.visitRemoveNodeCommand(InvalidationInterceptor.java:125)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
at org.jboss.cache.commands.AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.TxInterceptor.attachGtxAndPassUpChain(TxInterceptor.java:301)
at org.jboss.cache.interceptors.OptimisticTxInterceptor.handleDefault(OptimisticTxInterceptor.java:83)
at org.jboss.cache.commands.AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
at org.jboss.cache.commands.AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.jboss.cache.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:178)
at org.jboss.cache.interceptors.InvocationContextInterceptor.visitRemoveNodeCommand(InvocationContextInterceptor.java:88)
at org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
at org.jboss.cache.interceptors.InterceptorChain.invoke(InterceptorChain.java:287)
at org.jboss.cache.invocation.CacheInvocationDelegate.removeNode(CacheInvocationDelegate.java:478)
at org.hibernate.cache.jbc2.util.CacheHelper.removeAll(CacheHelper.java:378)
at org.hibernate.cache.jbc2.access.OptimisticTransactionalAccessDelegate.evictOrRemoveAll(OptimisticTransactionalAccessDelegate.java:172)
at org.hibernate.cache.jbc2.access.OptimisticTransactionalAccessDelegate.evictAll(OptimisticTransactionalAccessDelegate.java:80)
at org.hibernate.cache.jbc2.entity.TransactionalAccess.evictAll(TransactionalAccess.java:102)
at org.hibernate.impl.SessionFactoryImpl.evictEntity(SessionFactoryImpl.java:918)
at org.hibernate.action.BulkOperationCleanupAction.evictEntityRegions(BulkOperationCleanupAction.java:153)
at org.hibernate.action.BulkOperationCleanupAction.afterTransactionCompletion(BulkOperationCleanupAction.java:132)
at org.hibernate.engine.ActionQueue.afterTransactionCompletion(ActionQueue.java:198)
at org.hibernate.impl.SessionImpl.afterTransactionCompletion(SessionImpl.java:452)
at org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:252)
at org.hibernate.transaction.CacheSynchronization.afterCompletion(CacheSynchronization.java:117)
at com.ibm.ws.Transaction.JTA.RegisteredSyncs.distributeAfter(RegisteredSyncs.java:424)
at com.ibm.ws.Transaction.JTA.TransactionImpl.distributeAfter(TransactionImpl.java:3885)
at com.ibm.ws.Transaction.JTA.TransactionImpl.postCompletion(TransactionImpl.java:3864)
at com.ibm.ws.Transaction.JTA.TransactionImpl.commitXAResources(TransactionImpl.java:2521)
at com.ibm.ws.Transaction.JTA.TransactionImpl.stage1CommitProcessing(TransactionImpl.java:1647)
at com.ibm.ws.Transaction.JTA.TransactionImpl.processCommit(TransactionImpl.java:1607)
at com.ibm.ws.Transaction.JTA.TransactionImpl.commit(TransactionImpl.java:1542)
at com.ibm.ws.Transaction.JTA.TranManagerImpl.commit(TranManagerImpl.java:240)
at com.ibm.ws.Transaction.JTA.TranManagerSet.commit(TranManagerSet.java:164)
at com.ibm.ws.Transaction.JTA.UserTransactionImpl.commit(UserTransactionImpl.java:292)
at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:842)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:662)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:632)
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:139)
at fleetcycle.services.framework.execution.interceptors.TransactionInterceptor.doInTransactionTemplate(TransactionInterceptor.java:114)
at fleetcycle.services.framework.execution.interceptors.TransactionInterceptor.invoke(TransactionInterceptor.java:86)
at sun.reflect.GeneratedMethodAccessor1147.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:618)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:139)
at fleetcycle.model.framework.persistence.TransactionRetryInterceptor.invoke(TransactionRetryInterceptor.java:95)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy191.invoke(Unknown Source)
at fleetcycle.services.framework.execution.interceptors.SecurityInterceptor.invoke(SecurityInterceptor.java:29)
at fleetcycle.services.framework.execution.ExecutionEntryTask.doTask(ExecutionEntryTask.java:98)
at fleetcycle.services.framework.execution.ExecutionEntry.executeWorkflow(ExecutionEntry.java:105)
at fleetcycle.services.framework.execution.ExecutionEntryWorkflowImpl.invokeWorkflow(ExecutionEntryWorkflowImpl.java:89)
at sun.reflect.GeneratedMethodAccessor1146.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:618)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:139)
at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:104)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy192.invokeWorkflow(Unknown Source)
at fleetcycle.services.framework.execution.ServiceExecutor$2.doInCacheBlock(ServiceExecutor.java:225)
at fleetcycle.services.framework.execution.cache.CacheTemplate.invoke(CacheTemplate.java:93)
at fleetcycle.services.framework.execution.ServiceExecutor.process(ServiceExecutor.java:230)
at fleetcycle.services.framework.execution.ServiceExecutor.access$000(ServiceExecutor.java:33)
at fleetcycle.services.framework.execution.ServiceExecutor$1.doInWorkflowContext(ServiceExecutor.java:102)
at fleetcycle.services.framework.execution.WorkflowContextTemplate.execute(WorkflowContextTemplate.java:26)
at fleetcycle.services.framework.execution.ServiceExecutor.execute(ServiceExecutor.java:99)
at sun.reflect.GeneratedMethodAccessor1281.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:618)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:139)
at fleetcycle.services.framework.audit.intercept.ApplicationExceptionAuditingInterceptor.invoke(ApplicationExceptionAuditingInterceptor.java:34)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy193.execute(Unknown Source)
at fleetcycle.ui.framework.actions.AbstractFleetCycleAction.callExecutionEntry(AbstractFleetCycleAction.java:245)
at fleetcycle.ui.framework.actions.ServiceExecutorAction.execute(ServiceExecutorAction.java:169)
at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:484)
at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:274)
at fleetcycle.ui.framework.actions.FleetCycleRequestProcessor.process(FleetCycleRequestProcessor.java:109)
at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:507)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:743)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1068)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1009)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:145)
at fleetcycle.util.common.UserDetailsFilter.doFilterInternal(UserDetailsFilter.java:44)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:75)
at org.acegisecurity.util.FilterToBeanProxy.doFilter(FilterToBeanProxy.java:98)
at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:190)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:130)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:265)
at org.acegisecurity.intercept.web.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:107)
at org.acegisecurity.intercept.web.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:72)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:275)
at org.acegisecurity.ui.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:110)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:275)
at fleetcycle.ui.framework.security.AbstractAuthenticationFilter.doFilterInternal(AbstractAuthenticationFilter.java:144)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:75)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:275)
at org.acegisecurity.ui.AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:229)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:275)
at org.acegisecurity.ui.logout.LogoutFilter.doFilter(LogoutFilter.java:106)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:275)
at org.acegisecurity.context.HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:286)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:275)
at org.acegisecurity.util.FilterChainProxy.doFilter(FilterChainProxy.java:149)
at org.acegisecurity.util.FilterToBeanProxy.doFilter(FilterToBeanProxy.java:98)
at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:190)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:130)
at fleetcycle.ui.framework.actions.SessionFilter$1.doInWorkflowContext(SessionFilter.java:106)
at fleetcycle.services.framework.execution.WorkflowContextTemplate.execute(WorkflowContextTemplate.java:26)
at fleetcycle.ui.framework.actions.SessionFilter.doFilterInternal(SessionFilter.java:111)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:75)
at org.acegisecurity.util.FilterToBeanProxy.doFilter(FilterToBeanProxy.java:98)
at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:190)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:130)
at org.springframework.orm.hibernate3.support.OpenSessionInViewFilter.doFilterInternal(OpenSessionInViewFilter.java:198)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:75)
at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:190)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:130)
at com.ibm.ws.webcontainer.filter.WebAppFilterChain._doFilter(WebAppFilterChain.java:87)
at com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:771)
at com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:679)
at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:539)
at com.ibm.ws.wswebcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:478)
at com.ibm.ws.webcontainer.webapp.WebApp.handleRequest(WebApp.java:3357)
at com.ibm.ws.webcontainer.webapp.WebGroup.handleRequest(WebGroup.java:267)
at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:811)
at com.ibm.ws.wswebcontainer.WebContainer.handleRequest(WebContainer.java:1455)
at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:115)
at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:454)
at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewInformation(HttpInboundLink.java:383)
at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:263)
at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)
at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
at com.ibm.io.async.AsyncChannelFuture$1.run(AsyncChannelFuture.java:205)
at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1473)
Caused by:
org.jboss.cache.lock.TimeoutException: read lock for /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY could not be acquired by GlobalTransaction:<10.10.21.72:33898>:6849 after 15000 ms. Locks: Read lock owners: []
Write lock owner: GlobalTransaction:<10.10.21.72:33898>:6847
, lock info: write owner=GlobalTransaction:<10.10.21.72:33898>:6847 (activeReaders=0, activeWriter=Thread[WebContainer : 2,5,main], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
at org.jboss.cache.lock.IdentityLock.acquireReadLock0(IdentityLock.java:332)
at org.jboss.cache.lock.IdentityLock.acquireReadLock(IdentityLock.java:276)
at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:499)
... 178 more
TRACE 1782515 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 10:02:32,314 - Setting up transactional context.
TRACE 1782515 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 10:02:32,314 - Setting tx as com.ibm.ws.Transaction.JTA.TransactionImpl at 45bb45bb#tid=7417 and gtx as GlobalTransaction:<10.10.21.72:33898>:6847
TRACE 1782515 [WebContainer : 2] (org.jboss.cache.factories.ComponentRegistry) 2009-10-08 10:02:32,314 - Testing if invocations are allowed.
TRACE 1782515 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 10:02:32,314 - calling aftercompletion for GlobalTransaction:<10.10.21.72:33898>:6847
TRACE 1782515 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 10:02:32,314 - Running commit phase. One phase? false
TRACE 1782516 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 10:02:32,315 - Running commit for GlobalTransaction:<10.10.21.72:33898>:6847
DEBUG 1782516 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticValidatorInterceptor) 2009-10-08 10:02:32,315 - Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<10.10.21.72:33898>:6847
TRACE 1782528 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticValidatorInterceptor) 2009-10-08 10:02:32,327 - Applying children deltas to parent node /fleetcycle/domain/billing/invoicing/InvoiceStatus
TRACE 1782528 [WebContainer : 2] (org.jboss.cache.VersionedNode) 2009-10-08 10:02:32,327 - Marking node /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY as invalid
TRACE 1782534 [WebContainer : 2] (org.jboss.cache.VersionedNode) 2009-10-08 10:02:32,333 - Marking node /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY as invalid
TRACE 1782534 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticValidatorInterceptor) 2009-10-08 10:02:32,333 - Versioning is explicit; not attempting an increment.
TRACE 1782534 [WebContainer : 2] (org.jboss.cache.interceptors.OptimisticValidatorInterceptor) 2009-10-08 10:02:32,333 - Setting version of node /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY from org.hibernate.cache.jbc2.util.NonLockingDataVersion at 230b230b to org.hibernate.cache.jbc2.util.NonLockingDataVersion at 230b230b
TRACE 1782536 [WebContainer : 2] (org.jboss.cache.lock.NodeBasedLockManager) 2009-10-08 10:02:32,335 - releasing lock for /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY (write owner=GlobalTransaction:<10.10.21.72:33898>:6847), owner GlobalTransaction:<10.10.21.72:33898>:6847
TRACE 1782540 [WebContainer : 2] (org.jboss.cache.lock.NodeBasedLockManager) 2009-10-08 10:02:32,339 - releasing lock for /fleetcycle/domain/billing/invoicing/InvoiceStatus (read owners=[GlobalTransaction:<10.10.21.72:33898>:6847]), owner GlobalTransaction:<10.10.21.72:33898>:6847
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 10:02:32,503 - Setting up transactional context.
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.interceptors.OptimisticTxInterceptor) 2009-10-08 10:02:32,503 - Setting tx as null and gtx as null
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.interceptors.InvocationContextInterceptor) 2009-10-08 10:02:32,503 - Resetting invocation-scope options
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.commands.legacy.write.VersionedInvalidateCommand) 2009-10-08 10:02:32,503 - Invalidating fqn:/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.VersionedNode) 2009-10-08 10:02:32,503 - Marking node /fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY as invalid
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.interceptors.InvocationContextInterceptor) 2009-10-08 10:02:32,503 - Resetting invocation-scope options
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.marshall.CommandAwareRpcDispatcher) 2009-10-08 10:02:32,503 - Command : ReplicateCommand{cmds=OptimisticInvalidateCommand{dataVersion=org.hibernate.cache.jbc2.util.NonLockingDataVersion at 42014201 ,fqn=/fleetcycle/domain/billing/invoicing/InvoiceStatus/ENTITY}} executed, result is: null
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.marshall.CacheMarshaller300) 2009-10-08 10:02:32,503 - Marshalling object null
TRACE 1782704 [Multiplexer-1] (org.jboss.cache.marshall.CacheMarshaller300) 2009-10-08 10:02:32,503 - Done serializing object: null
TRACE 1782705 [OOB-1,udp-legacy-fleetcycle,10.10.21.72:33898] (org.jboss.cache.marshall.CacheMarshaller300) 2009-10-08 10:02:32,504 - Unmarshalled object null
TRACE 1782705 [WebContainer : 2] (org.jboss.cache.marshall.CommandAwareRpcDispatcher) 2009-10-08 10:02:32,504 - responses: [sender=10.10.21.72:33896, retval=null, received=true, suspected=false]
View the original post : http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4260342#4260342
Reply to the post : http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&p=4260342
More information about the jboss-user
mailing list