See
http://hudson.qa.jboss.com/hudson/job/jbpm4-base/./jdk=java15_default,lab...
Changes:
[heiko.braun(a)jboss.com] Test the report SQL statments as part of the integration test
suite
------------------------------------------
[...truncated 3044 lines...]
07:25:25,577 FIN | [DefaultIdGenerator] generated execution id
TimerEvent.57.guardedWait[0]
07:25:25,577 FIN | [ScopeInstanceImpl] creating timer on execution[guardedWait]
07:25:25,579 FIN | [TimerSession] scheduling timer[0|2009-05-29 07:35:25,578|timeout]
07:25:25,591 FIN | [ExecuteActivity] execution[guardedWait] executes
activity(guardedWait)
07:25:25,599 FIN | [ExecuteJobCmd] executing job timer[8|2009-05-29
07:35:25,578|timeout]...
07:25:25,600 FIN | [TimerImpl] executing timer[8|2009-05-29 07:35:25,578|timeout]
07:25:25,605 FIN | [TimerImpl] firing event null into activity(guardedWait)
07:25:25,606 FIN | [ScopeInstanceImpl] create variable 'escalation' in
'process-instance' with value 'true'
07:25:25,607 FIN | [TimerImpl] deleting timer[8|2009-05-29 07:35:25,578|timeout]
07:25:25,608 FIN | [ExecuteJobCmd] executed job timer[8|2009-05-29 07:35:25,578|timeout]
07:25:25,664 FIN | [HibernatePvmDbSession] deleting process instance TimerEvent.57
07:25:25,671 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
07:25:25,673 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
07:25:25,689 FIN | [BaseJbpmTestCase] === ending testTimerEventTimerFires
=============================
07:25:25,692 FIN | [BaseJbpmTestCase] === starting testTimerEventContinueBeforeTimerFires
=============================
07:25:25,713 FIN | [ProcessDefinitionImpl] creating new execution for process
'TimerEvent'
07:25:25,715 FIN | [DefaultIdGenerator] generated execution id TimerEvent.59
07:25:25,717 FIN | [ExecuteActivity] executing activity(10058769)
07:25:25,718 FIN | [Execution] creating execution[guardedWait]
07:25:25,720 FIN | [DefaultIdGenerator] generated execution id
TimerEvent.59.guardedWait[0]
07:25:25,721 FIN | [ScopeInstanceImpl] creating timer on execution[guardedWait]
07:25:25,724 FIN | [TimerSession] scheduling timer[0|2009-05-29 07:35:25,723|timeout]
07:25:25,727 FIN | [ExecuteActivity] execution[guardedWait] executes
activity(guardedWait)
07:25:25,738 FIN | [Signal] execution[guardedWait] signals activity(guardedWait)
07:25:25,741 FIN | [Execution] destroying timers of execution[guardedWait]
07:25:25,742 FIN | [TimerSession] canceling timer[9|2009-05-29 07:35:25,723|timeout]
07:25:25,744 FIN | [Execution] execution[guardedWait] ends
07:25:25,745 FIN | [ExecuteActivity] executing activity(next step)
07:25:25,787 FIN | [HibernatePvmDbSession] deleting process instance TimerEvent.59
07:25:25,793 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
07:25:25,796 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
07:25:25,807 FIN | [BaseJbpmTestCase] === ending testTimerEventContinueBeforeTimerFires
=============================
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.305 sec
Running org.jbpm.examples.identity.IdentityTest
07:25:25,817 FIN | [BaseJbpmTestCase] === starting testSingleUser
=============================
07:25:25,836 FIN | [BaseJbpmTestCase] === ending testSingleUser
=============================
07:25:25,839 FIN | [BaseJbpmTestCase] === starting testCreateGroup
=============================
07:25:25,852 FIN | [BaseJbpmTestCase] === ending testCreateGroup
=============================
07:25:25,854 FIN | [BaseJbpmTestCase] === starting testFindGroupsByUser
=============================
07:25:25,871 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_ID_USER
07:25:25,883 FIN | [BaseJbpmTestCase] === ending testFindGroupsByUser
=============================
07:25:25,885 FIN | [BaseJbpmTestCase] === starting testFindGroupByUserAndGroupType
=============================
07:25:25,919 FIN | [BaseJbpmTestCase] === ending testFindGroupByUserAndGroupType
=============================
07:25:25,922 FIN | [BaseJbpmTestCase] === starting testSingleGroup
=============================
redhat
07:25:25,979 FIN | [BaseJbpmTestCase] === ending testSingleGroup
=============================
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.171 sec
Running org.jbpm.examples.async.activity.AsyncActivityTest
07:25:25,988 FIN | [BaseJbpmTestCase] === starting testAsyncActivity
=============================
07:25:26,236 FIN | [ProcessDefinitionImpl] creating new execution for process
'AsyncActivity'
07:25:26,238 FIN | [DefaultIdGenerator] generated execution id AsyncActivity.61
07:25:26,239 FIN | [ExecuteActivity] executing activity(1764419)
07:25:26,241 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
07:25:26,247 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[10]...
07:25:26,250 FIN | [ExecuteActivity] executing activity(generate pdf)
07:25:26,254 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
07:25:26,255 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[10]
07:25:26,258 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[11]...
07:25:26,261 FIN | [ExecuteActivity] executing activity(calculate primes)
07:25:26,263 FIN | [ExecuteActivity] executing activity(end)
07:25:26,271 FIN | [Execution] process-instance ends with state ended
07:25:26,277 FIN | [HibernatePvmDbSession] deleting process instance AsyncActivity.61
07:25:26,279 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[11]
07:25:26,299 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
07:25:26,301 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
07:25:26,338 FIN | [BaseJbpmTestCase] === ending testAsyncActivity
=============================
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.357 sec
Running org.jbpm.examples.end.multiple.EndMultipleTest
07:25:26,347 FIN | [BaseJbpmTestCase] === starting testEndMultipleOk
=============================
07:25:26,435 FIN | [ProcessDefinitionImpl] creating new execution for process
'EndMultiple'
07:25:26,438 FIN | [DefaultIdGenerator] generated execution id EndMultiple.62
07:25:26,439 FIN | [ExecuteActivity] executing activity(14587704)
07:25:26,440 FIN | [ExecuteActivity] executing activity(get return code)
07:25:26,454 FIN | [Signal] signalling activity(get return code), signalName=200
07:25:26,456 FIN | [ExecuteActivity] executing activity(ok)
07:25:26,456 FIN | [Execution] process-instance ends with state ended
07:25:26,460 FIN | [HibernatePvmDbSession] deleting process instance EndMultiple.62
07:25:26,516 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
07:25:26,517 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
07:25:26,525 FIN | [BaseJbpmTestCase] === ending testEndMultipleOk
=============================
07:25:26,527 FIN | [BaseJbpmTestCase] === starting testEndMultipleBadRequest
=============================
07:25:26,586 FIN | [ProcessDefinitionImpl] creating new execution for process
'EndMultiple'
07:25:26,588 FIN | [DefaultIdGenerator] generated execution id EndMultiple.63
07:25:26,590 FIN | [ExecuteActivity] executing activity(9528826)
07:25:26,591 FIN | [ExecuteActivity] executing activity(get return code)
07:25:26,596 FIN | [Signal] signalling activity(get return code), signalName=400
07:25:26,597 FIN | [ExecuteActivity] executing activity(bad request)
07:25:26,598 FIN | [Execution] process-instance ends with state ended
07:25:26,604 FIN | [HibernatePvmDbSession] deleting process instance EndMultiple.63
07:25:26,636 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
07:25:26,638 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
07:25:26,658 FIN | [BaseJbpmTestCase] === ending testEndMultipleBadRequest
=============================
07:25:26,660 FIN | [BaseJbpmTestCase] === starting testEndMultipleInternalServerError
=============================
07:25:26,680 FIN | [ProcessDefinitionImpl] creating new execution for process
'EndMultiple'
07:25:26,682 FIN | [DefaultIdGenerator] generated execution id EndMultiple.64
07:25:26,684 FIN | [ExecuteActivity] executing activity(8600885)
07:25:26,685 FIN | [ExecuteActivity] executing activity(get return code)
07:25:26,693 FIN | [Signal] signalling activity(get return code), signalName=500
07:25:26,695 FIN | [ExecuteActivity] executing activity(internal server error)
07:25:26,695 FIN | [Execution] process-instance ends with state ended
07:25:26,701 FIN | [HibernatePvmDbSession] deleting process instance EndMultiple.64
07:25:26,730 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
07:25:26,732 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
07:25:26,738 FIN | [BaseJbpmTestCase] === ending testEndMultipleInternalServerError
=============================
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.397 sec
Running org.jbpm.examples.subprocess.outcomeactivity.SubProcessOutcomeActivityTest
07:25:26,744 FIN | [BaseJbpmTestCase] === starting testSubProcessResultOk
=============================
07:25:26,775 FIN | [ProcessDefinitionImpl] creating new execution for process
'SubProcessDocument'
07:25:26,777 FIN | [DefaultIdGenerator] generated execution id SubProcessDocument.65
07:25:26,777 FIN | [ExecuteActivity] executing activity(11726490)
07:25:26,777 FIN | [ExecuteActivity] executing activity(review)
07:25:26,779 FIN | [ProcessDefinitionImpl] creating new execution for process
'SubProcessReview'
07:25:26,780 FIN | [DefaultIdGenerator] generated execution id SubProcessReview.66
07:25:26,780 FIN | [ExecuteActivity] executing activity(11819817)
07:25:26,781 FIN | [ExecuteActivity] executing activity(get approval)
07:25:26,784 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.state != 'suspended' and
task.assignee = :assignee order by task.priority desc
07:25:26,784 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
07:25:26,789 FIN | [Signal] signalling activity(get approval), signalName=ok
07:25:26,790 FIN | [ExecuteActivity] executing activity(ok)
07:25:26,791 FIN | [Execution] process-instance ends with state ended
07:25:26,793 FIN | [Signal] signalling activity(review), signalName=null
07:25:26,793 WRN | [ProxyWarnLog] Narrowing proxy to class
org.jbpm.jpdl.internal.model.JpdlExecution - this operation breaks ==
07:25:26,794 FIN | [ExecuteActivity] executing activity(next step)
07:25:26,811 FIN | [HibernatePvmDbSession] deleting process instance SubProcessReview.66
07:25:26,843 FIN | [HibernatePvmDbSession] deleting process instance
SubProcessDocument.65
07:25:26,846 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
07:25:26,847 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_PROCINST
07:25:26,880 FIN | [BaseJbpmTestCase] === ending testSubProcessResultOk
=============================
07:25:26,881 FIN | [BaseJbpmTestCase] === starting testSubProcessResultNok
=============================
07:25:26,904 FIN | [ProcessDefinitionImpl] creating new execution for process
'SubProcessDocument'
07:25:26,905 FIN | [DefaultIdGenerator] generated execution id SubProcessDocument.67
07:25:26,905 FIN | [ExecuteActivity] executing activity(33240916)
07:25:26,905 FIN | [ExecuteActivity] executing activity(review)
07:25:26,907 FIN | [ProcessDefinitionImpl] creating new execution for process
'SubProcessReview'
07:25:26,942 FIN | [DefaultIdGenerator] generated execution id SubProcessReview.68
07:25:26,942 FIN | [ExecuteActivity] executing activity(29029231)
07:25:26,943 FIN | [ExecuteActivity] executing activity(get approval)
07:25:26,947 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.state != 'suspended' and
task.assignee = :assignee order by task.priority desc
07:25:26,948 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
07:25:26,952 FIN | [Signal] signalling activity(get approval), signalName=nok
07:25:26,952 FIN | [ExecuteActivity] executing activity(nok)
07:25:26,953 FIN | [Execution] process-instance ends with state ended
07:25:26,956 FIN | [Signal] signalling activity(review), signalName=null
07:25:26,957 WRN | [ProxyWarnLog] Narrowing proxy to class
org.jbpm.jpdl.internal.model.JpdlExecution - this operation breaks ==
07:25:26,958 FIN | [ExecuteActivity] executing activity(update)
07:25:26,961 FIN | [HibernatePvmDbSession] deleting process instance SubProcessReview.68
07:25:27,036 FIN | [HibernatePvmDbSession] deleting process instance
SubProcessDocument.67
07:25:27,072 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
07:25:27,075 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_PROCINST
07:25:27,092 FIN | [BaseJbpmTestCase] === ending testSubProcessResultNok
=============================
07:25:27,093 FIN | [BaseJbpmTestCase] === starting testSubProcessResultReject
=============================
07:25:27,138 FIN | [ProcessDefinitionImpl] creating new execution for process
'SubProcessDocument'
07:25:27,139 FIN | [DefaultIdGenerator] generated execution id SubProcessDocument.69
07:25:27,140 FIN | [ExecuteActivity] executing activity(30823518)
07:25:27,141 FIN | [ExecuteActivity] executing activity(review)
07:25:27,143 FIN | [ProcessDefinitionImpl] creating new execution for process
'SubProcessReview'
07:25:27,145 FIN | [DefaultIdGenerator] generated execution id SubProcessReview.70
07:25:27,146 FIN | [ExecuteActivity] executing activity(30273569)
07:25:27,146 FIN | [ExecuteActivity] executing activity(get approval)
07:25:27,149 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.state != 'suspended' and
task.assignee = :assignee order by task.priority desc
07:25:27,150 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
07:25:27,156 FIN | [Signal] signalling activity(get approval), signalName=reject
07:25:27,157 FIN | [ExecuteActivity] executing activity(reject)
07:25:27,159 FIN | [Execution] process-instance ends with state ended
07:25:27,161 FIN | [Signal] signalling activity(review), signalName=null
07:25:27,163 WRN | [ProxyWarnLog] Narrowing proxy to class
org.jbpm.jpdl.internal.model.JpdlExecution - this operation breaks ==
07:25:27,163 FIN | [ExecuteActivity] executing activity(close)
07:25:27,166 FIN | [HibernatePvmDbSession] deleting process instance SubProcessReview.70
07:25:27,204 FIN | [HibernatePvmDbSession] deleting process instance
SubProcessDocument.69
07:25:27,209 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
07:25:27,212 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_PROCINST
07:25:27,221 FIN | [BaseJbpmTestCase] === ending testSubProcessResultReject
=============================
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.483 sec
Running org.jbpm.examples.services.ServicesTest
07:25:27,251 INF | [Configuration] configuring from resource: jbpm.hibernate.cfg.xml
07:25:27,253 INF | [Configuration] Configuration resource: jbpm.hibernate.cfg.xml
07:25:27,258 INF | [Configuration] Reading mappings from resource :
jbpm.repository.hbm.xml
07:25:27,274 INF | [Configuration] Reading mappings from resource :
jbpm.execution.hbm.xml
07:25:27,297 INF | [Configuration] Reading mappings from resource : jbpm.history.hbm.xml
07:25:27,311 INF | [Configuration] Reading mappings from resource : jbpm.task.hbm.xml
07:25:27,327 INF | [Configuration] Reading mappings from resource : jbpm.jpdl.hbm.xml
07:25:27,364 INF | [Configuration] Reading mappings from resource : jbpm.identity.hbm.xml
07:25:27,387 INF | [Configuration] Configured SessionFactory: null
07:25:27,423 INF | [DriverManagerConnectionProvider] Using Hibernate built-in connection
pool (not for production use!)
07:25:27,425 INF | [DriverManagerConnectionProvider] Hibernate connection pool size: 20
07:25:27,427 INF | [DriverManagerConnectionProvider] autocommit mode: false
07:25:27,429 INF | [DriverManagerConnectionProvider] using driver: org.hsqldb.jdbcDriver
at URL: jdbc:hsqldb:mem:.
07:25:27,430 INF | [DriverManagerConnectionProvider] connection properties: {user=sa,
password=****}
07:25:27,433 INF | [Dialect] Using dialect: org.hibernate.dialect.HSQLDialect
07:25:27,435 INF | [TransactionFactoryFactory] Using default transaction strategy (direct
JDBC transactions)
07:25:27,438 INF | [TransactionManagerLookupFactory] No TransactionManagerLookup
configured (in JTA environment, use of read-write or transactional second-level cache is
not recommended)
07:25:27,440 INF | [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
07:25:27,447 INF | [SessionFactoryImpl] building session factory
07:25:27,666 INF | [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name
configured
07:25:27,673 INF | [SchemaExport] Running hbm2ddl schema export
07:25:27,707 INF | [SchemaExport] exporting generated schema to database
07:25:27,719 INF | [SchemaExport] schema export complete
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.683 sec
Running org.jbpm.examples.task.assignmenthandler.TaskAssignmentHandlerTest
07:25:27,912 FIN | [BaseJbpmTestCase] === starting testTaskAssignmentHandler
=============================
07:25:28,033 FIN | [ProcessDefinitionImpl] creating new execution for process
'TaskAssignmentHandler'
07:25:28,035 FIN | [DefaultIdGenerator] generated execution id TaskAssignmentHandler.1
07:25:28,036 FIN | [ExecuteActivity] executing activity(22326153)
07:25:28,036 FIN | [ExecuteActivity] executing activity(review)
07:25:28,039 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.state != 'suspended' and
task.assignee = :assignee order by task.priority desc
07:25:28,040 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
07:25:28,043 FIN | [HibernatePvmDbSession] deleting process instance
TaskAssignmentHandler.1
07:25:28,045 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
07:25:28,046 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
07:25:28,051 FIN | [BaseJbpmTestCase] === ending testTaskAssignmentHandler
=============================
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.143 sec
Results :
Failed tests:
testOverallActivityReport_Statements(reporting.SQLStmtTest)
testProcessSummaryReport_Statements(reporting.SQLStmtTest)
Tests run: 59, Failures: 2, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[ERROR] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] There are test failures.
Please refer to
http://hudson.qa.jboss.com/hudson/job/jbpm4-base/./jdk=java15_default,lab...
for the individual test results.
[INFO] ------------------------------------------------------------------------
[INFO] For more information, run Maven with the -e switch
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 1 minute 42 seconds
[INFO] Finished at: Fri May 29 07:25:28 PDT 2009
[INFO] Final Memory: 37M/114M
[INFO] ------------------------------------------------------------------------
Recording test results