Kuali Rice Development
  1. Kuali Rice Development
  2. KULRICE-8481

BlanketApproveTest.testBlanketApproveToMultipleNodes fails in CI with Should be at blanket approved node WD4B3.

    Details

    • Type: Bug Fix Bug Fix
    • Status: Closed Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.2.0-rc1
    • Fix Version/s: 2.2.1
    • Component/s: Quality Assurance
    • Security Level: Public (Public: Anyone can view)
    • Labels:
      None
    • Similar issues:
      KULRICE-3906When KEW is JPA-enabled, blanket approvals on documents with split and join nodes fail to execute properly
      KULRICE-9286KualiInquirableTest fails in CI with An inquiry URL to AccountManager should be built
      KULRICE-6727Sub Fund Reviewer is not displaying Blanket Approved in Route log annotation
      KULRICE-9290SearchAttributeIndexRequestTest fails in CI with unable to get class for unknown documentTypeName 'SearchAttributeIndexTestDocument'
      KULRICE-9287KualiLookupableTest fails in CI with Lookup not defined for business object class org.kuali.rice.krad.test.document.bo.Account
      KULRICE-7172Should adhoc requests be persisted upon a blanket approve
      KULRICE-8762CONTRIB: "Approve & Blanket Approve" button should be disabled for a person who is doing COMPLETE action and "CANCEL" button should be enabled
      KULRICE-7568Figure out what to do with Blanket Approve Workgroup, Blanket Approve Group
      KULRICE-960Blanket Approve Valid actions is possibly incorrect
      KULRICE-2616Document Search by "Approver Network ID" does not include Blanket Approvers
    • Rice Team:
      QA
    • KAI Review Status:
      Not Required
    • KTI Review Status:
      Not Required

      Description

      org.kuali.rice.kew.actions.BlanketApproveTest.testBlanketApproveToMultipleNodes

      Failing for the past 18 builds (Since #595 )

      Should be at blanket approved node WD4B3.
      Stacktrace

      java.lang.AssertionError: Should be at blanket approved node WD4B3.
      	at org.junit.Assert.fail(Assert.java:93)
      	at org.junit.Assert.assertTrue(Assert.java:43)
      	at org.kuali.rice.kew.actions.BlanketApproveTest.testBlanketApproveToMultipleNodes(BlanketApproveTest.java:293)
      	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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
      	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
      	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
      	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
      	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
      	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:30)
      	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
      	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
      	at org.kuali.rice.test.runners.RiceUnitTestClassRunner.runChild(RiceUnitTestClassRunner.java:46)
      	at org.kuali.rice.test.runners.RiceUnitTestClassRunner.runChild(RiceUnitTestClassRunner.java:34)
      	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
      	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
      	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
      	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
      	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
      	at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
      	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
      	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
      	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
      	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.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
      	at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
      	at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
      	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
      	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)
      

      Standard Output

      Alternate Log4j config resource does not exist! /var/lib/jenkins/workspace/rice-trunk-integration-test-mysql/log4j.properties
      Using default log4j configuration: classpath:rice-testharness-default-log4j.properties
      2012-10-29 15:12:05,676 [main] INFO org.kuali.rice.test.RiceTestCase - ##############################################################
      2012-10-29 15:12:05,676 [main] INFO org.kuali.rice.test.RiceTestCase - # Starting test BlanketApproveTest.testBlanketApproveToMultipleNodes...
      2012-10-29 15:12:05,676 [main] INFO org.kuali.rice.test.RiceTestCase - # [Memory] max: 1069416448, total: 263135232, free: 43894504
      2012-10-29 15:12:05,676 [main] INFO org.kuali.rice.test.RiceTestCase - ##############################################################
      2012-10-29 15:12:05,696 [main] INFO org.kuali.rice.test.ClearDatabaseLifecycle - Clearing tables for schema RICEUNT@IP-10-85-102-137.EC2.INTERNAL
      2012-10-29 15:12:05,709 [main] INFO org.kuali.rice.test.ClearDatabaseLifecycle - Clearing contents using statement ->DELETE FROM kren_chnl_prodcr_t<-
      Clearing contents using statement ->DELETE FROM kren_chnl_subscrp_t<-
      Clearing contents using statement ->DELETE FROM kren_chnl_t<-
      Clearing contents using statement ->DELETE FROM kren_cntnt_typ_t<-
      Clearing contents using statement ->DELETE FROM kren_msg_deliv_t<-
      Clearing contents using statement ->DELETE FROM kren_msg_t<-
      Clearing contents using statement ->DELETE FROM kren_ntfctn_msg_deliv_t<-
      Clearing contents using statement ->DELETE FROM kren_ntfctn_t<-
      Clearing contents using statement ->DELETE FROM kren_prio_t<-
      Clearing contents using statement ->DELETE FROM kren_prodcr_t<-
      Clearing contents using statement ->DELETE FROM kren_recip_deliv_t<-
      Clearing contents using statement ->DELETE FROM kren_recip_list_t<-
      Clearing contents using statement ->DELETE FROM kren_recip_prefs_t<-
      Clearing contents using statement ->DELETE FROM kren_recip_t<-
      Clearing contents using statement ->DELETE FROM kren_rvwer_t<-
      Clearing contents using statement ->DELETE FROM kren_sndr_t<-
      Clearing contents using statement ->DELETE FROM krew_actn_itm_t<-
      Clearing contents using statement ->DELETE FROM krew_actn_rqst_t<-
      Clearing contents using statement ->DELETE FROM krew_actn_tkn_t<-
      Clearing contents using statement ->DELETE FROM krew_app_doc_stat_tran_t<-
      Clearing contents using statement ->DELETE FROM krew_att_t<-
      Clearing contents using statement ->DELETE FROM krew_attr_defn_t<-
      Clearing contents using statement ->DELETE FROM krew_dlgn_rsp_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_cntnt_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_ext_dt_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_ext_flt_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_ext_long_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_ext_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_lnk_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_nte_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_app_doc_stat_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_app_stat_cat_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_plcy_reln_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_proc_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_t<-
      Clearing contents using statement ->DELETE FROM krew_edl_assctn_t<-
      Clearing contents using statement ->DELETE FROM krew_edl_def_t<-
      Clearing contents using statement ->DELETE FROM krew_edl_dmp_t<-
      Clearing contents using statement ->DELETE FROM krew_edl_fld_dmp_t<-
      Clearing contents using statement ->DELETE FROM krew_init_rte_node_instn_t<-
      Clearing contents using statement ->DELETE FROM krew_out_box_itm_t<-
      Clearing contents using statement ->DELETE FROM krew_ppl_flw_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_ppl_flw_dlgt_t<-
      Clearing contents using statement ->DELETE FROM krew_ppl_flw_mbr_t<-
      Clearing contents using statement ->DELETE FROM krew_ppl_flw_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_brch_proto_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_brch_st_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_brch_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_cfg_parm_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_instn_lnk_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_instn_st_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_instn_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_lnk_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_expr_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_ext_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_ext_val_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_rsp_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_tmpl_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_tmpl_optn_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_tmpl_t<-
      Clearing contents using statement ->DELETE FROM krew_typ_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_typ_t<-
      Clearing contents using statement ->DELETE FROM krew_usr_optn_t<-
      Clearing contents using statement ->DELETE FROM krms_actn_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_actn_t<-
      Clearing contents using statement ->DELETE FROM krms_agenda_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_agenda_itm_t<-
      Clearing contents using statement ->DELETE FROM krms_agenda_t<-
      Clearing contents using statement ->DELETE FROM krms_attr_defn_t<-
      Clearing contents using statement ->DELETE FROM krms_cmpnd_prop_props_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_actn_typ_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_agenda_typ_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_func_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_rule_typ_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_term_spec_t<-
      Clearing contents using statement ->DELETE FROM krms_ctgry_t<-
      Clearing contents using statement ->DELETE FROM krms_func_ctgry_t<-
      Clearing contents using statement ->DELETE FROM krms_func_parm_t<-
      Clearing contents using statement ->DELETE FROM krms_func_t<-
      Clearing contents using statement ->DELETE FROM krms_prop_parm_t<-
      Clearing contents using statement ->DELETE FROM krms_prop_t<-
      Clearing contents using statement ->DELETE FROM krms_rule_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_rule_t<-
      Clearing contents using statement ->DELETE FROM krms_term_parm_t<-
      Clearing contents using statement ->DELETE FROM krms_term_rslvr_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_term_rslvr_input_spec_t<-
      Clearing contents using statement ->DELETE FROM krms_term_rslvr_parm_spec_t<-
      Clearing contents using statement ->DELETE FROM krms_term_rslvr_t<-
      Clearing contents using statement ->DELETE FROM krms_term_spec_ctgry_t<-
      Clearing contents using statement ->DELETE FROM krms_term_spec_t<-
      Clearing contents using statement ->DELETE FROM krms_term_t<-
      Clearing contents using statement ->DELETE FROM krms_typ_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_typ_t<-
      Clearing contents using statement ->DELETE FROM krsb_bam_parm_t<-
      Clearing contents using statement ->DELETE FROM krsb_bam_t<-
      Clearing contents using statement ->DELETE FROM krsb_msg_pyld_t<-
      Clearing contents using statement ->DELETE FROM krsb_msg_que_t<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_blob_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_calendars<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_cron_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_fired_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_job_details<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_job_listeners<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_locks<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_paused_trigger_grps<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_scheduler_state<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_simple_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_trigger_listeners<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_svc_def_t<-
      Clearing contents using statement ->DELETE FROM krsb_svc_dscrptr_t<-
      
      2012-10-29 15:12:06,218 [main] INFO org.kuali.rice.test.ClearDatabaseLifecycle - Tables successfully cleared for schema RICEUNT@IP-10-85-102-137.EC2.INTERNAL
      2012-10-29 15:12:06,273 [main] INFO org.kuali.rice.test.ClearDatabaseLifecycle - Time to clear tables: 0:00:00.597
      2012-10-29 15:12:06,293 [main] INFO org.kuali.rice.test.ClearDatabaseLifecycle - Clearing tables for schema RICEUNT@IP-10-85-102-137.EC2.INTERNAL
      2012-10-29 15:12:06,323 [main] INFO org.kuali.rice.test.ClearDatabaseLifecycle - Clearing contents using statement ->DELETE FROM kren_chnl_prodcr_t<-
      Clearing contents using statement ->DELETE FROM kren_chnl_subscrp_t<-
      Clearing contents using statement ->DELETE FROM kren_chnl_t<-
      Clearing contents using statement ->DELETE FROM kren_cntnt_typ_t<-
      Clearing contents using statement ->DELETE FROM kren_msg_deliv_t<-
      Clearing contents using statement ->DELETE FROM kren_msg_t<-
      Clearing contents using statement ->DELETE FROM kren_ntfctn_msg_deliv_t<-
      Clearing contents using statement ->DELETE FROM kren_ntfctn_t<-
      Clearing contents using statement ->DELETE FROM kren_prio_t<-
      Clearing contents using statement ->DELETE FROM kren_prodcr_t<-
      Clearing contents using statement ->DELETE FROM kren_recip_deliv_t<-
      Clearing contents using statement ->DELETE FROM kren_recip_list_t<-
      Clearing contents using statement ->DELETE FROM kren_recip_prefs_t<-
      Clearing contents using statement ->DELETE FROM kren_recip_t<-
      Clearing contents using statement ->DELETE FROM kren_rvwer_t<-
      Clearing contents using statement ->DELETE FROM kren_sndr_t<-
      Clearing contents using statement ->DELETE FROM krew_actn_itm_t<-
      Clearing contents using statement ->DELETE FROM krew_actn_rqst_t<-
      Clearing contents using statement ->DELETE FROM krew_actn_tkn_t<-
      Clearing contents using statement ->DELETE FROM krew_app_doc_stat_tran_t<-
      Clearing contents using statement ->DELETE FROM krew_att_t<-
      Clearing contents using statement ->DELETE FROM krew_attr_defn_t<-
      Clearing contents using statement ->DELETE FROM krew_dlgn_rsp_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_cntnt_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_ext_dt_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_ext_flt_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_ext_long_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_ext_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_hdr_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_lnk_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_nte_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_app_doc_stat_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_app_stat_cat_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_plcy_reln_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_proc_t<-
      Clearing contents using statement ->DELETE FROM krew_doc_typ_t<-
      Clearing contents using statement ->DELETE FROM krew_edl_assctn_t<-
      Clearing contents using statement ->DELETE FROM krew_edl_def_t<-
      Clearing contents using statement ->DELETE FROM krew_edl_dmp_t<-
      Clearing contents using statement ->DELETE FROM krew_edl_fld_dmp_t<-
      Clearing contents using statement ->DELETE FROM krew_init_rte_node_instn_t<-
      Clearing contents using statement ->DELETE FROM krew_out_box_itm_t<-
      Clearing contents using statement ->DELETE FROM krew_ppl_flw_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_ppl_flw_dlgt_t<-
      Clearing contents using statement ->DELETE FROM krew_ppl_flw_mbr_t<-
      Clearing contents using statement ->DELETE FROM krew_ppl_flw_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_brch_proto_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_brch_st_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_brch_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_cfg_parm_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_instn_lnk_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_instn_st_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_instn_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_lnk_t<-
      Clearing contents using statement ->DELETE FROM krew_rte_node_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_expr_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_ext_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_ext_val_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_rsp_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_tmpl_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_tmpl_optn_t<-
      Clearing contents using statement ->DELETE FROM krew_rule_tmpl_t<-
      Clearing contents using statement ->DELETE FROM krew_typ_attr_t<-
      Clearing contents using statement ->DELETE FROM krew_typ_t<-
      Clearing contents using statement ->DELETE FROM krew_usr_optn_t<-
      Clearing contents using statement ->DELETE FROM krms_actn_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_actn_t<-
      Clearing contents using statement ->DELETE FROM krms_agenda_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_agenda_itm_t<-
      Clearing contents using statement ->DELETE FROM krms_agenda_t<-
      Clearing contents using statement ->DELETE FROM krms_attr_defn_t<-
      Clearing contents using statement ->DELETE FROM krms_cmpnd_prop_props_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_actn_typ_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_agenda_typ_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_func_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_rule_typ_t<-
      Clearing contents using statement ->DELETE FROM krms_cntxt_vld_term_spec_t<-
      Clearing contents using statement ->DELETE FROM krms_ctgry_t<-
      Clearing contents using statement ->DELETE FROM krms_func_ctgry_t<-
      Clearing contents using statement ->DELETE FROM krms_func_parm_t<-
      Clearing contents using statement ->DELETE FROM krms_func_t<-
      Clearing contents using statement ->DELETE FROM krms_prop_parm_t<-
      Clearing contents using statement ->DELETE FROM krms_prop_t<-
      Clearing contents using statement ->DELETE FROM krms_rule_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_rule_t<-
      Clearing contents using statement ->DELETE FROM krms_term_parm_t<-
      Clearing contents using statement ->DELETE FROM krms_term_rslvr_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_term_rslvr_input_spec_t<-
      Clearing contents using statement ->DELETE FROM krms_term_rslvr_parm_spec_t<-
      Clearing contents using statement ->DELETE FROM krms_term_rslvr_t<-
      Clearing contents using statement ->DELETE FROM krms_term_spec_ctgry_t<-
      Clearing contents using statement ->DELETE FROM krms_term_spec_t<-
      Clearing contents using statement ->DELETE FROM krms_term_t<-
      Clearing contents using statement ->DELETE FROM krms_typ_attr_t<-
      Clearing contents using statement ->DELETE FROM krms_typ_t<-
      Clearing contents using statement ->DELETE FROM krsb_bam_parm_t<-
      Clearing contents using statement ->DELETE FROM krsb_bam_t<-
      Clearing contents using statement ->DELETE FROM krsb_msg_pyld_t<-
      Clearing contents using statement ->DELETE FROM krsb_msg_que_t<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_blob_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_calendars<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_cron_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_fired_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_job_details<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_job_listeners<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_locks<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_paused_trigger_grps<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_scheduler_state<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_simple_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_trigger_listeners<-
      Clearing contents using statement ->DELETE FROM krsb_qrtz_triggers<-
      Clearing contents using statement ->DELETE FROM krsb_svc_def_t<-
      Clearing contents using statement ->DELETE FROM krsb_svc_dscrptr_t<-
      
      2012-10-29 15:12:06,831 [main] INFO org.kuali.rice.test.ClearDatabaseLifecycle - Tables successfully cleared for schema RICEUNT@IP-10-85-102-137.EC2.INTERNAL
      2012-10-29 15:12:06,835 [main] INFO org.kuali.rice.test.ClearDatabaseLifecycle - Time to clear tables: 0:00:00.562
      2012-10-29 15:12:06,848 [main] INFO org.kuali.rice.test.SQLDataLoader - ################################
      2012-10-29 15:12:06,848 [main] INFO org.kuali.rice.test.SQLDataLoader - #classpath:org/kuali/rice/kew/test/DefaultPerTestData.sql
      2012-10-29 15:12:06,848 [main] INFO org.kuali.rice.test.SQLDataLoader - #
      2012-10-29 15:12:06,848 [main] INFO org.kuali.rice.test.SQLDataLoader - #
      2012-10-29 15:12:06,849 [main] INFO org.kuali.rice.test.SQLDataLoader - #
      2012-10-29 15:12:06,849 [main] INFO org.kuali.rice.test.SQLDataLoader - ################################
      2012-10-29 15:12:07,185 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5638 name 'KualiDocument' (current = true)
      2012-10-29 15:12:07,214 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5639 name 'RiceDocument' (current = true)
      2012-10-29 15:12:07,242 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5638 name 'KualiDocument' (current = true)
      2012-10-29 15:12:07,319 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5640 name 'DocumentTypeDocument' (current = true)
      2012-10-29 15:12:07,324 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5639 name 'RiceDocument' (current = true)
      2012-10-29 15:12:07,533 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5641 name 'TestDocumentType' (current = true)
      2012-10-29 15:12:07,566 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5642 name 'TestDocumentType2' (current = true)
      2012-10-29 15:12:07,618 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5641 name 'TestDocumentType' (current = true)
      2012-10-29 15:12:07,655 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5643 name 'TestDocumentType3' (current = true)
      2012-10-29 15:12:07,706 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5641 name 'TestDocumentType' (current = true)
      2012-10-29 15:12:07,790 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: TestRule1
      2012-10-29 15:12:07,807 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5608
      2012-10-29 15:12:07,807 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:08,566 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5644 name 'SuperUserActionInvalidPostProcessor' (current = true)
      2012-10-29 15:12:08,616 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:08,698 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5646 name 'CreatedDocumentInactive' (current = true)
      2012-10-29 15:12:08,705 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:08,845 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5647 name 'BlanketApprovePolicyTest' (current = true)
      2012-10-29 15:12:08,852 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:09,143 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5648 name 'BlanketApproveSequentialTest' (current = true)
      2012-10-29 15:12:09,150 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:10,053 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5649 name 'BlanketApproveParallelTest' (current = true)
      2012-10-29 15:12:10,060 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:10,144 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5650 name 'SuperUserApproveActionRequestFyiTest' (current = true)
      2012-10-29 15:12:10,283 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5651 name 'SuperUserApproveActionRequestApproveTest' (current = true)
      2012-10-29 15:12:11,061 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5652 name 'NotificationTest' (current = true)
      2012-10-29 15:12:11,143 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5653 name 'NotificationTestChild' (current = true)
      2012-10-29 15:12:11,355 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5652 name 'NotificationTest' (current = true)
      2012-10-29 15:12:11,396 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5654 name 'RecallTest' (current = true)
      2012-10-29 15:12:11,566 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5652 name 'NotificationTest' (current = true)
      2012-10-29 15:12:11,615 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5655 name 'RecallTestRestricted' (current = true)
      2012-10-29 15:12:11,619 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5654 name 'RecallTest' (current = true)
      2012-10-29 15:12:11,711 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5656 name 'RecallTestOnlyAdhoc' (current = true)
      2012-10-29 15:12:11,760 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5657 name 'RecallWithPrevNotifyTest' (current = true)
      2012-10-29 15:12:11,930 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5652 name 'NotificationTest' (current = true)
      2012-10-29 15:12:12,003 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5658 name 'IntermediateRecallDocType' (current = true)
      2012-10-29 15:12:12,162 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5652 name 'NotificationTest' (current = true)
      2012-10-29 15:12:12,209 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5659 name 'RecallWithoutPendingNotifyTest' (current = true)
      2012-10-29 15:12:12,218 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5658 name 'IntermediateRecallDocType' (current = true)
      2012-10-29 15:12:12,285 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5660 name 'RecallWithThirdPartyNotifyTest' (current = true)
      2012-10-29 15:12:12,454 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5652 name 'NotificationTest' (current = true)
      2012-10-29 15:12:12,505 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5661 name 'SUDisapproveWithNotificationTest' (current = true)
      2012-10-29 15:12:12,675 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5652 name 'NotificationTest' (current = true)
      2012-10-29 15:12:12,730 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5662 name 'SUApproveFinalNodeDisallowed' (current = true)
      2012-10-29 15:12:12,896 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5652 name 'NotificationTest' (current = true)
      2012-10-29 15:12:13,242 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5663 name 'BlanketApproveMandatoryNodeTest' (current = true)
      2012-10-29 15:12:13,250 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:13,414 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5664 name 'SaveActionEventTest' (current = true)
      2012-10-29 15:12:13,590 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5665 name 'SaveActionEventTestNonInitiator' (current = true)
      2012-10-29 15:12:13,823 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5666 name 'TakeWorkgroupAuthorityDoc' (current = true)
      2012-10-29 15:12:14,173 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5667 name 'MoveSequentialTest' (current = true)
      2012-10-29 15:12:14,180 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:14,639 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5668 name 'MoveInProcessTest' (current = true)
      2012-10-29 15:12:14,657 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:14,832 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5669 name 'AdhocRouteTest' (current = true)
      2012-10-29 15:12:14,937 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5670 name 'AdhocRouteTest-PriorityParallel' (current = true)
      2012-10-29 15:12:15,110 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5671 name 'PreApprovalTest' (current = true)
      2012-10-29 15:12:15,800 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5672 name 'VariablesTest' (current = true)
      2012-10-29 15:12:15,981 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5673 name 'InitiatorRoleApprovalTest' (current = true)
      2012-10-29 15:12:16,330 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5674 name 'BlanketApproveThroughRoleAndWorkgroupTest' (current = true)
      2012-10-29 15:12:16,655 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5675 name 'SUApproveDocument' (current = true)
      2012-10-29 15:12:16,731 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5676 name 'SUApproveDocumentNotifications' (current = true)
      2012-10-29 15:12:16,795 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5675 name 'SUApproveDocument' (current = true)
      2012-10-29 15:12:17,179 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5677 name 'RouteLogActionTest' (current = true)
      2012-10-29 15:12:17,321 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5678 name 'RouteLogActionTestTrivial' (current = true)
      2012-10-29 15:12:17,392 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5679 name 'AdHocNoNodeTest' (current = true)
      2012-10-29 15:12:18,026 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved current document type Id 5680 name 'ReturnToPreviousWithSplitTest' (current = true)
      2012-10-29 15:12:18,033 [main] INFO org.kuali.rice.kew.doctype.service.impl.DocumentTypeServiceImpl - Saved parent document type Id 5645 name 'BlanketApproveTest' (current = true)
      2012-10-29 15:12:18,152 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,158 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,183 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,199 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,202 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,207 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,216 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,226 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,248 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,257 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,267 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,292 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,293 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,304 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,334 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,334 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,335 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,353 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,356 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,397 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,416 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,418 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,420 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,423 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,444 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,447 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,449 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,452 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,472 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,475 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,477 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,533 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,535 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,557 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,559 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,562 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:18,861 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocument2Template and SuperUserActionInvalidPostProcessor Rule 1
      2012-10-29 15:12:18,878 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5625
      2012-10-29 15:12:18,878 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:18,878 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocument2Template and SuperUserActionInvalidPostProcessor Rule 2
      2012-10-29 15:12:18,895 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5626
      2012-10-29 15:12:18,895 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:18,895 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocumentTemplate Rule 1
      2012-10-29 15:12:18,923 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      28ms, Saved rule: 5627
      2012-10-29 15:12:18,923 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      28ms, Time to make current
      2012-10-29 15:12:18,923 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocumentTemplate Rule 3
      2012-10-29 15:12:18,939 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5628
      2012-10-29 15:12:18,939 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:18,940 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocumentTemplate Rule 2
      2012-10-29 15:12:18,956 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5629
      2012-10-29 15:12:18,956 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:18,956 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocument2Template Rule 1
      2012-10-29 15:12:18,973 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5630
      2012-10-29 15:12:18,973 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:18,973 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocument3Template Rule 1
      2012-10-29 15:12:18,989 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5631
      2012-10-29 15:12:18,989 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:18,990 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocument4Template Rule 1
      2012-10-29 15:12:19,006 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5632
      2012-10-29 15:12:19,006 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,006 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocumentFinalTemplate Rule 1
      2012-10-29 15:12:19,022 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5633
      2012-10-29 15:12:19,022 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,022 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Ack1Template Rule 1
      2012-10-29 15:12:19,038 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5634
      2012-10-29 15:12:19,038 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,039 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Ack2Template Rule 1
      2012-10-29 15:12:19,055 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5635
      2012-10-29 15:12:19,055 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,055 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Notify First Rule 1
      2012-10-29 15:12:19,081 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      26ms, Saved rule: 5636
      2012-10-29 15:12:19,081 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      26ms, Time to make current
      2012-10-29 15:12:19,081 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Notify Left Branch Rule 1
      2012-10-29 15:12:19,098 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5637
      2012-10-29 15:12:19,098 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,098 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Notify Right Branch Rule 1
      2012-10-29 15:12:19,114 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5638
      2012-10-29 15:12:19,114 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,114 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Notify Final Rule 1
      2012-10-29 15:12:19,169 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      55ms, Saved rule: 5639
      2012-10-29 15:12:19,169 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      55ms, Time to make current
      2012-10-29 15:12:19,169 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocumentTemplate SaveAction Rule 1
      2012-10-29 15:12:19,185 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5640
      2012-10-29 15:12:19,186 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,186 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: WorkflowDocumentTemplate SaveAction Rule 2
      2012-10-29 15:12:19,202 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5641
      2012-10-29 15:12:19,202 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,202 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: TakeWorkgroupAuthorityDoc route to TestWorkgroup
      2012-10-29 15:12:19,219 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5642
      2012-10-29 15:12:19,219 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,219 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required AdhocRouteTest
      2012-10-29 15:12:19,235 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5643
      2012-10-29 15:12:19,235 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,236 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required PreApprovalTest1
      2012-10-29 15:12:19,252 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5644
      2012-10-29 15:12:19,252 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,253 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required PreApprovalTest2
      2012-10-29 15:12:19,269 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5645
      2012-10-29 15:12:19,269 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,269 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required PreApprovalTest3
      2012-10-29 15:12:19,286 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5646
      2012-10-29 15:12:19,286 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,286 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required PreApprovalTest4
      2012-10-29 15:12:19,303 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5647
      2012-10-29 15:12:19,303 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,303 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required VariablesTest1
      2012-10-29 15:12:19,337 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      34ms, Saved rule: 5648
      2012-10-29 15:12:19,337 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      34ms, Time to make current
      2012-10-29 15:12:19,337 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required VariablesTest2
      2012-10-29 15:12:19,354 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5649
      2012-10-29 15:12:19,354 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,354 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required VariablesTest3
      2012-10-29 15:12:19,370 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5650
      2012-10-29 15:12:19,370 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,371 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required VariablesTest4
      2012-10-29 15:12:19,387 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5651
      2012-10-29 15:12:19,387 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,387 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required InitiatorRoleApprovalTest1
      2012-10-29 15:12:19,403 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5652
      2012-10-29 15:12:19,403 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,403 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required InitiatorRoleApprovalTest2
      2012-10-29 15:12:19,419 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5653
      2012-10-29 15:12:19,419 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,420 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required InitiatorRoleApprovalTest3
      2012-10-29 15:12:19,436 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5654
      2012-10-29 15:12:19,436 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,436 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: required InitiatorRoleApprovalTest4
      2012-10-29 15:12:19,452 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5655
      2012-10-29 15:12:19,452 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,453 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: BA Notification Rule 1
      2012-10-29 15:12:19,469 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5656
      2012-10-29 15:12:19,469 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,470 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: BA Notification Rule 2
      2012-10-29 15:12:19,486 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5657
      2012-10-29 15:12:19,486 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,486 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: BA Notification Workgroup Rule 1
      2012-10-29 15:12:19,503 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5658
      2012-10-29 15:12:19,503 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,503 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: BA Notification Workgroup Rule 2
      2012-10-29 15:12:19,533 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      30ms, Saved rule: 5659
      2012-10-29 15:12:19,533 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      30ms, Time to make current
      2012-10-29 15:12:19,533 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: SUApproveDocument rule
      2012-10-29 15:12:19,550 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5660
      2012-10-29 15:12:19,550 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,550 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: SUApproveDocument rule WorkflowDocument3Template
      2012-10-29 15:12:19,566 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5661
      2012-10-29 15:12:19,567 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,567 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: RLAT WorkflowDocumentTemplate Rule 1
      2012-10-29 15:12:19,583 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5662
      2012-10-29 15:12:19,583 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Time to make current
      2012-10-29 15:12:19,583 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: RLAT WorkflowDocumentTemplate Rule 2
      2012-10-29 15:12:19,600 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5663
      2012-10-29 15:12:19,600 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,600 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: RLAT Ack1Template Rule 1
      2012-10-29 15:12:19,617 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5664
      2012-10-29 15:12:19,617 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Time to make current
      2012-10-29 15:12:19,680 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:19,687 [main] WARN org.kuali.rice.kew.xml.CommonXmlParser - Rule XML is using deprecated element 'user', please use 'principalName' instead.
      2012-10-29 15:12:19,717 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Notify left Branch Prim Del
      2012-10-29 15:12:19,743 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      26ms, Saved rule: 5665
      2012-10-29 15:12:19,750 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      33ms, Time to make current
      2012-10-29 15:12:19,750 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Notify Left Branch Sec Del
      2012-10-29 15:12:19,766 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      16ms, Saved rule: 5667
      2012-10-29 15:12:19,773 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      23ms, Time to make current
      2012-10-29 15:12:19,773 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Preparing rule: Notify Right Delegation
      2012-10-29 15:12:19,790 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      17ms, Saved rule: 5669
      2012-10-29 15:12:19,796 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      23ms, Time to make current
      2012-10-29 15:12:20,272 [main] INFO org.kuali.rice.kew.impl.action.DocumentOrchestrationQueueImpl - Performing document orchestration on documentId=5681
      2012-10-29 15:12:20,281 [main] INFO org.kuali.rice.kew.engine.BlanketApproveEngine - Processing document for Blanket Approval: 5681 : null
      2012-10-29 15:12:20,364 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       3ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:20,405 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Time to activate 0 action requests.
      2012-10-29 15:12:20,441 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Time to filter massRules for template WorkflowDocumentTemplate
      2012-10-29 15:12:20,441 [main] INFO org.kuali.rice.kew.rule.FlexRM - Total number of rules selected by RuleSelector for documentType=BlanketApproveParallelTest and ruleTemplate=WorkflowDocumentTemplate: 2
      2012-10-29 15:12:20,451 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      10ms, Time to make action request for template WorkflowDocumentTemplate
      2012-10-29 15:12:20,480 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      13ms, Time to activate action request with id 2563
      2012-10-29 15:12:20,494 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      14ms, Time to activate action request with id 2564
      2012-10-29 15:12:20,534 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      70ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:20,606 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      13ms, Time to activate action request with id 2565
      2012-10-29 15:12:20,619 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      13ms, Time to activate action request with id 2566
      2012-10-29 15:12:20,664 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      71ms, Time to activate 2 action requests.
      2012-10-29 15:12:20,668 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       3ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:20,720 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Time to activate 0 action requests.
      2012-10-29 15:12:20,834 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       1ms, Time to activate 0 action requests.
      2012-10-29 15:12:20,853 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Time to filter massRules for template WorkflowDocument4Template
      2012-10-29 15:12:20,853 [main] INFO org.kuali.rice.kew.rule.FlexRM - Total number of rules selected by RuleSelector for documentType=BlanketApproveParallelTest and ruleTemplate=WorkflowDocument4Template: 1
      2012-10-29 15:12:20,858 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       5ms, Time to make action request for template WorkflowDocument4Template
      2012-10-29 15:12:20,881 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      14ms, Time to activate action request with id 2567
      2012-10-29 15:12:20,909 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      44ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:20,949 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      12ms, Time to activate action request with id 2568
      2012-10-29 15:12:20,972 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      35ms, Time to activate 1 action requests.
      2012-10-29 15:12:20,972 [main] INFO org.kuali.rice.kew.engine.StandardWorkflowEngine - Aquiring lock on document 5681
      2012-10-29 15:12:20,974 [main] INFO org.kuali.rice.kew.engine.StandardWorkflowEngine - Aquired lock on document 5681
      2012-10-29 15:12:20,978 [main] INFO org.kuali.rice.kew.engine.StandardWorkflowEngine - Processing document: 5681 : null
      2012-10-29 15:12:21,000 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Time to filter massRules for template WorkflowDocument3Template
      2012-10-29 15:12:21,001 [main] INFO org.kuali.rice.kew.rule.FlexRM - Total number of rules selected by RuleSelector for documentType=BlanketApproveParallelTest and ruleTemplate=WorkflowDocument3Template: 1
      2012-10-29 15:12:21,006 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       6ms, Time to make action request for template WorkflowDocument3Template
      2012-10-29 15:12:21,029 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      14ms, Time to activate action request with id 2569
      2012-10-29 15:12:21,054 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      41ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:21,065 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       2ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:21,184 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       0ms, Time to filter massRules for template WorkflowDocument2Template
      2012-10-29 15:12:21,184 [main] INFO org.kuali.rice.kew.rule.FlexRM - Total number of rules selected by RuleSelector for documentType=BlanketApproveParallelTest and ruleTemplate=WorkflowDocument2Template: 1
      2012-10-29 15:12:21,197 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      13ms, Time to make action request for template WorkflowDocument2Template
      2012-10-29 15:12:21,220 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      14ms, Time to activate action request with id 2570
      2012-10-29 15:12:21,245 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      41ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:21,277 [main] INFO org.kuali.rice.kew.engine.StandardWorkflowEngine - Successfully processed document: 5681 : null
      2012-10-29 15:12:21,294 [main] INFO org.kuali.rice.kew.engine.StandardWorkflowEngine - Aquiring lock on document 5681
      2012-10-29 15:12:21,296 [main] INFO org.kuali.rice.kew.engine.StandardWorkflowEngine - Aquired lock on document 5681
      2012-10-29 15:12:21,300 [main] INFO org.kuali.rice.kew.engine.StandardWorkflowEngine - Processing document: 5681 : null
      2012-10-29 15:12:21,321 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:      15ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:21,347 [main] INFO org.kuali.rice.kew.util.PerformanceLogger - Time:       3ms, docId=5681, Time to activate requests.
      2012-10-29 15:12:21,366 [main] INFO org.kuali.rice.kew.engine.StandardWorkflowEngine - Successfully processed document: 5681 : null
      2012-10-29 15:12:21,373 [main] INFO org.kuali.rice.kew.impl.action.DocumentOrchestrationQueueImpl - Document orchestration complete against documentId=5681
      2012-10-29 15:12:21,529 [main] WARN org.kuali.rice.krad.datadictionary.DataDictionaryIndexMapper - Unable to find document entry for key: BlanketApproveParallelTest
      2012-10-29 15:12:21,834 [main] WARN org.kuali.rice.test.RiceTestCase - Attempting to stop a lifecycle class org.kuali.rice.test.RiceTestCase$4
      2012-10-29 15:12:21,834 [main] WARN org.kuali.rice.test.RiceTestCase - Attempting to stop a lifecycle class org.kuali.rice.test.lifecycles.PerTestDataLoaderLifecycle
      2012-10-29 15:12:21,834 [main] WARN org.kuali.rice.test.RiceTestCase - Attempting to stop a lifecycle class org.kuali.rice.test.ClearDatabaseLifecycle
      2012-10-29 15:12:21,835 [main] WARN org.kuali.rice.test.RiceTestCase - Attempting to stop a lifecycle class org.kuali.rice.kew.test.KEWTestCase$ClearCacheLifecycle
      2012-10-29 15:12:21,835 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/PrincipalType
      2012-10-29 15:12:21,835 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{ExternalIdentifierType}
      2012-10-29 15:12:21,835 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/EntityPrivacyPreferencesType
      2012-10-29 15:12:21,836 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/RoleMemberType
      2012-10-29 15:12:21,836 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{AffiliationType}
      2012-10-29 15:12:21,836 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{EmploymentStatus}
      2012-10-29 15:12:21,836 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/EntityNamePrincipalNameType
      2012-10-29 15:12:21,836 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/GroupMemberType
      2012-10-29 15:12:21,837 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/DelegateTypeType
      2012-10-29 15:12:21,837 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{EntityType}
      2012-10-29 15:12:21,837 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{AddressType}
      2012-10-29 15:12:21,837 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/PermissionType
      2012-10-29 15:12:21,838 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/KimTypeType
      2012-10-29 15:12:21,838 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{NameType}
      2012-10-29 15:12:21,838 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/EntityType
      2012-10-29 15:12:21,838 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{EmploymentType}
      2012-10-29 15:12:21,838 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/ResponsibilityType
      2012-10-29 15:12:21,839 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{PhoneType}
      2012-10-29 15:12:21,839 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/EntityDefaultType
      2012-10-29 15:12:21,839 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{CitizenshipStatus}
      2012-10-29 15:12:21,839 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/DelegateMemberType
      2012-10-29 15:12:21,839 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/TemplateType{Responsibility}
      2012-10-29 15:12:21,840 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/GroupType
      2012-10-29 15:12:21,840 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/RoleResponsibilityType
      2012-10-29 15:12:21,840 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/TemplateType{Permission}
      2012-10-29 15:12:21,840 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/CodedAttributeType{EmailType}
      2012-10-29 15:12:21,841 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/RoleType
      2012-10-29 15:12:21,841 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kim/v2_0/RoleMembershipType
      2012-10-29 15:12:21,841 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kew/v2_0/RuleDelegationType
      2012-10-29 15:12:21,841 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kew/v2_0/RoutePathType
      2012-10-29 15:12:21,841 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kew/v2_0/RuleResponsibilityType
      2012-10-29 15:12:21,842 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kew/v2_0/RuleType
      2012-10-29 15:12:21,842 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kew/v2_0/RuleTemplateType
      2012-10-29 15:12:21,842 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kew/v2_0/DocumentTypeType
      2012-10-29 15:12:21,843 [main] INFO org.kuali.rice.kew.actions.BlanketApproveTest - Clearing cache: http://rice.kuali.org/kew/v2_0/ExtensionDefinitionType
      2012-10-29 15:12:21,843 [main] WARN org.kuali.rice.test.RiceTestCase - Attempting to stop a lifecycle class org.kuali.rice.test.ClearDatabaseLifecycle
      2012-10-29 15:12:21,843 [main] INFO org.kuali.rice.test.RiceTestCase - ##############################################################
      2012-10-29 15:12:21,843 [main] INFO org.kuali.rice.test.RiceTestCase - # ...finished test BlanketApproveTest.testBlanketApproveToMultipleNodes
      2012-10-29 15:12:21,843 [main] INFO org.kuali.rice.test.RiceTestCase - # [Memory] max: 1069416448, total: 263135232, free: 40452120
      2012-10-29 15:12:21,844 [main] INFO org.kuali.rice.test.RiceTestCase - # Time to load test-specific test data: 11995
      2012-10-29 15:12:21,844 [main] INFO org.kuali.rice.test.RiceTestCase - # Time to run test-specific setup: 0
      2012-10-29 15:12:21,844 [main] INFO org.kuali.rice.test.RiceTestCase - # Time to start all Lifecycles: 14154
      2012-10-29 15:12:21,844 [main] INFO org.kuali.rice.test.RiceTestCase - ##############################################################
      

        Activity

        Hide
        Erik Meade added a comment -

        No longer failing

        Show
        Erik Meade added a comment - No longer failing
        Hide
        Jessica Coltrin (Inactive) added a comment -

        Since these were fixed on the trunk, they are 2.3.

        Show
        Jessica Coltrin (Inactive) added a comment - Since these were fixed on the trunk, they are 2.3.

          People

          • Assignee:
            Unassigned
            Reporter:
            Erik Meade
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Structure Helper Panel