Problem with timer
jbfromthepflaumblock Nov 30, 2009 1:16 PM=== Environment ==============================
- jBPM Version : 4.2
- Database : HSQLDB
- JDK : 1.6
- Container : java version "1.6.0_15"
Java(TM) SE Runtime Environment (build 1.6.0_15-b03)
Java HotSpot(TM) 64-Bit Server VM (build 14.1-b02, mixed mode)
=== Process ==================================
<?xml version="1.0" encoding="UTF-8"?> <process name="loop" xmlns="http://jbpm.org/4.2/jpdl"> <start g="24,96,48,48" name="start1"> <transition g="-56,-20" name="to check status" to="check status"/> </start> <java class="java.util.Random" method="nextInt" name="check status" var="randomResult" g="204,96,157,49"> <transition to="exclusive1"/> </java> <decision g="432,96,48,48" name="exclusive1"> <transition g="-11,-21" name="ok" to="end1"> <condition expr="#{randomResult=="6"}" /> </transition> <transition g="455,253:-95,-22" name="not ready yet" to="wait"/> </decision> <task name="wait" g="204,228,157,49"> <transition name="try again" to="check status" g="-66,-8"> <timer duedate="15 seconds"/> </transition> </task> <end g="600,96,157,52" name="end1"/> </process>
=== Debug logs &Stacktrace ==============================
2009-11-30 18:47:43,652 DEBUG [org.jbpm.pvm.internal.model.ProcessDefinitionImpl] (http-127.0.0.1-8080-3) creating new execution for process 'loop'
2009-11-30 18:47:43,653 DEBUG [org.jbpm.pvm.internal.id.DatabaseIdComposer] (http-127.0.0.1-8080-3) generated execution id loop.20067
2009-11-30 18:47:43,654 DEBUG [org.jbpm.pvm.internal.model.op.ExecuteActivity] (http-127.0.0.1-8080-3) executing activity(start1)
2009-11-30 18:47:43,654 DEBUG [org.jbpm.pvm.internal.model.op.ExecuteActivity] (http-127.0.0.1-8080-3) executing activity(check status)
2009-11-30 18:47:43,655 DEBUG [org.jbpm.pvm.internal.model.ScopeInstanceImpl] (http-127.0.0.1-8080-3) create variable 'randomResult' in 'execution[loop.20067]' with value '1116249621'
2009-11-30 18:47:43,657 DEBUG [org.jbpm.pvm.internal.model.op.ExecuteActivity] (http-127.0.0.1-8080-3) executing activity(exclusive1)
2009-11-30 18:47:43,678 DEBUG [org.jbpm.pvm.internal.id.DatabaseIdComposer] (http-127.0.0.1-8080-3) generated execution id loop.20067.wait
2009-11-30 18:47:43,678 DEBUG [org.jbpm.pvm.internal.model.ExecutionImpl] (http-127.0.0.1-8080-3) created execution[loop.20067.wait]
2009-11-30 18:47:43,678 DEBUG [org.jbpm.pvm.internal.model.ScopeInstanceImpl] (http-127.0.0.1-8080-3) creating timer on execution[loop.20067.wait]
2009-11-30 18:47:43,709 DEBUG [org.jbpm.pvm.internal.session.TimerSession] (http-127.0.0.1-8080-3) scheduling timer[20072|2009-11-30 18:47:58,679|try again]
2009-11-30 18:47:43,711 DEBUG [org.jbpm.pvm.internal.model.op.ExecuteActivity] (http-127.0.0.1-8080-3) execution[loop.20067.wait] executes activity(wait)
2009-11-30 18:47:58,689 DEBUG [org.jbpm.pvm.internal.jobexecutor.DispatcherThread] (DispatcherThread) submitting jobs [20072]
2009-11-30 18:47:58,700 DEBUG [org.jbpm.pvm.internal.jobexecutor.DispatcherThread] (DispatcherThread) added jobs [20072] to the queue
2009-11-30 18:47:58,712 DEBUG [org.jbpm.pvm.internal.cmd.ExecuteJobCmd] (pool-9-thread-1) executing job timer[20072|2009-11-30 18:47:58,679|try again]...
2009-11-30 18:47:58,713 DEBUG [org.jbpm.pvm.internal.job.TimerImpl] (pool-9-thread-1) executing timer[20072|2009-11-30 18:47:58,679|try again]
2009-11-30 18:47:58,717 DEBUG [org.jbpm.pvm.internal.job.TimerImpl] (pool-9-thread-1) feeding timer signal try again into execution[loop.20067.wait]
2009-11-30 18:47:58,725 DEBUG [org.jbpm.pvm.internal.model.op.Signal] (pool-9-thread-1) execution[loop.20067.wait] signals activity(wait)
2009-11-30 18:47:58,731 DEBUG [org.jbpm.pvm.internal.model.ExecutionImpl] (pool-9-thread-1) destroying timers of execution[loop.20067.wait]
2009-11-30 18:47:58,737 DEBUG [org.jbpm.pvm.internal.model.ExecutionImpl] (pool-9-thread-1) execution[loop.20067.wait] ends
2009-11-30 18:47:58,742 DEBUG [org.jbpm.pvm.internal.model.op.ExecuteActivity] (pool-9-thread-1) executing activity(check status)
2009-11-30 18:47:58,742 DEBUG [org.jbpm.pvm.internal.model.ScopeInstanceImpl] (pool-9-thread-1) updating variable 'randomResult' in 'execution[loop.20067]' to value '751427787'
2009-11-30 18:47:58,743 DEBUG [org.jbpm.pvm.internal.model.op.ExecuteActivity] (pool-9-thread-1) executing activity(exclusive1)
2009-11-30 18:47:58,748 DEBUG [org.jbpm.pvm.internal.id.DatabaseIdComposer] (pool-9-thread-1) generated execution id loop.20067.wait
2009-11-30 18:47:58,749 DEBUG [org.jbpm.pvm.internal.model.ExecutionImpl] (pool-9-thread-1) created execution[loop.20067.wait]
2009-11-30 18:47:58,749 DEBUG [org.jbpm.pvm.internal.model.ScopeInstanceImpl] (pool-9-thread-1) creating timer on execution[loop.20067.wait]
2009-11-30 18:47:58,749 DEBUG [org.jbpm.pvm.internal.session.TimerSession] (pool-9-thread-1) scheduling timer[20078|2009-11-30 18:48:13,749|try again]
2009-11-30 18:47:58,755 DEBUG [org.jbpm.pvm.internal.model.op.ExecuteActivity] (pool-9-thread-1) execution[loop.20067.wait] executes activity(wait)
2009-11-30 18:47:58,756 DEBUG [org.jbpm.pvm.internal.job.TimerImpl] (pool-9-thread-1) deleting timer[20072|2009-11-30 18:47:58,679|try again]
2009-11-30 18:47:58,756 DEBUG [org.jbpm.pvm.internal.cmd.ExecuteJobCmd] (pool-9-thread-1) executed job timer[20072|2009-11-30 18:47:58,679|try again]
2009-11-30 18:47:58,766 WARN [org.hibernate.util.JDBCExceptionReporter] (pool-9-thread-1) SQL Error: -104, SQLState: 23000
2009-11-30 18:47:58,766 ERROR [org.hibernate.util.JDBCExceptionReporter] (pool-9-thread-1) Violation of unique constraint $$: duplicate value(s) for column(s) $$: SYS_CT_50 in statement [update JBPM4_EXECUTION set DBVERSION_=?, ACTIVITYNAME_=?, PROCDEFID_=?, HASVARS_=?, NAME_=?, KEY_=?, ID_=?, STATE_=?, SUSPHISTSTATE_=?, PRIORITY_=?, HISACTINST_=?, PARENT_=?, INSTANCE_=?, SUPEREXEC_=?, SUBPROCINST_=? where DBID_=? and DBVERSION_=?]
2009-11-30 18:47:58,767 ERROR [org.hibernate.event.def.AbstractFlushingEventListener] (pool-9-thread-1) Could not synchronize database state with session
org.hibernate.exception.ConstraintViolationException: could not update: [org.jbpm.pvm.internal.model.ExecutionImpl#20077]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:94)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2453)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2335)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2635)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:115)
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:321)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365)
at org.hibernate.transaction.CacheSynchronization.beforeCompletion(CacheSynchronization.java:88)
at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:101)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:263)
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:1414)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:162)
at org.jbpm.pvm.internal.tx.jta.JtaTransaction.commit(JtaTransaction.java:91)
at org.jbpm.pvm.internal.tx.jta.JtaTransactionInterceptor.executeInNewTx(JtaTransactionInterceptor.java:89)
at org.jbpm.pvm.internal.tx.jta.JtaTransactionInterceptor.execute(JtaTransactionInterceptor.java:66)
at org.jbpm.pvm.internal.svc.RetryInterceptor.execute(RetryInterceptor.java:55)
at org.jbpm.pvm.internal.tx.jta.JtaRetryInterceptor.executeWithRetry(JtaRetryInterceptor.java:52)
at org.jbpm.pvm.internal.tx.jta.JtaRetryInterceptor.execute(JtaRetryInterceptor.java:45)
at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.executeInNewEnvironment(EnvironmentInterceptor.java:53)
at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.execute(EnvironmentInterceptor.java:40)
at org.jbpm.pvm.internal.svc.SkipInterceptor.execute(SkipInterceptor.java:43)
at org.jbpm.pvm.internal.jobexecutor.JobParcel.run(JobParcel.java:48)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.sql.SQLException: Violation of unique constraint $$: duplicate value(s) for column(s) $$: SYS_CT_50 in statement [update JBPM4_EXECUTION set DBVERSION_=?, ACTIVITYNAME_=?, PROCDEFID_=?, HASVARS_=?, NAME_=?, KEY_=?, ID_=?, STATE_=?, SUSPHISTSTATE_=?, PRIORITY_=?, HISACTINST_=?, PARENT_=?, INSTANCE_=?, SUPEREXEC_=?, SUBPROCINST_=? where DBID_=? and DBVERSION_=?]
at org.hsqldb.jdbc.Util.throwError(Unknown Source)
at org.hsqldb.jdbc.jdbcPreparedStatement.executeUpdate(Unknown Source)
at org.jboss.resource.adapter.jdbc.CachedPreparedStatement.executeUpdate(CachedPreparedStatement.java:94)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:365)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2435)
... 35 more
2009-11-30 18:47:58,771 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (pool-9-thread-1) [com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator_2] TwoPhaseCoordinator.beforeCompletion - failed for com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple@5eff06be
org.hibernate.exception.ConstraintViolationException: could not update: [org.jbpm.pvm.internal.model.ExecutionImpl#20077]
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:94)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2453)
at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2335)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2635)
at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:115)
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:321)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365)
at org.hibernate.transaction.CacheSynchronization.beforeCompletion(CacheSynchronization.java:88)
at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:101)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:263)
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:1414)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:162)
at org.jbpm.pvm.internal.tx.jta.JtaTransaction.commit(JtaTransaction.java:91)
at org.jbpm.pvm.internal.tx.jta.JtaTransactionInterceptor.executeInNewTx(JtaTransactionInterceptor.java:89)
at org.jbpm.pvm.internal.tx.jta.JtaTransactionInterceptor.execute(JtaTransactionInterceptor.java:66)
at org.jbpm.pvm.internal.svc.RetryInterceptor.execute(RetryInterceptor.java:55)
at org.jbpm.pvm.internal.tx.jta.JtaRetryInterceptor.executeWithRetry(JtaRetryInterceptor.java:52)
at org.jbpm.pvm.internal.tx.jta.JtaRetryInterceptor.execute(JtaRetryInterceptor.java:45)
at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.executeInNewEnvironment(EnvironmentInterceptor.java:53)
at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.execute(EnvironmentInterceptor.java:40)
at org.jbpm.pvm.internal.svc.SkipInterceptor.execute(SkipInterceptor.java:43)
at org.jbpm.pvm.internal.jobexecutor.JobParcel.run(JobParcel.java:48)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.sql.SQLException: Violation of unique constraint $$: duplicate value(s) for column(s) $$: SYS_CT_50 in statement [update JBPM4_EXECUTION set DBVERSION_=?, ACTIVITYNAME_=?, PROCDEFID_=?, HASVARS_=?, NAME_=?, KEY_=?, ID_=?, STATE_=?, SUSPHISTSTATE_=?, PRIORITY_=?, HISACTINST_=?, PARENT_=?, INSTANCE_=?, SUPEREXEC_=?, SUBPROCINST_=? where DBID_=? and DBVERSION_=?]
at org.hsqldb.jdbc.Util.throwError(Unknown Source)
at org.hsqldb.jdbc.jdbcPreparedStatement.executeUpdate(Unknown Source)
at org.jboss.resource.adapter.jdbc.CachedPreparedStatement.executeUpdate(CachedPreparedStatement.java:94)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:365)
at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2435)
... 35 more
2009-11-30 18:47:58,774 ERROR [org.jbpm.pvm.internal.jobexecutor.JobParcel] (pool-9-thread-1) exception in job block
org.jbpm.api.JbpmException: couldn't rollback: BaseTransaction.rollback - [com.arjuna.ats.internal.jta.transaction.arjunacore.notx] [com.arjuna.ats.internal.jta.transaction.arjunacore.notx] no transaction!
at org.jbpm.pvm.internal.tx.jta.JtaTransaction.rollback(JtaTransaction.java:85)
at org.jbpm.pvm.internal.tx.jta.JtaTransactionInterceptor.executeInNewTx(JtaTransactionInterceptor.java:92)
at org.jbpm.pvm.internal.tx.jta.JtaTransactionInterceptor.execute(JtaTransactionInterceptor.java:66)
at org.jbpm.pvm.internal.svc.RetryInterceptor.execute(RetryInterceptor.java:55)
at org.jbpm.pvm.internal.tx.jta.JtaRetryInterceptor.executeWithRetry(JtaRetryInterceptor.java:52)
at org.jbpm.pvm.internal.tx.jta.JtaRetryInterceptor.execute(JtaRetryInterceptor.java:45)
at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.executeInNewEnvironment(EnvironmentInterceptor.java:53)
at org.jbpm.pvm.internal.svc.EnvironmentInterceptor.execute(EnvironmentInterceptor.java:40)
at org.jbpm.pvm.internal.svc.SkipInterceptor.execute(SkipInterceptor.java:43)
at org.jbpm.pvm.internal.jobexecutor.JobParcel.run(JobParcel.java:48)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.IllegalStateException: BaseTransaction.rollback - [com.arjuna.ats.internal.jta.transaction.arjunacore.notx] [com.arjuna.ats.internal.jta.transaction.arjunacore.notx] no transaction!
....
=== Problem description =========================
Hi,
the errors above appears after starting the process via the jBPM console.
Is my process definition wrong? I would like to check if a service is running and proceed afterwards.
The problems seems to be located at the timer.
Thanks for your help. I'm new to jBPM and open for any solutions.
Greetings,
Jonas