[jbpm-dev] Build failed in Hudson: jbpm4-base » java15_default,linux #305

Fri Jun 5 08:20:58 EDT 2009

See http://hudson.qa.jboss.com/hudson/job/jbpm4-base/./jdk=java15_default,label=linux/305/changes

Changes:

[jeff.yuchang] * [JBPM-2172] Update the jboss idm version to 1.0.0.Alpha8

[tom.baeyens at jboss.com] added beep at end of test.demo.setup.bat

------------------------------------------
[...truncated 11824 lines...]
08:19:26,200 FIN | [ProcessDefinitionImpl] creating new execution for process 'Hql'
08:19:26,201 FIN | [DefaultIdGenerator] generated execution id Hql.55
08:19:26,201 FIN | [ExecuteActivity] executing activity(379806828)
08:19:26,202 FIN | [ExecuteActivity] executing activity(get task names)
08:19:26,207 FIN | [ScopeInstanceImpl] create variable 'tasknames with i' in 'process-instance' with value '[dishes, iron]'
08:19:26,209 FIN | [ExecuteActivity] executing activity(count tasks)
08:19:26,215 FIN | [ScopeInstanceImpl] create variable 'tasks' in 'process-instance' with value '3'
08:19:26,216 FIN | [ExecuteActivity] executing activity(wait)
08:19:26,251 FIN | [DbSessionImpl] deleting process instance Hql.55
08:19:26,278 SEV | [Db] FIXME: JBPM-2004 3 records left in table JBPM4_HIST_ACTINST
08:19:26,279 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
08:19:26,308 FIN | [BaseJbpmTestCase] === ending testHql =============================

Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.254 sec
08:19:26,327 FIN | [BaseJbpmTestCase] === starting testTimerEventTimerFires =============================
Running org.jbpm.examples.timer.event.TimerEventTest
08:19:26,447 FIN | [ProcessDefinitionImpl] creating new execution for process 'TimerEvent'
08:19:26,452 FIN | [DefaultIdGenerator] generated execution id TimerEvent.56
08:19:26,452 FIN | [ExecuteActivity] executing activity(1372351082)
08:19:26,453 FIN | [Execution] creating execution[guardedWait]
08:19:26,453 FIN | [DefaultIdGenerator] generated execution id TimerEvent.56.guardedWait[0]
08:19:26,453 FIN | [ScopeInstanceImpl] creating timer on execution[guardedWait]
08:19:26,454 FIN | [TimerSession] scheduling timer[0|2009-06-05 08:29:26,453|timeout]
08:19:26,455 FIN | [ExecuteActivity] execution[guardedWait] executes activity(guardedWait)
08:19:26,468 FIN | [ExecuteJobCmd] executing job timer[8|2009-06-05 08:29:26,453|timeout]...
08:19:26,468 FIN | [TimerImpl] executing timer[8|2009-06-05 08:29:26,453|timeout]
08:19:26,473 FIN | [TimerImpl] firing event null into activity(guardedWait)
08:19:26,476 FIN | [ScopeInstanceImpl] create variable 'escalation' in 'process-instance' with value 'true'
08:19:26,477 FIN | [TimerImpl] deleting timer[8|2009-06-05 08:29:26,453|timeout]
08:19:26,478 FIN | [ExecuteJobCmd] executed job timer[8|2009-06-05 08:29:26,453|timeout]
08:19:26,517 FIN | [DbSessionImpl] deleting process instance TimerEvent.56
08:19:26,546 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
08:19:26,547 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
08:19:26,583 FIN | [BaseJbpmTestCase] === ending testTimerEventTimerFires =============================

08:19:26,584 FIN | [BaseJbpmTestCase] === starting testTimerEventContinueBeforeTimerFires =============================
08:19:26,694 FIN | [ProcessDefinitionImpl] creating new execution for process 'TimerEvent'
08:19:26,696 FIN | [DefaultIdGenerator] generated execution id TimerEvent.58
08:19:26,696 FIN | [ExecuteActivity] executing activity(1333433798)
08:19:26,696 FIN | [Execution] creating execution[guardedWait]
08:19:26,697 FIN | [DefaultIdGenerator] generated execution id TimerEvent.58.guardedWait[0]
08:19:26,697 FIN | [ScopeInstanceImpl] creating timer on execution[guardedWait]
08:19:26,697 FIN | [TimerSession] scheduling timer[0|2009-06-05 08:29:26,697|timeout]
08:19:26,699 FIN | [ExecuteActivity] execution[guardedWait] executes activity(guardedWait)
08:19:26,709 FIN | [Signal] execution[guardedWait] signals activity(guardedWait)
08:19:26,711 FIN | [Execution] destroying timers of execution[guardedWait]
08:19:26,713 FIN | [TimerSession] canceling timer[9|2009-06-05 08:29:26,697|timeout]
08:19:26,719 FIN | [Execution] execution[guardedWait] ends
08:19:26,719 FIN | [ExecuteActivity] executing activity(next step)
08:19:26,752 FIN | [DbSessionImpl] deleting process instance TimerEvent.58
08:19:26,765 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
08:19:26,766 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
08:19:26,793 FIN | [BaseJbpmTestCase] === ending testTimerEventContinueBeforeTimerFires =============================

Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.508 sec
08:19:26,852 FIN | [BaseJbpmTestCase] === starting testAsyncActivity =============================
Running org.jbpm.examples.async.activity.AsyncActivityTest
08:19:26,979 FIN | [ProcessDefinitionImpl] creating new execution for process 'AsyncActivity'
08:19:26,980 FIN | [DefaultIdGenerator] generated execution id AsyncActivity.60
08:19:26,981 FIN | [ExecuteActivity] executing activity(898724571)
08:19:26,981 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
08:19:26,994 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[10]...
08:19:27,000 FIN | [ExecuteActivity] executing activity(generate pdf)
08:19:27,007 FIN | [JobExecutorMessageSession] sending message ExecuteActivityMessage
08:19:27,008 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[10]
08:19:27,017 FIN | [ExecuteJobCmd] executing job ExecuteActivityMessage[11]...
08:19:27,025 FIN | [ExecuteActivity] executing activity(calculate primes)
08:19:27,026 FIN | [ExecuteActivity] executing activity(end)
08:19:27,027 FIN | [Execution] process-instance ends with state ended
08:19:27,034 FIN | [DbSessionImpl] deleting process instance AsyncActivity.60
08:19:27,036 FIN | [ExecuteJobCmd] executed job ExecuteActivityMessage[11]
08:19:27,065 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
08:19:27,066 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
08:19:27,094 FIN | [BaseJbpmTestCase] === ending testAsyncActivity =============================

Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.26 sec
08:19:27,115 FIN | [BaseJbpmTestCase] === starting testEndMultipleOk =============================
Running org.jbpm.examples.end.multiple.EndMultipleTest
08:19:27,231 FIN | [ProcessDefinitionImpl] creating new execution for process 'EndMultiple'
08:19:27,232 FIN | [DefaultIdGenerator] generated execution id EndMultiple.61
08:19:27,233 FIN | [ExecuteActivity] executing activity(7216623)
08:19:27,234 FIN | [ExecuteActivity] executing activity(get return code)
08:19:27,242 FIN | [Signal] signalling activity(get return code), signalName=200
08:19:27,244 FIN | [ExecuteActivity] executing activity(ok)
08:19:27,244 FIN | [Execution] process-instance ends with state ended
08:19:27,255 FIN | [DbSessionImpl] deleting process instance EndMultiple.61
08:19:27,309 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
08:19:27,310 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
08:19:27,360 FIN | [BaseJbpmTestCase] === ending testEndMultipleOk =============================

08:19:27,361 FIN | [BaseJbpmTestCase] === starting testEndMultipleBadRequest =============================
08:19:27,433 FIN | [ProcessDefinitionImpl] creating new execution for process 'EndMultiple'
08:19:27,434 FIN | [DefaultIdGenerator] generated execution id EndMultiple.62
08:19:27,435 FIN | [ExecuteActivity] executing activity(944360053)
08:19:27,435 FIN | [ExecuteActivity] executing activity(get return code)
08:19:27,443 FIN | [Signal] signalling activity(get return code), signalName=400
08:19:27,444 FIN | [ExecuteActivity] executing activity(bad request)
08:19:27,444 FIN | [Execution] process-instance ends with state ended
08:19:27,452 FIN | [DbSessionImpl] deleting process instance EndMultiple.62
08:19:27,480 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
08:19:27,481 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
08:19:27,508 FIN | [BaseJbpmTestCase] === ending testEndMultipleBadRequest =============================

08:19:27,509 FIN | [BaseJbpmTestCase] === starting testEndMultipleInternalServerError =============================
08:19:27,569 FIN | [ProcessDefinitionImpl] creating new execution for process 'EndMultiple'
08:19:27,571 FIN | [DefaultIdGenerator] generated execution id EndMultiple.63
08:19:27,571 FIN | [ExecuteActivity] executing activity(991553580)
08:19:27,571 FIN | [ExecuteActivity] executing activity(get return code)
08:19:27,582 FIN | [Signal] signalling activity(get return code), signalName=500
08:19:27,584 FIN | [ExecuteActivity] executing activity(internal server error)
08:19:27,584 FIN | [Execution] process-instance ends with state ended
08:19:27,591 FIN | [DbSessionImpl] deleting process instance EndMultiple.63
08:19:27,619 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
08:19:27,620 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
08:19:27,648 FIN | [BaseJbpmTestCase] === ending testEndMultipleInternalServerError =============================

Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.553 sec
08:19:27,670 FIN | [BaseJbpmTestCase] === starting testSubProcessResultOk =============================
Running org.jbpm.examples.subprocess.outcomeactivity.SubProcessOutcomeActivityTest
08:19:27,804 FIN | [ProcessDefinitionImpl] creating new execution for process 'SubProcessDocument'
08:19:27,805 FIN | [DefaultIdGenerator] generated execution id SubProcessDocument.64
08:19:27,806 FIN | [ExecuteActivity] executing activity(1721500295)
08:19:27,806 FIN | [ExecuteActivity] executing activity(review)
08:19:27,810 FIN | [ProcessDefinitionImpl] creating new execution for process 'SubProcessReview'
08:19:27,811 FIN | [DefaultIdGenerator] generated execution id SubProcessReview.65
08:19:27,812 FIN | [ExecuteActivity] executing activity(1003335204)
08:19:27,812 FIN | [ExecuteActivity] executing activity(get approval)
08:19:27,820 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 
08:19:27,821 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
08:19:27,834 FIN | [Signal] signalling activity(get approval), signalName=ok
08:19:27,837 FIN | [ExecuteActivity] executing activity(ok)
08:19:27,837 FIN | [Execution] process-instance ends with state ended
08:19:27,844 FIN | [Signal] signalling activity(review), signalName=null
08:19:27,844 WRN | [ProxyWarnLog] Narrowing proxy to class org.jbpm.jpdl.internal.model.JpdlExecution - this operation breaks ==
08:19:27,845 FIN | [ExecuteActivity] executing activity(next step)
08:19:27,862 FIN | [DbSessionImpl] deleting process instance SubProcessReview.65
08:19:27,909 FIN | [DbSessionImpl] deleting process instance SubProcessDocument.64
08:19:27,921 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
08:19:27,921 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_PROCINST
08:19:27,946 FIN | [BaseJbpmTestCase] === ending testSubProcessResultOk =============================

08:19:27,947 FIN | [BaseJbpmTestCase] === starting testSubProcessResultNok =============================
08:19:28,064 FIN | [ProcessDefinitionImpl] creating new execution for process 'SubProcessDocument'
08:19:28,065 FIN | [DefaultIdGenerator] generated execution id SubProcessDocument.66
08:19:28,066 FIN | [ExecuteActivity] executing activity(87078426)
08:19:28,066 FIN | [ExecuteActivity] executing activity(review)
08:19:28,070 FIN | [ProcessDefinitionImpl] creating new execution for process 'SubProcessReview'
08:19:28,190 FIN | [DefaultIdGenerator] generated execution id SubProcessReview.67
08:19:28,200 FIN | [ExecuteActivity] executing activity(859014954)
08:19:28,209 FIN | [ExecuteActivity] executing activity(get approval)
08:19:28,232 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 
08:19:28,234 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
08:19:28,246 FIN | [Signal] signalling activity(get approval), signalName=nok
08:19:28,251 FIN | [ExecuteActivity] executing activity(nok)
08:19:28,255 FIN | [Execution] process-instance ends with state ended
08:19:28,264 FIN | [Signal] signalling activity(review), signalName=null
08:19:28,267 WRN | [ProxyWarnLog] Narrowing proxy to class org.jbpm.jpdl.internal.model.JpdlExecution - this operation breaks ==
08:19:28,270 FIN | [ExecuteActivity] executing activity(update)
08:19:28,285 FIN | [DbSessionImpl] deleting process instance SubProcessReview.67
08:19:28,396 FIN | [DbSessionImpl] deleting process instance SubProcessDocument.66
08:19:28,408 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
08:19:28,411 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_PROCINST
08:19:28,556 FIN | [BaseJbpmTestCase] === ending testSubProcessResultNok =============================

08:19:28,559 FIN | [BaseJbpmTestCase] === starting testSubProcessResultReject =============================
08:19:28,907 FIN | [ProcessDefinitionImpl] creating new execution for process 'SubProcessDocument'
08:19:28,912 FIN | [DefaultIdGenerator] generated execution id SubProcessDocument.68
08:19:28,915 FIN | [ExecuteActivity] executing activity(924505996)
08:19:28,918 FIN | [ExecuteActivity] executing activity(review)
08:19:28,925 FIN | [ProcessDefinitionImpl] creating new execution for process 'SubProcessReview'
08:19:28,929 FIN | [DefaultIdGenerator] generated execution id SubProcessReview.69
08:19:28,932 FIN | [ExecuteActivity] executing activity(2038170764)
08:19:28,934 FIN | [ExecuteActivity] executing activity(get approval)
08:19:28,944 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 
08:19:28,946 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
08:19:28,957 FIN | [Signal] signalling activity(get approval), signalName=reject
08:19:28,961 FIN | [ExecuteActivity] executing activity(reject)
08:19:28,964 FIN | [Execution] process-instance ends with state ended
08:19:28,972 FIN | [Signal] signalling activity(review), signalName=null
08:19:28,975 WRN | [ProxyWarnLog] Narrowing proxy to class org.jbpm.jpdl.internal.model.JpdlExecution - this operation breaks ==
08:19:28,979 FIN | [ExecuteActivity] executing activity(close)
08:19:29,122 FIN | [DbSessionImpl] deleting process instance SubProcessReview.69
08:19:29,349 FIN | [DbSessionImpl] deleting process instance SubProcessDocument.68
08:19:29,499 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_ACTINST
08:19:29,508 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM4_HIST_PROCINST
08:19:29,682 FIN | [BaseJbpmTestCase] === ending testSubProcessResultReject =============================

Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.037 sec
Running org.jbpm.examples.services.ServicesTest
08:19:29,939 INF | [Configuration] configuring from resource: jbpm.hibernate.cfg.xml
08:19:29,952 INF | [Configuration] Configuration resource: jbpm.hibernate.cfg.xml
08:19:29,983 INF | [Configuration] Reading mappings from resource : jbpm.repository.hbm.xml
08:19:30,136 INF | [Configuration] Reading mappings from resource : jbpm.execution.hbm.xml
08:19:30,342 INF | [Configuration] Reading mappings from resource : jbpm.history.hbm.xml
08:19:30,520 INF | [Configuration] Reading mappings from resource : jbpm.task.hbm.xml
08:19:30,700 INF | [Configuration] Reading mappings from resource : jbpm.jpdl.hbm.xml
08:19:30,739 INF | [Configuration] Reading mappings from resource : jbpm.identity.hbm.xml
08:19:30,902 INF | [Configuration] Configured SessionFactory: null
08:19:30,919 INF | [DriverManagerConnectionProvider] Using Hibernate built-in connection pool (not for production use!)
08:19:30,927 INF | [DriverManagerConnectionProvider] Hibernate connection pool size: 20
08:19:30,936 INF | [DriverManagerConnectionProvider] autocommit mode: false
08:19:30,946 INF | [DriverManagerConnectionProvider] using driver: org.hsqldb.jdbcDriver at URL: jdbc:hsqldb:mem:.
08:19:30,952 INF | [DriverManagerConnectionProvider] connection properties: {user=sa, password=****}
08:19:30,960 INF | [Dialect] Using dialect: org.hibernate.dialect.HSQLDialect
08:19:30,966 INF | [TransactionFactoryFactory] Using default transaction strategy (direct JDBC transactions)
08:19:30,972 INF | [TransactionManagerLookupFactory] No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
08:19:30,978 INF | [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
08:19:31,112 INF | [SessionFactoryImpl] building session factory
08:19:31,671 INF | [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
08:19:31,679 INF | [SchemaExport] Running hbm2ddl schema export
08:19:31,683 INF | [SchemaExport] exporting generated schema to database
08:19:31,724 INF | [SchemaExport] schema export complete
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.696 sec
Running org.jbpm.examples.task.assignmenthandler.TaskAssignmentHandlerTest
08:19:32,423 FIN | [BaseJbpmTestCase] === starting testTaskAssignmentHandler =============================
08:19:32,917 FIN | [ProcessDefinitionImpl] creating new execution for process 'TaskAssignmentHandler'
08:19:32,926 FIN | [DefaultIdGenerator] generated execution id TaskAssignmentHandler.1
08:19:32,936 FIN | [ExecuteActivity] executing activity(147520740)
08:19:32,945 FIN | [ExecuteActivity] executing activity(review)
08:19:32,967 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 
08:19:32,974 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
08:19:33,121 FIN | [DbSessionImpl] deleting process instance TaskAssignmentHandler.1
08:19:33,154 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_ACTINST
08:19:33,167 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM4_HIST_PROCINST
08:19:33,344 FIN | [BaseJbpmTestCase] === ending testTaskAssignmentHandler =============================

Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.938 sec

Results :

Tests in error: 
  testTemplateMail(org.jbpm.examples.mail.template.TemplateMailTest)

Tests run: 52, Failures: 0, Errors: 1, Skipped: 0

[INFO] ------------------------------------------------------------------------
[ERROR] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] There are test failures.

Please refer to /qa/services/hudson/hudson_workspace/workspace/jbpm4-base/jdk/java15_default/label/linux/jbpm4/modules/examples/target/surefire-reports for the individual test results.
[INFO] ------------------------------------------------------------------------
[INFO] For more information, run Maven with the -e switch
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 6 minutes 4 seconds
[INFO] Finished at: Fri Jun 05 08:19:33 EDT 2009
[INFO] Final Memory: 60M/143M
[INFO] ------------------------------------------------------------------------
Recording test results