See http://hudson.qa.jboss.com/hudson/job/jboss-esb-linux/1020/changes Changes: [mark.little(a)jboss.com] http://jira.jboss.com/jira/browse/JBESB-1686 ------------------------------------------ [...truncated 10068 lines...] [java] [junit] 09:37:15,725 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'before-signal' on 'State(wait1)' for 'Token(/)' [java] [junit] 09:37:15,725 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'node-leave' on 'State(wait1)' for 'Token(/)' [java] [junit] 09:37:15,726 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] executing action 'CancelTimerAction(1909385)' [java] [junit] 09:37:15,726 DEBUG [JbpmJobExector:10.18.0.113:1][Token] token[1] is locked by token[1] [java] [junit] 09:37:15,728 WARN [JbpmJobExector:10.18.0.113:1][ProxyWarnLog] Narrowing proxy to class org.jbpm.job.Timer - this operation breaks == [java] [junit] 09:37:15,728 DEBUG [JbpmJobExector:10.18.0.113:1][JobSession] deleting timer timer(wait1,08-07-02 09:37:15,696,Token: 1) by name wait1 [java] [junit] 09:37:15,730 DEBUG [JbpmJobExector:10.18.0.113:1][Token] token[1] is unlocked by token[1] [java] [junit] 09:37:15,730 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'transition' on 'Transition(continue)' for 'Token(/)' [java] [junit] 09:37:15,732 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'node-enter' on 'Node(mynode)' for 'Token(/)' [java] [junit] 09:37:15,734 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'node-leave' on 'Node(mynode)' for 'Token(/)' [java] [junit] 09:37:15,734 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'transition' on 'Transition(toWait2)' for 'Token(/)' [java] [junit] 09:37:15,736 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'node-enter' on 'State(wait2)' for 'Token(/)' [java] [junit] 09:37:15,737 WARN [JbpmJobExector:10.18.0.113:1][ProxyWarnLog] Narrowing proxy to class org.jbpm.graph.node.State - this operation breaks == [java] [junit] 09:37:15,741 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] executing action 'CreateTimerAction(15b4ad2)' [java] [junit] 09:37:15,741 DEBUG [JbpmJobExector:10.18.0.113:1][Token] token[1] is locked by token[1] [java] [junit] 09:37:15,741 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'timer-create' on 'State(wait2)' for 'Token(/)' [java] [junit] 09:37:15,742 DEBUG [JbpmJobExector:10.18.0.113:1][Token] token[1] is unlocked by token[1] [java] [junit] 09:37:15,742 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'after-signal' on 'State(wait1)' for 'Token(/)' [java] [junit] 09:37:15,742 DEBUG [JbpmJobExector:10.18.0.113:1][Services] executing default save operations [java] [junit] 09:37:15,742 DEBUG [JbpmJobExector:10.18.0.113:1][HibernateSaveOperation] saving process instance [java] [junit] 09:37:15,743 DEBUG [JbpmJobExector:10.18.0.113:1][SaveLogsOperation] flushing logs to logging service. [java] [junit] 09:37:15,747 DEBUG [JbpmJobExector:10.18.0.113:1][CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance@1b5a40a' [java] [junit] 09:37:15,747 DEBUG [JbpmJobExector:10.18.0.113:1][JobSession] deleting timer(wait1,08-07-02 09:37:15,696,Token: 1) [java] [junit] 09:37:15,747 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@43153c [java] [junit] 09:37:15,747 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@1798928 [java] [junit] 09:37:15,747 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@273f4e [java] [junit] 09:37:15,751 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] closing hibernate session [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'tx': org.jbpm.tx.TxService@1a5e65f [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'scheduler': org.jbpm.scheduler.db.DbSchedulerService@b79701 [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@11adeb7 [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] acquiring jobs for execution... [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] creating org.jbpm.JbpmContext@113e8f3 [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] creating hibernate session [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@22e177 [java] [junit] 09:37:15,752 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] querying for acquirable job... [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] no acquirable jobs in job table [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@113e8f3 [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@5e9f1 [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@22e177 [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] closing hibernate session [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'tx': org.jbpm.tx.TxService@41f227 [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] obtained locks on following jobs: [] [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] creating org.jbpm.JbpmContext@1811e2c [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] creating hibernate session [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:15,753 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@1e40274 [java] [junit] 09:37:15,754 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@1811e2c [java] [junit] 09:37:15,754 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@1d978ea [java] [junit] 09:37:15,754 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@1e40274 [java] [junit] 09:37:15,754 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] closing hibernate session [java] [junit] 09:37:15,754 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'tx': org.jbpm.tx.TxService@916f80 [java] [junit] 09:37:16,721 DEBUG [main][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:16,721 DEBUG [main][JbpmContext] creating org.jbpm.JbpmContext@2f4813 [java] [junit] 09:37:16,721 DEBUG [main][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:16,721 DEBUG [main][DbPersistenceService] creating hibernate session [java] [junit] 09:37:16,721 DEBUG [main][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:16,721 DEBUG [main][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@24eafa [java] [junit] 2 wait2 [java] [junit] 09:37:16,726 DEBUG [main][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@2f4813 [java] [junit] 09:37:16,726 DEBUG [main][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@16136f0 [java] [junit] 09:37:16,726 DEBUG [main][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@24eafa [java] [junit] 09:37:16,726 DEBUG [main][DbPersistenceService] closing hibernate session [java] [junit] 09:37:16,726 DEBUG [main][Services] closing service 'tx': org.jbpm.tx.TxService@5c2a25 [java] [junit] 09:37:17,731 DEBUG [main][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:17,731 DEBUG [main][JbpmContext] creating org.jbpm.JbpmContext@d2efa1 [java] [junit] 09:37:17,731 DEBUG [main][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:17,731 DEBUG [main][DbPersistenceService] creating hibernate session [java] [junit] 09:37:17,731 DEBUG [main][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:17,732 DEBUG [main][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@725967 [java] [junit] 3 wait2 [java] [junit] 09:37:17,733 DEBUG [main][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@d2efa1 [java] [junit] 09:37:17,734 DEBUG [main][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@1e94001 [java] [junit] 09:37:17,734 DEBUG [main][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@725967 [java] [junit] 09:37:17,734 DEBUG [main][DbPersistenceService] closing hibernate session [java] [junit] 09:37:17,736 DEBUG [main][Services] closing service 'tx': org.jbpm.tx.TxService@1b0de2e [java] [junit] 09:37:17,743 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] acquiring jobs for execution... [java] [junit] 09:37:17,743 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:17,743 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] creating org.jbpm.JbpmContext@cad437 [java] [junit] 09:37:17,743 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:17,743 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] creating hibernate session [java] [junit] 09:37:17,744 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:17,744 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@329572 [java] [junit] 09:37:17,744 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] querying for acquirable job... [java] [junit] 09:37:17,759 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] trying to obtain a lock for 'timer(wait2,08-07-02 09:37:17,741,Token: 1)' [java] [junit] 09:37:17,761 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@cad437 [java] [junit] 09:37:17,761 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@1d1fc02 [java] [junit] 09:37:17,761 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@329572 [java] [junit] 09:37:17,767 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] closing hibernate session [java] [junit] 09:37:17,767 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'tx': org.jbpm.tx.TxService@f70ee1 [java] [junit] 09:37:17,767 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] obtained locks on following jobs: [timer(wait2,08-07-02 09:37:17,741,Token: 1)] [java] [junit] 09:37:17,767 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:17,767 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] creating org.jbpm.JbpmContext@1f1e39b [java] [junit] 09:37:17,767 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:17,767 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] creating hibernate session [java] [junit] 09:37:17,768 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:17,768 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@195ff24 [java] [junit] 09:37:17,773 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] executing job timer(wait2,08-07-02 09:37:17,741,Token: 1) [java] [junit] 09:37:17,780 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'before-signal' on 'State(wait2)' for 'Token(/)' [java] [junit] 09:37:17,780 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'node-leave' on 'State(wait2)' for 'Token(/)' [java] [junit] 09:37:17,785 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] executing action 'CancelTimerAction(12beeec)' [java] [junit] 09:37:17,785 DEBUG [JbpmJobExector:10.18.0.113:1][Token] token[1] is locked by token[1] [java] [junit] 09:37:17,793 WARN [JbpmJobExector:10.18.0.113:1][ProxyWarnLog] Narrowing proxy to class org.jbpm.job.Timer - this operation breaks == [java] [junit] 09:37:17,793 DEBUG [JbpmJobExector:10.18.0.113:1][JobSession] deleting timer timer(wait2,08-07-02 09:37:17,741,Token: 1) by name wait2 [java] [junit] 09:37:17,794 DEBUG [JbpmJobExector:10.18.0.113:1][Token] token[1] is unlocked by token[1] [java] [junit] 09:37:17,794 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'transition' on 'Transition(continue)' for 'Token(/)' [java] [junit] 09:37:17,802 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'node-enter' on 'EndState(end)' for 'Token(/)' [java] [junit] 09:37:17,807 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'process-end' on 'ProcessDefinition(testTimer)' for 'Token(/)' [java] [junit] 09:37:17,808 DEBUG [JbpmJobExector:10.18.0.113:1][GraphElement] event 'after-signal' on 'State(wait2)' for 'Token(/)' [java] [junit] 09:37:17,808 DEBUG [JbpmJobExector:10.18.0.113:1][Services] executing default save operations [java] [junit] 09:37:17,808 DEBUG [JbpmJobExector:10.18.0.113:1][HibernateSaveOperation] saving process instance [java] [junit] 09:37:17,809 DEBUG [JbpmJobExector:10.18.0.113:1][SaveLogsOperation] flushing logs to logging service. [java] [junit] 09:37:17,813 DEBUG [JbpmJobExector:10.18.0.113:1][CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance@11650d6' [java] [junit] 09:37:17,813 DEBUG [JbpmJobExector:10.18.0.113:1][JobSession] deleting timer(wait2,08-07-02 09:37:17,741,Token: 1) [java] [junit] 09:37:17,813 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@1f1e39b [java] [junit] 09:37:17,813 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@1e26602 [java] [junit] 09:37:17,813 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@195ff24 [java] [junit] 09:37:17,818 DEBUG [JbpmJobExector:10.18.0.113:1][JobSession] deleting timers for process instance org.jbpm.graph.exe.ProcessInstance@11650d6 [java] [junit] 09:37:17,823 DEBUG [JbpmJobExector:10.18.0.113:1][JobSession] 0 remaining timers for 'org.jbpm.graph.exe.ProcessInstance@11650d6' are deleted [java] [junit] 09:37:17,823 DEBUG [JbpmJobExector:10.18.0.113:1][JobSession] deleting execute-node-jobs for process instance org.jbpm.graph.exe.ProcessInstance@11650d6 [java] [junit] 09:37:17,824 DEBUG [JbpmJobExector:10.18.0.113:1][JobSession] 0 remaining execute-node-jobs for 'org.jbpm.graph.exe.ProcessInstance@11650d6' are deleted [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] closing hibernate session [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'tx': org.jbpm.tx.TxService@9e75f6 [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'scheduler': org.jbpm.scheduler.db.DbSchedulerService@15291cd [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@1e22c75 [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] acquiring jobs for execution... [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] creating org.jbpm.JbpmContext@1d4eeb5 [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] creating hibernate session [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@83e35b [java] [junit] 09:37:17,828 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] querying for acquirable job... [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] no acquirable jobs in job table [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@1d4eeb5 [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@a2d304 [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@83e35b [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] closing hibernate session [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'tx': org.jbpm.tx.TxService@1cbd4f7 [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][JobExecutorThread] obtained locks on following jobs: [] [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] creating org.jbpm.JbpmContext@10ade7e [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] creating hibernate session [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:17,830 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@956254 [java] [junit] 09:37:17,831 DEBUG [JbpmJobExector:10.18.0.113:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@10ade7e [java] [junit] 09:37:17,831 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@a632be [java] [junit] 09:37:17,831 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@956254 [java] [junit] 09:37:17,831 DEBUG [JbpmJobExector:10.18.0.113:1][DbPersistenceService] closing hibernate session [java] [junit] 09:37:17,831 DEBUG [JbpmJobExector:10.18.0.113:1][Services] closing service 'tx': org.jbpm.tx.TxService@14d659d [java] [junit] 09:37:18,738 DEBUG [main][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 09:37:18,739 DEBUG [main][JbpmContext] creating org.jbpm.JbpmContext@4a3158 [java] [junit] 09:37:18,739 DEBUG [main][DbPersistenceServiceFactory] creating persistence service [java] [junit] 09:37:18,739 DEBUG [main][DbPersistenceService] creating hibernate session [java] [junit] 09:37:18,739 DEBUG [main][DbPersistenceService] beginning hibernate transaction [java] [junit] 09:37:18,739 DEBUG [main][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@ed8eb5 [java] [junit] 4 end [java] [junit] 09:37:18,741 DEBUG [main][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@4a3158 [java] [junit] 09:37:18,741 DEBUG [main][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@1a697a1 [java] [junit] 09:37:18,741 DEBUG [main][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@ed8eb5 [java] [junit] 09:37:18,744 DEBUG [main][DbPersistenceService] closing hibernate session [java] [junit] 09:37:18,744 DEBUG [main][Services] closing service 'tx': org.jbpm.tx.TxService@541b02 [java] [junit] ------------- ---------------- --------------- [java] [junit] Testcase: unknown took 5.103 sec [java] [junitreport] Transform time: 192ms [java] [junitreport] Transform time: 69ms [java] [report] processing input files ... [java] [report] 1 file(s) read and merged in 4 ms [java] [report] writing [html] report to [/qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbpm/build/tests/coverage/index.html] ... [java] test: [java] test: [java] [copy] Copying 10 files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/classes [java] prepare: [java] [mkdir] Created dir: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/jbrules.esb/META-INF [java] [mkdir] Created dir: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/classes [java] compile: [java] [javac] Compiling 15 source files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/classes [java] [javac] Note: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/src/main/java/org/jboss/internal/soa/esb/services/routing/cbr/DslHelper.java uses or overrides a deprecated API. [java] [javac] Note: Recompile with -Xlint:deprecation for details. [java] check.for.files: [java] jar: [java] [jar] Building jar: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/jbossesb-jbrules.jar [java] esb: [java] [copy] Copying 17 files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/jbrules.esb [java] base.test: [java] [mkdir] Created dir: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/coverage/instr [java] [instr] processing instrumentation path ... [java] [instr] instrumentation path processed in 280 ms [java] [instr] [18 class(es) instrumented, 0 resource(s) copied] [java] [instr] metadata merged into [/qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/coverage/coverage.emma] {in 17 ms} [java] [mkdir] Created dir: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/report [java] [javac] Compiling 11 source files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/classes [java] [copy] Copying 3 files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/classes [java] [echo] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules [java] [junit] Running org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest [java] [junit] Tests run: 1, Failures: 1, Errors: 0, Time elapsed: 0.295 sec [java] [junit] Testsuite: org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest [java] [junit] Tests run: 1, Failures: 1, Errors: 0, Time elapsed: 0.295 sec [java] [junit] Testcase: warning took 0.004 sec [java] [junit] FAILED [java] [junit] No tests found in org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest [java] [junit] junit.framework.AssertionFailedError: No tests found in org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest [java] BUILD FAILED [java] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/build.xml:178: The following error occurred while executing this line: [java] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/build.xml:30: The following error occurred while executing this line: [java] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build.xml:16: The following error occurred while executing this line: [java] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/base-project-build.xml:104: Test org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest failed [java] Total time: 8 minutes 3 seconds [java] Java Result: 1 esb.init-app-server: esb.init-esb-server: esb.init-ftp-server: esb.init: stop-server: [echo] Stopping local ESB server [java] Shutdown message has been posted to the server. [java] Server shutdown may take a while - check logfiles for completion [echo] 2008-07-02 09:37:24 EDT: waiting for ESB server to stop, checking file /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/build/jbossesb-test/jbossesb-server/server/default/log/server.log ... BUILD FAILED /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/integration-build.xml:11: The following error occurred while executing this line: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/build.xml:488: Product Unit Test failure Total time: 8 minutes 51 seconds Recording test results Recording Emma reports trunk/product/build/tests/coverage/coverage.xml

See http://hudson.qa.jboss.com/hudson/job/jboss-esb-linux/1022/changes Changes: [beve] Work for JBESB-1426 "CBR XPathDSL should allow namespace aware documents" ------------------------------------------ [...truncated 10056 lines...] [java] [junit] 11:24:16,545 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'before-signal' on 'State(wait1)' for 'Token(/)' [java] [junit] 11:24:16,546 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'node-leave' on 'State(wait1)' for 'Token(/)' [java] [junit] 11:24:16,549 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] executing action 'CancelTimerAction(ca5bff)' [java] [junit] 11:24:16,549 DEBUG [JbpmJobExector:10.18.0.216:1][Token] token[1] is locked by token[1] [java] [junit] 11:24:16,552 WARN [JbpmJobExector:10.18.0.216:1][ProxyWarnLog] Narrowing proxy to class org.jbpm.job.Timer - this operation breaks == [java] [junit] 11:24:16,553 DEBUG [JbpmJobExector:10.18.0.216:1][JobSession] deleting timer timer(wait1,08-07-04 11:24:16,491,Token: 1) by name wait1 [java] [junit] 11:24:16,557 DEBUG [JbpmJobExector:10.18.0.216:1][Token] token[1] is unlocked by token[1] [java] [junit] 11:24:16,558 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'transition' on 'Transition(continue)' for 'Token(/)' [java] [junit] 11:24:16,561 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'node-enter' on 'Node(mynode)' for 'Token(/)' [java] [junit] 11:24:16,563 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'node-leave' on 'Node(mynode)' for 'Token(/)' [java] [junit] 11:24:16,563 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'transition' on 'Transition(toWait2)' for 'Token(/)' [java] [junit] 11:24:16,585 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'node-enter' on 'State(wait2)' for 'Token(/)' [java] [junit] 11:24:16,586 WARN [JbpmJobExector:10.18.0.216:1][ProxyWarnLog] Narrowing proxy to class org.jbpm.graph.node.State - this operation breaks == [java] [junit] 11:24:16,595 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] executing action 'CreateTimerAction(1798928)' [java] [junit] 11:24:16,595 DEBUG [JbpmJobExector:10.18.0.216:1][Token] token[1] is locked by token[1] [java] [junit] 11:24:16,595 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'timer-create' on 'State(wait2)' for 'Token(/)' [java] [junit] 11:24:16,597 DEBUG [JbpmJobExector:10.18.0.216:1][Token] token[1] is unlocked by token[1] [java] [junit] 11:24:16,597 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'after-signal' on 'State(wait1)' for 'Token(/)' [java] [junit] 11:24:16,597 DEBUG [JbpmJobExector:10.18.0.216:1][Services] executing default save operations [java] [junit] 11:24:16,597 DEBUG [JbpmJobExector:10.18.0.216:1][HibernateSaveOperation] saving process instance [java] [junit] 11:24:16,600 DEBUG [JbpmJobExector:10.18.0.216:1][SaveLogsOperation] flushing logs to logging service. [java] [junit] 11:24:16,608 DEBUG [JbpmJobExector:10.18.0.216:1][CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance@1ce00b4' [java] [junit] 11:24:16,608 DEBUG [JbpmJobExector:10.18.0.216:1][JobSession] deleting timer(wait1,08-07-04 11:24:16,491,Token: 1) [java] [junit] 11:24:16,608 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@86d1da [java] [junit] 11:24:16,608 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@dd89f9 [java] [junit] 11:24:16,608 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@13b625b [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] closing hibernate session [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'tx': org.jbpm.tx.TxService@14124d6 [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'scheduler': org.jbpm.scheduler.db.DbSchedulerService@1d978ea [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@916f80 [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] acquiring jobs for execution... [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] creating org.jbpm.JbpmContext@2f4813 [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:16,620 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] creating hibernate session [java] [junit] 11:24:16,621 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:16,621 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@24eafa [java] [junit] 11:24:16,621 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] querying for acquirable job... [java] [junit] 11:24:16,623 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] no acquirable jobs in job table [java] [junit] 11:24:16,623 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@2f4813 [java] [junit] 11:24:16,623 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@152643 [java] [junit] 11:24:16,623 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@24eafa [java] [junit] 11:24:16,623 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] closing hibernate session [java] [junit] 11:24:16,623 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'tx': org.jbpm.tx.TxService@8321c8 [java] [junit] 11:24:16,624 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] obtained locks on following jobs: [] [java] [junit] 11:24:16,624 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:16,624 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] creating org.jbpm.JbpmContext@11ee017 [java] [junit] 11:24:16,624 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:16,624 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] creating hibernate session [java] [junit] 11:24:16,624 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:16,624 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@a39de [java] [junit] 11:24:16,627 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@11ee017 [java] [junit] 11:24:16,627 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@24ea85 [java] [junit] 11:24:16,627 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@a39de [java] [junit] 11:24:16,627 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] closing hibernate session [java] [junit] 11:24:16,627 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'tx': org.jbpm.tx.TxService@1a0d346 [java] [junit] 11:24:17,528 DEBUG [main][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:17,528 DEBUG [main][JbpmContext] creating org.jbpm.JbpmContext@18eabf6 [java] [junit] 11:24:17,528 DEBUG [main][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:17,528 DEBUG [main][DbPersistenceService] creating hibernate session [java] [junit] 11:24:17,529 DEBUG [main][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:17,529 DEBUG [main][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@1bbd583 [java] [junit] 2 wait2 [java] [junit] 11:24:17,538 DEBUG [main][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@18eabf6 [java] [junit] 11:24:17,538 DEBUG [main][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@6dddcf [java] [junit] 11:24:17,538 DEBUG [main][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@1bbd583 [java] [junit] 11:24:17,539 DEBUG [main][DbPersistenceService] closing hibernate session [java] [junit] 11:24:17,539 DEBUG [main][Services] closing service 'tx': org.jbpm.tx.TxService@10cafa1 [java] [junit] 11:24:18,541 DEBUG [main][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:18,541 DEBUG [main][JbpmContext] creating org.jbpm.JbpmContext@1de7497 [java] [junit] 11:24:18,541 DEBUG [main][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:18,541 DEBUG [main][DbPersistenceService] creating hibernate session [java] [junit] 11:24:18,542 DEBUG [main][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:18,542 DEBUG [main][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@1b88122 [java] [junit] 3 wait2 [java] [junit] 11:24:18,545 DEBUG [main][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@1de7497 [java] [junit] 11:24:18,545 DEBUG [main][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@6e3e5e [java] [junit] 11:24:18,545 DEBUG [main][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@1b88122 [java] [junit] 11:24:18,546 DEBUG [main][DbPersistenceService] closing hibernate session [java] [junit] 11:24:18,547 DEBUG [main][Services] closing service 'tx': org.jbpm.tx.TxService@e20ef8 [java] [junit] 11:24:18,597 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] acquiring jobs for execution... [java] [junit] 11:24:18,597 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:18,597 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] creating org.jbpm.JbpmContext@144e858 [java] [junit] 11:24:18,597 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:18,597 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] creating hibernate session [java] [junit] 11:24:18,597 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:18,598 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@f1f34a [java] [junit] 11:24:18,598 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] querying for acquirable job... [java] [junit] 11:24:18,600 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] trying to obtain a lock for 'timer(wait2,08-07-04 11:24:18,595,Token: 1)' [java] [junit] 11:24:18,602 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@144e858 [java] [junit] 11:24:18,602 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@19b2faf [java] [junit] 11:24:18,602 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@f1f34a [java] [junit] 11:24:18,605 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] closing hibernate session [java] [junit] 11:24:18,609 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'tx': org.jbpm.tx.TxService@dcb6b4 [java] [junit] 11:24:18,609 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] obtained locks on following jobs: [timer(wait2,08-07-04 11:24:18,595,Token: 1)] [java] [junit] 11:24:18,609 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:18,609 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] creating org.jbpm.JbpmContext@5f1c48 [java] [junit] 11:24:18,609 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:18,609 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] creating hibernate session [java] [junit] 11:24:18,609 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:18,610 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@39ea58 [java] [junit] 11:24:18,618 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] executing job timer(wait2,08-07-04 11:24:18,595,Token: 1) [java] [junit] 11:24:18,628 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'before-signal' on 'State(wait2)' for 'Token(/)' [java] [junit] 11:24:18,628 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'node-leave' on 'State(wait2)' for 'Token(/)' [java] [junit] 11:24:18,634 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] executing action 'CancelTimerAction(194ba17)' [java] [junit] 11:24:18,634 DEBUG [JbpmJobExector:10.18.0.216:1][Token] token[1] is locked by token[1] [java] [junit] 11:24:18,641 WARN [JbpmJobExector:10.18.0.216:1][ProxyWarnLog] Narrowing proxy to class org.jbpm.job.Timer - this operation breaks == [java] [junit] 11:24:18,642 DEBUG [JbpmJobExector:10.18.0.216:1][JobSession] deleting timer timer(wait2,08-07-04 11:24:18,595,Token: 1) by name wait2 [java] [junit] 11:24:18,645 DEBUG [JbpmJobExector:10.18.0.216:1][Token] token[1] is unlocked by token[1] [java] [junit] 11:24:18,645 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'transition' on 'Transition(continue)' for 'Token(/)' [java] [junit] 11:24:18,654 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'node-enter' on 'EndState(end)' for 'Token(/)' [java] [junit] 11:24:18,656 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'process-end' on 'ProcessDefinition(testTimer)' for 'Token(/)' [java] [junit] 11:24:18,659 DEBUG [JbpmJobExector:10.18.0.216:1][GraphElement] event 'after-signal' on 'State(wait2)' for 'Token(/)' [java] [junit] 11:24:18,659 DEBUG [JbpmJobExector:10.18.0.216:1][Services] executing default save operations [java] [junit] 11:24:18,659 DEBUG [JbpmJobExector:10.18.0.216:1][HibernateSaveOperation] saving process instance [java] [junit] 11:24:18,659 DEBUG [JbpmJobExector:10.18.0.216:1][SaveLogsOperation] flushing logs to logging service. [java] [junit] 11:24:18,669 DEBUG [JbpmJobExector:10.18.0.216:1][CascadeSaveOperation] cascading save of 'org.jbpm.graph.exe.ProcessInstance@189c12a' [java] [junit] 11:24:18,669 DEBUG [JbpmJobExector:10.18.0.216:1][JobSession] deleting timer(wait2,08-07-04 11:24:18,595,Token: 1) [java] [junit] 11:24:18,669 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@5f1c48 [java] [junit] 11:24:18,669 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@19d9c0d [java] [junit] 11:24:18,669 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@39ea58 [java] [junit] 11:24:18,680 DEBUG [JbpmJobExector:10.18.0.216:1][JobSession] deleting timers for process instance org.jbpm.graph.exe.ProcessInstance@189c12a [java] [junit] 11:24:18,691 DEBUG [JbpmJobExector:10.18.0.216:1][JobSession] 0 remaining timers for 'org.jbpm.graph.exe.ProcessInstance@189c12a' are deleted [java] [junit] 11:24:18,691 DEBUG [JbpmJobExector:10.18.0.216:1][JobSession] deleting execute-node-jobs for process instance org.jbpm.graph.exe.ProcessInstance@189c12a [java] [junit] 11:24:18,694 DEBUG [JbpmJobExector:10.18.0.216:1][JobSession] 0 remaining execute-node-jobs for 'org.jbpm.graph.exe.ProcessInstance@189c12a' are deleted [java] [junit] 11:24:18,697 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] closing hibernate session [java] [junit] 11:24:18,697 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'tx': org.jbpm.tx.TxService@13a83cc [java] [junit] 11:24:18,697 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'scheduler': org.jbpm.scheduler.db.DbSchedulerService@a2d304 [java] [junit] 11:24:18,697 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'logging': org.jbpm.logging.db.DbLoggingService@1cbd4f7 [java] [junit] 11:24:18,698 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] acquiring jobs for execution... [java] [junit] 11:24:18,698 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:18,698 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] creating org.jbpm.JbpmContext@10ade7e [java] [junit] 11:24:18,698 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:18,698 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] creating hibernate session [java] [junit] 11:24:18,698 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:18,698 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@956254 [java] [junit] 11:24:18,698 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] querying for acquirable job... [java] [junit] 11:24:18,701 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] no acquirable jobs in job table [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@10ade7e [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@a632be [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@956254 [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] closing hibernate session [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'tx': org.jbpm.tx.TxService@14d659d [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][JobExecutorThread] obtained locks on following jobs: [] [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] creating org.jbpm.JbpmContext@4a3158 [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] creating hibernate session [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:18,702 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@ed8eb5 [java] [junit] 11:24:18,705 DEBUG [JbpmJobExector:10.18.0.216:1][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@4a3158 [java] [junit] 11:24:18,705 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@15738e0 [java] [junit] 11:24:18,705 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@ed8eb5 [java] [junit] 11:24:18,705 DEBUG [JbpmJobExector:10.18.0.216:1][DbPersistenceService] closing hibernate session [java] [junit] 11:24:18,705 DEBUG [JbpmJobExector:10.18.0.216:1][Services] closing service 'tx': org.jbpm.tx.TxService@15726ec [java] [junit] 11:24:19,550 DEBUG [main][JbpmContextInfo] creating jbpm context with service factories '[tx, message, scheduler, logging, persistence, authentication]' [java] [junit] 11:24:19,550 DEBUG [main][JbpmContext] creating org.jbpm.JbpmContext@bc6007 [java] [junit] 11:24:19,550 DEBUG [main][DbPersistenceServiceFactory] creating persistence service [java] [junit] 11:24:19,550 DEBUG [main][DbPersistenceService] creating hibernate session [java] [junit] 11:24:19,551 DEBUG [main][DbPersistenceService] beginning hibernate transaction [java] [junit] 11:24:19,551 DEBUG [main][DbPersistenceService] begun hibernate transaction org.hibernate.transaction.JDBCTransaction@144752d [java] [junit] 4 end [java] [junit] 11:24:19,553 DEBUG [main][JbpmContext] closing jbpmContext org.jbpm.JbpmContext@bc6007 [java] [junit] 11:24:19,553 DEBUG [main][Services] closing service 'persistence': org.jbpm.persistence.db.DbPersistenceService@39452f [java] [junit] 11:24:19,553 DEBUG [main][DbPersistenceService] committing hibernate transaction org.hibernate.transaction.JDBCTransaction@144752d [java] [junit] 11:24:19,556 DEBUG [main][DbPersistenceService] closing hibernate session [java] [junit] 11:24:19,556 DEBUG [main][Services] closing service 'tx': org.jbpm.tx.TxService@8809ce [java] [junit] ------------- ---------------- --------------- [java] [junit] Testcase: unknown took 5.129 sec [java] [junitreport] Transform time: 279ms [java] [junitreport] Transform time: 75ms [java] [report] processing input files ... [java] [report] 1 file(s) read and merged in 7 ms [java] [report] writing [html] report to [/qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbpm/build/tests/coverage/index.html] ... [java] test: [java] test: [java] [copy] Copying 11 files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/classes [java] prepare: [java] [mkdir] Created dir: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/jbrules.esb/META-INF [java] [mkdir] Created dir: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/classes [java] compile: [java] [javac] Compiling 15 source files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/classes [java] [javac] Note: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/src/main/java/org/jboss/internal/soa/esb/services/routing/cbr/DslHelper.java uses or overrides a deprecated API. [java] [javac] Note: Recompile with -Xlint:deprecation for details. [java] check.for.files: [java] jar: [java] [jar] Building jar: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/jbossesb-jbrules.jar [java] esb: [java] [copy] Copying 17 files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/jbrules.esb [java] base.test: [java] [mkdir] Created dir: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/coverage/instr [java] [instr] processing instrumentation path ... [java] [instr] instrumentation path processed in 257 ms [java] [instr] [18 class(es) instrumented, 0 resource(s) copied] [java] [instr] metadata merged into [/qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/coverage/coverage.emma] {in 13 ms} [java] [mkdir] Created dir: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/report [java] [javac] Compiling 11 source files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/classes [java] [copy] Copying 3 files to /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build/tests/classes [java] [echo] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules [java] [junit] Running org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest [java] [junit] Tests run: 1, Failures: 1, Errors: 0, Time elapsed: 0.224 sec [java] [junit] Testsuite: org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest [java] [junit] Tests run: 1, Failures: 1, Errors: 0, Time elapsed: 0.224 sec [java] [junit] Testcase: warning took 0.004 sec [java] [junit] FAILED [java] [junit] No tests found in org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest [java] [junit] junit.framework.AssertionFailedError: No tests found in org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest [java] BUILD FAILED [java] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/build.xml:178: The following error occurred while executing this line: [java] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/build.xml:30: The following error occurred while executing this line: [java] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/jbrules/build.xml:16: The following error occurred while executing this line: [java] /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/services/base-project-build.xml:104: Test org.jboss.internal.soa.esb.services.routing.cbr.DslHelperUnitTest failed [java] Total time: 9 minutes 2 seconds [java] Java Result: 1 esb.init-app-server: esb.init-esb-server: esb.init-ftp-server: esb.init: stop-server: [echo] Stopping local ESB server [java] Shutdown message has been posted to the server. [java] Server shutdown may take a while - check logfiles for completion [echo] 2008-07-04 11:24:26 EDT: waiting for ESB server to stop, checking file /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/build/jbossesb-test/jbossesb-server/server/default/log/server.log ... BUILD FAILED /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/integration-build.xml:11: The following error occurred while executing this line: /qa/services/hudson/hudson_workspace/workspace/jboss-esb-linux/trunk/product/build.xml:488: Product Unit Test failure Total time: 10 minutes 4 seconds Recording test results Recording Emma reports trunk/product/build/tests/coverage/coverage.xml

See http://hudson.qa.jboss.com/hudson/job/jboss-esb-linux/1024/changes