10:55 a.m.
See http://hudson.qa.jboss.com/hudson/job/jbpm4-base/./jdk=jrockit16,label=li...
------------------------------------------
[...truncated 4332 lines...]
at org.jbpm.pvm.internal.cmd.DeployCmd.execute(DeployCmd.java:33)
at
org.jbpm.pvm.internal.svc.DefaultCommandService.execute(DefaultCommandService.java:42)
at
org.jbpm.pvm.internal.tx.StandardTransactionInterceptor.execute(StandardTransactionInterceptor.java:54)
at
org.jbpm.pvm.internal.svc.EnvironmentInterceptor.execute(EnvironmentInterceptor.java:54)
at org.jbpm.pvm.internal.svc.RetryInterceptor.execute(RetryInterceptor.java:55)
at org.jbpm.pvm.internal.repository.DeploymentImpl.deploy(DeploymentImpl.java:81)
at
org.jbpm.examples.subprocess.outcomeactivity.SubProcessOutcomeActivityTest.setUp(SubProcessOutcomeActivityTest.java:42)
at junit.framework.TestCase.runBare(TestCase.java:125)
at junit.framework.TestResult$1.protect(TestResult.java:106)
at junit.framework.TestResult.runProtected(TestResult.java:124)
at junit.framework.TestResult.run(TestResult.java:109)
at junit.framework.TestCase.run(TestCase.java:118)
at junit.framework.TestSuite.runTest(TestSuite.java:208)
at junit.framework.TestSuite.run(TestSuite.java:203)
at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.maven.surefire.junit.JUnitTestSet.execute(JUnitTestSet.java:213)
at
org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140)
at
org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:127)
at org.apache.maven.surefire.Surefire.run(Surefire.java:177)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:338)
at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:997)
Caused by: org.jbpm.api.JbpmException
at org.jbpm.pvm.internal.xml.ProblemList.getJbpmException(ProblemList.java:165)
... 30 more
Caused by: org.xml.sax.SAXParseException: Element type "end" must be followed by
either attribute specifications, ">" or "/>".
at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1231)
at
com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:522)
at org.jbpm.pvm.internal.xml.Parser.buildDom(Parser.java:451)
at org.jbpm.pvm.internal.xml.Parser.execute(Parser.java:387)
at org.jbpm.pvm.internal.xml.Parse.execute(Parse.java:157)
at org.jbpm.jpdl.internal.repository.JpdlDeployer.deploy(JpdlDeployer.java:62)
at org.jbpm.pvm.internal.repository.DeployerManager.deploy(DeployerManager.java:36)
at
org.jbpm.pvm.internal.repository.RepositorySessionImpl.deploy(RepositorySessionImpl.java:55)
... 28 more
### EXCEPTION ###########################################
Tests run: 3, Failures: 0, Errors: 3, Skipped: 0, Time elapsed: 0.069 sec <<<
FAILURE!
Running org.jbpm.examples.end.processinstance.EndProcessInstanceTest
11:55:09,538 FIN | [BaseJbpmTestCase] === starting testEndProcessInstance
=============================
11:55:09,569 FIN | [ProcessDefinitionImpl] creating new execution for process
'EndProcessInstance'
11:55:09,570 FIN | [DefaultIdGenerator] generated execution id EndProcessInstance.43
11:55:09,571 FIN | [TakeTransition] taking -->(end)
11:55:09,571 FIN | [Execution] process-instance ends with state ended
11:55:09,572 FIN | [HibernatePvmDbSession] deleting process instance
EndProcessInstance.43
11:55:09,581 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:09,585 FIN | [BaseJbpmTestCase] === ending testEndProcessInstance
=============================
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.053 sec
Running org.jbpm.examples.timer.event.TimerEventTest
11:55:09,592 FIN | [BaseJbpmTestCase] === starting testTimerEventTimerFires
=============================
11:55:09,634 FIN | [ProcessDefinitionImpl] creating new execution for process
'TimerEvent'
11:55:09,637 FIN | [DefaultIdGenerator] generated execution id TimerEvent.44
11:55:09,638 FIN | [TakeTransition] taking -->(guardedWait)
11:55:09,639 FIN | [Execution] creating execution[guardedWait]
11:55:09,640 FIN | [DefaultIdGenerator] generated execution id
TimerEvent.44.guardedWait[0]
11:55:09,641 FIN | [ScopeInstanceImpl] creating timer on execution[guardedWait]
11:55:09,643 FIN | [TimerSession] scheduling timer[0|2009-05-04 12:05:09,643|timeout]
11:55:09,652 FIN | [ExecuteJobCmd] executing job timer[4|2009-05-04
12:05:09,643|timeout]...
11:55:09,653 FIN | [TimerImpl] executing timer[4|2009-05-04 12:05:09,643|timeout]
11:55:09,656 FIN | [TimerImpl] firing event null into activity(guardedWait)
11:55:09,695 FIN | [ScopeInstanceImpl] create variable 'escalation' in
'process-instance' with value 'true'
11:55:09,698 FIN | [TimerImpl] deleting timer[4|2009-05-04 12:05:09,643|timeout]
11:55:09,700 FIN | [ExecuteJobCmd] executed job timer[4|2009-05-04 12:05:09,643|timeout]
11:55:09,719 FIN | [HibernatePvmDbSession] deleting process instance TimerEvent.44
11:55:09,722 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_ACTINST
11:55:09,723 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:09,726 FIN | [BaseJbpmTestCase] === ending testTimerEventTimerFires
=============================
11:55:09,728 FIN | [BaseJbpmTestCase] === starting testTimerEventContinueBeforeTimerFires
=============================
11:55:09,737 FIN | [ProcessDefinitionImpl] creating new execution for process
'TimerEvent'
11:55:09,738 FIN | [DefaultIdGenerator] generated execution id TimerEvent.46
11:55:09,739 FIN | [TakeTransition] taking -->(guardedWait)
11:55:09,739 FIN | [Execution] creating execution[guardedWait]
11:55:09,739 FIN | [DefaultIdGenerator] generated execution id
TimerEvent.46.guardedWait[0]
11:55:09,740 FIN | [ScopeInstanceImpl] creating timer on execution[guardedWait]
11:55:09,741 FIN | [TimerSession] scheduling timer[0|2009-05-04 12:05:09,740|timeout]
11:55:09,743 FIN | [Signal] execution[guardedWait] signals activity(guardedWait)
11:55:09,743 FIN | [TakeTransition] execution[guardedWait] takes (guardedWait)--go
on-->(next step)
11:55:09,744 FIN | [ScopeInstanceImpl] destroying timers of execution[guardedWait]
11:55:09,745 FIN | [TimerSession] canceling timer[5|2009-05-04 12:05:09,740|timeout]
11:55:09,746 FIN | [Execution] execution[guardedWait] ends
11:55:09,757 FIN | [HibernatePvmDbSession] deleting process instance TimerEvent.46
11:55:09,759 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM_HIST_ACTINST
11:55:09,759 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:09,763 FIN | [BaseJbpmTestCase] === ending testTimerEventContinueBeforeTimerFires
=============================
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.177 sec
Running org.jbpm.examples.esb.EsbTest
11:55:09,776 FIN | [BaseJbpmTestCase] === starting testEsb =============================
11:55:09,865 FIN | [ProcessDefinitionImpl] creating new execution for process
'Esb'
11:55:09,866 FIN | [DefaultIdGenerator] generated execution id Esb.48
11:55:09,867 FIN | [ScopeInstanceImpl] create variable 'title' in
'process-instance' with value 'Internetworking with TCP/IP'
11:55:09,868 FIN | [TakeTransition] taking -->(invoke esb service)
log4j:WARN No appenders could be found for logger
(org.jboss.soa.esb.services.registry.RegistryFactory).
log4j:WARN Please initialize the log4j system properly.
11:55:10,109 FIN | [EsbActivity] sending body: [ objects: {goal=deliver asap,
bookTitle=Internetworking with TCP/IP} ] to service bookSold in category orderProcessing
over the esb
11:55:10,125 FIN | [TakeTransition] taking (invoke esb service)-->(wait)
11:55:10,135 FIN | [HibernatePvmDbSession] deleting process instance Esb.48
11:55:10,138 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM_HIST_ACTINST
11:55:10,138 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:10,142 FIN | [BaseJbpmTestCase] === ending testEsb =============================
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.377 sec
Running org.jbpm.examples.state.sequence.StateSequenceTest
11:55:10,148 FIN | [BaseJbpmTestCase] === starting testWaitStatesSequence
=============================
11:55:10,177 FIN | [ProcessDefinitionImpl] creating new execution for process
'StateSequence'
11:55:10,178 FIN | [DefaultIdGenerator] generated execution id StateSequence.49
11:55:10,179 FIN | [TakeTransition] taking -->(a)
11:55:10,180 FIN | [Signal] signalling activity(a), signal=null
11:55:10,181 FIN | [TakeTransition] taking (a)-->(b)
11:55:10,182 FIN | [Signal] signalling activity(b), signal=null
11:55:10,183 FIN | [TakeTransition] taking (b)-->(c)
11:55:10,192 FIN | [HibernatePvmDbSession] deleting process instance StateSequence.49
11:55:10,194 SEV | [Db] FIXME: JBPM-2004 3 records left in table JBPM_HIST_ACTINST
11:55:10,195 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:10,200 FIN | [BaseJbpmTestCase] === ending testWaitStatesSequence
=============================
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.058 sec
Running org.jbpm.examples.decision.conditions.DecisionConditionsTest
11:55:10,207 FIN | [BaseJbpmTestCase] === starting testDecisionConditionsGood
=============================
11:55:10,231 FIN | [ProcessDefinitionImpl] creating new execution for process
'DecisionConditions'
11:55:10,231 FIN | [DefaultIdGenerator] generated execution id DecisionConditions.50
11:55:10,232 FIN | [ScopeInstanceImpl] create variable 'content' in
'process-instance' with value 'good'
11:55:10,232 FIN | [TakeTransition] taking -->(evaluate document)
11:55:10,242 FIN | [TakeTransition] taking (evaluate document)-->(submit document)
11:55:10,249 FIN | [HibernatePvmDbSession] deleting process instance
DecisionConditions.50
11:55:10,251 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_ACTINST
11:55:10,251 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:10,255 FIN | [BaseJbpmTestCase] === ending testDecisionConditionsGood
=============================
11:55:10,255 FIN | [BaseJbpmTestCase] === starting testDecisionConditionsBad
=============================
11:55:10,264 FIN | [ProcessDefinitionImpl] creating new execution for process
'DecisionConditions'
11:55:10,266 FIN | [DefaultIdGenerator] generated execution id DecisionConditions.51
11:55:10,267 FIN | [ScopeInstanceImpl] create variable 'content' in
'process-instance' with value 'bad'
11:55:10,269 FIN | [TakeTransition] taking -->(evaluate document)
11:55:10,273 FIN | [TakeTransition] taking (evaluate document)-->(try again)
11:55:10,291 FIN | [HibernatePvmDbSession] deleting process instance
DecisionConditions.51
11:55:10,295 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_ACTINST
11:55:10,298 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:10,304 FIN | [BaseJbpmTestCase] === ending testDecisionConditionsBad
=============================
11:55:10,306 FIN | [BaseJbpmTestCase] === starting testDecisionConditionsUgly
=============================
11:55:10,319 FIN | [ProcessDefinitionImpl] creating new execution for process
'DecisionConditions'
11:55:10,321 FIN | [DefaultIdGenerator] generated execution id DecisionConditions.52
11:55:10,322 FIN | [ScopeInstanceImpl] create variable 'content' in
'process-instance' with value 'ugly'
11:55:10,323 FIN | [TakeTransition] taking -->(evaluate document)
11:55:10,325 FIN | [TakeTransition] taking (evaluate document)-->(give up)
11:55:10,367 FIN | [HibernatePvmDbSession] deleting process instance
DecisionConditions.52
11:55:10,371 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_ACTINST
11:55:10,372 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:10,378 FIN | [BaseJbpmTestCase] === ending testDecisionConditionsUgly
=============================
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.202 sec
Running org.jbpm.examples.task.candidates.TaskCandidatesTest
11:55:10,410 FIN | [BaseJbpmTestCase] === starting testGroupCandidateAssignment
=============================
11:55:10,447 FIN | [ProcessDefinitionImpl] creating new execution for process
'TaskCandidates'
11:55:10,449 FIN | [DefaultIdGenerator] generated execution id TaskCandidates.53
11:55:10,449 FIN | [TakeTransition] taking -->(review)
11:55:10,449 FIN | [ProcessDefinitionImpl] creating new execution for process
'TaskLifeCycle'
11:55:10,451 FIN | [ScopeInstanceImpl] create variable 'task' in
'process-instance' with value 'Task(null)'
11:55:10,460 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task , org.jbpm.pvm.internal.task.ParticipationImpl
as participant where participant.task = task and participant.type = 'candidate'
and (participant.userId = :candidateUserId) or (participant.groupId in
(:candidateGroupIds) ) and task.assignee is null order by task.priority desc
11:55:10,470 FIN | [TaskQueryImpl] setting parameter candidateUserId: johndoe
11:55:10,471 FIN | [TaskQueryImpl] setting parameter candidateGroupIds: [sales-dept]
11:55:10,480 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task , org.jbpm.pvm.internal.task.ParticipationImpl
as participant where participant.task = task and participant.type = 'candidate'
and (participant.userId = :candidateUserId) or (participant.groupId in
(:candidateGroupIds) ) and task.assignee is null order by task.priority desc
11:55:10,481 FIN | [TaskQueryImpl] setting parameter candidateUserId: joesmoe
11:55:10,482 FIN | [TaskQueryImpl] setting parameter candidateGroupIds: [sales-dept]
11:55:10,483 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.assignee = :assignee order by
task.priority desc
11:55:10,483 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
11:55:10,484 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.assignee = :assignee order by
task.priority desc
11:55:10,484 FIN | [TaskQueryImpl] setting parameter assignee: joesmoe
11:55:10,488 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task , org.jbpm.pvm.internal.task.ParticipationImpl
as participant where participant.task = task and participant.type = 'candidate'
and (participant.userId = :candidateUserId) or (participant.groupId in
(:candidateGroupIds) ) and task.assignee is null order by task.priority desc
11:55:10,489 FIN | [TaskQueryImpl] setting parameter candidateUserId: johndoe
11:55:10,489 FIN | [TaskQueryImpl] setting parameter candidateGroupIds: [sales-dept]
11:55:10,491 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task , org.jbpm.pvm.internal.task.ParticipationImpl
as participant where participant.task = task and participant.type = 'candidate'
and (participant.userId = :candidateUserId) or (participant.groupId in
(:candidateGroupIds) ) and task.assignee is null order by task.priority desc
11:55:10,491 FIN | [TaskQueryImpl] setting parameter candidateUserId: joesmoe
11:55:10,491 FIN | [TaskQueryImpl] setting parameter candidateGroupIds: [sales-dept]
11:55:10,493 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.assignee = :assignee order by
task.priority desc
11:55:10,494 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
11:55:10,495 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.assignee = :assignee order by
task.priority desc
11:55:10,497 FIN | [TaskQueryImpl] setting parameter assignee: joesmoe
11:55:10,499 FIN | [Signal] signalling activity(review), signal=null
11:55:10,500 FIN | [TakeTransition] taking (review)-->(wait)
11:55:10,501 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.assignee = :assignee order by
task.priority desc
11:55:10,501 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
11:55:10,511 FIN | [HibernatePvmDbSession] deleting process instance TaskCandidates.53
11:55:10,524 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM_HIST_ACTINST
11:55:10,524 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:10,528 FIN | [BaseJbpmTestCase] === ending testGroupCandidateAssignment
=============================
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.123 sec
Running org.jbpm.examples.task.swimlane.TaskSwimlaneTest
11:55:10,534 FIN | [BaseJbpmTestCase] === starting testTaskSwimlane
=============================
11:55:10,569 FIN | [ProcessDefinitionImpl] creating new execution for process
'TaskSwimlane'
11:55:10,570 FIN | [DefaultIdGenerator] generated execution id TaskSwimlane.54
11:55:10,571 FIN | [TakeTransition] taking -->(enter order data)
11:55:10,572 FIN | [ProcessDefinitionImpl] creating new execution for process
'TaskLifeCycle'
11:55:10,573 FIN | [ScopeInstanceImpl] create variable 'task' in
'process-instance' with value 'Task(null)'
11:55:10,578 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task , org.jbpm.pvm.internal.task.ParticipationImpl
as participant where participant.task = task and participant.type = 'candidate'
and (participant.userId = :candidateUserId) or (participant.groupId in
(:candidateGroupIds) ) and task.assignee is null order by task.priority desc
11:55:10,579 FIN | [TaskQueryImpl] setting parameter candidateUserId: johndoe
11:55:10,579 FIN | [TaskQueryImpl] setting parameter candidateGroupIds: [sales-dept]
11:55:10,583 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.assignee = :assignee order by
task.priority desc
11:55:10,584 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
11:55:10,588 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task , org.jbpm.pvm.internal.task.ParticipationImpl
as participant where participant.task = task and participant.type = 'candidate'
and (participant.userId = :candidateUserId) or (participant.groupId in
(:candidateGroupIds) ) and task.assignee is null order by task.priority desc
11:55:10,588 FIN | [TaskQueryImpl] setting parameter candidateUserId: johndoe
11:55:10,589 FIN | [TaskQueryImpl] setting parameter candidateGroupIds: [sales-dept]
11:55:10,589 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.assignee = :assignee order by
task.priority desc
11:55:10,590 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
11:55:10,591 FIN | [Signal] signalling activity(enter order data), signal=null
11:55:10,592 FIN | [TakeTransition] taking (enter order data)-->(calculate quote)
11:55:10,593 WRN | [ProxyWarnLog] Narrowing proxy to class
org.jbpm.jpdl.internal.model.JpdlExecution - this operation breaks ==
11:55:10,594 FIN | [ProcessDefinitionImpl] creating new execution for process
'TaskLifeCycle'
11:55:10,594 FIN | [ScopeInstanceImpl] create variable 'task' in
'process-instance' with value 'Task(null)'
11:55:10,598 FIN | [TaskQueryImpl] select distinct task from
org.jbpm.pvm.internal.task.TaskImpl as task where task.assignee = :assignee order by
task.priority desc
11:55:10,599 FIN | [TaskQueryImpl] setting parameter assignee: johndoe
11:55:10,607 FIN | [HibernatePvmDbSession] deleting process instance TaskSwimlane.54
11:55:10,611 SEV | [Db] FIXME: JBPM-2004 2 records left in table JBPM_HIST_ACTINST
11:55:10,612 SEV | [Db] FIXME: JBPM-2004 1 records left in table JBPM_HIST_PROCINST
11:55:10,618 FIN | [BaseJbpmTestCase] === ending testTaskSwimlane
=============================
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.09 sec
Results :
Tests in error:
testSubProcessResultOk(org.jbpm.examples.subprocess.outcomeactivity.SubProcessOutcomeActivityTest)
testSubProcessResultNok(org.jbpm.examples.subprocess.outcomeactivity.SubProcessOutcomeActivityTest)
testSubProcessResultReject(org.jbpm.examples.subprocess.outcomeactivity.SubProcessOutcomeActivityTest)
Tests run: 48, Failures: 0, Errors: 3, 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=jrockit16,label=li...
for the individual test results.
[INFO] ------------------------------------------------------------------------
[INFO] For more information, run Maven with the -e switch
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 1 minute 24 seconds
[INFO] Finished at: Mon May 04 11:55:11 EDT 2009
[INFO] Final Memory: 68M/87M
[INFO] ------------------------------------------------------------------------
Recording test results