10:46 a.m.
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@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@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@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@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@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@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@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@230b230b to
org.hibernate.cache.jbc2.util.NonLockingDataVersion@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@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#...
Reply to the post :
http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&a...