Hiding StaleObjectStaleException problem
kadlecp Jun 15, 2008 11:00 AMHello,
when running with more threads, or when suspending running process I receive StaleObjectStaleException. I tried to get rid of them according to docs (chapter 6.5).
I set log4j
log4j.logger.org.hibernate.event.def.AbstractFlushingEventListener=FATAL
With that log4j setting some stack traces disappeared.
When suspending running process I still got
15:06:59,500 ERROR [Services] problem closing service 'persistence' org.jbpm.JbpmException: couldn't commit JTA transaction at org.jbpm.persistence.jta.JtaDbPersistenceService.endJtaTransaction(JtaDbPersistenceService.java:93) at org.jbpm.persistence.jta.JtaDbPersistenceService.close(JtaDbPersistenceService.java:61) at org.jbpm.svc.Services.close(Services.java:223) at org.jbpm.JbpmContext.close(JbpmContext.java:139) at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:210) at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:64) Caused by: javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.at ansaction.arjunacore.commitwhenaborted] Can't commit because the transaction is in aborted state at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1401) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:140) at org.jbpm.persistence.jta.JtaDbPersistenceService.endJtaTransaction(JtaDbPersistenceService.java:91) ... 5 more Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was i bpm.graph.exe.Token#70784] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1769) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27) at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000) at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338) at org.hibernate.transaction.CacheSynchronization.beforeCompletion(CacheSynchronization.java:59) at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:114) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:247) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:86) at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1389) ... 9 more 15:06:59,504 ERROR [JobExecutorThread] exception in job executor thread. waiting 5000 milliseconds org.jbpm.JbpmException: couldn't commit JTA transaction at org.jbpm.persistence.jta.JtaDbPersistenceService.endJtaTransaction(JtaDbPersistenceService.java:93) at org.jbpm.persistence.jta.JtaDbPersistenceService.close(JtaDbPersistenceService.java:61) at org.jbpm.svc.Services.close(Services.java:223) at org.jbpm.JbpmContext.close(JbpmContext.java:139) at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:210) at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:64) Caused by: javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.at ansaction.arjunacore.commitwhenaborted] Can't commit because the transaction is in aborted state at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1401) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:140) at org.jbpm.persistence.jta.JtaDbPersistenceService.endJtaTransaction(JtaDbPersistenceService.java:91) ... 5 more Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was i bpm.graph.exe.Token#70784] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1769) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27) at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000) at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338) at org.hibernate.transaction.CacheSynchronization.beforeCompletion(CacheSynchronization.java:59) at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:114) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:247) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:86) at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1389) ... 9 more
To get rid of those I had to make some changes to classes org.jbpm.svc.Services and org.jbpm.job.executor.JobExecutorThread.
I have to replace following code
} catch (JbpmPersistenceException e) { if ("org.hibernate.StaleObjectStateException".equals(e.getCause().getClass().getName())) { ... StaleObjectLogConfigurer.staleObjectExceptionsLog.error("problem closing service '"+serviceName+"': optimistic locking failed", e); } else { ... } }
with
} catch (JbpmException e) { if (isCausedBy(e, "org.hibernate.StaleObjectStateException")) { ... StaleObjectLogConfigurer.staleObjectExceptionsLog.error("problem closing service '"+serviceName+"': optimistic locking failed", e); } else { ... } }
where method isCausedBy is defined as follows
private boolean isCausedBy(Throwable e, String name) { boolean isCaused = false; while (e != null) { if (e.getClass().getName().equals(name)) { isCaused = true; break; } e = e.getCause(); } return isCaused; }
With these changes I receive only
15:40:13,104 WARN [arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator_2] TwoPhaseCoordinator.beforeCompletion - failed fo una.ats.internal.jta.resources.arjunacore.SynchronizationImple@fa447 org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbp xe.Token#73493] at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1769) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2412) at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2312) at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:96) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27) at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000) at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338) at org.hibernate.transaction.CacheSynchronization.beforeCompletion(CacheSynchronization.java:59) at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:114) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:247) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:86) at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1389) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:140) at org.jbpm.persistence.jta.JtaDbPersistenceService.endJtaTransaction(JtaDbPersistenceService.java:91) at org.jbpm.persistence.jta.JtaDbPersistenceService.close(JtaDbPersistenceService.java:61) at org.jbpm.svc.Services.close(Services.java:223) at org.jbpm.JbpmContext.close(JbpmContext.java:139) at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:211) at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:65)
And this is JBoss Transaction logging which is somehow configurable as well.
Is it bug in jBPM that not all StaleObjectStateExeception are hidden in Services and JobExecutorThread?
Regars
Pavel