8 Replies Latest reply on Oct 3, 2013 5:19 PM by aadav86

Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

aadav86 Sep 30, 2013 2:56 AM

Hi,

Our web application implemented with jBPM5.3 running in production currently is facing a weird problems in creating workitem for human task that is placed inside multiple instance node. But the issue is specific to only the production environment having oracle 11g at the back-end. We fail to replicate this issue in non-production environment (same oracle 11g DB) even after 1000s of attempts to create human tasks with same BPMN and code.

Basically the process design is as below, for reference bpmn is also attached with this post.

Issue Description

For example, if my process instance iterates four times, for the first iteration the task and corresponding workitem is getting created properly but for the next iteration creation of workitem fails due to which my process instance gets completed before its execution. The whole execution of my process is illustrated below in terms of logs.

Step 1: Process instance creation - First set of tasks are created based on the collection input fed to the MI Node (In this case only one task)

2013-09-29 03:33:43,583 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (ajp-3.156.34.176-8009-1) kbase retrieved: org.drools.impl.KnowledgeBaseImpl@7729bd25

2013-09-29 03:33:43,583 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Before createTaskHandler

2013-09-29 03:33:43,602 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select SESSIONINFO_ID_SEQ.nextval from dual

2013-09-29 03:33:43,605 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into SessionInfo (lastModificationDate, rulesByteArray, startDate, OPTLOCK, id) values (?, ?, ?, ?, ?)

2013-09-29 03:33:43,628 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select task0_.id as col_0_0_, deadline1_.id as col_1_0_, deadline1_.deadline_date as col_2_0_ from Task task0_, Deadline deadline1_ where task0_.archived=0 and (deadline1_.id in (select startdeadl2_.id from Deadline startdeadl2_ where task0_.id=startdeadl2_.Deadlines_StartDeadLine_Id) or deadline1_.id in (select enddeadlin3_.id from Deadline enddeadlin3_ where task0_.id=enddeadlin3_.Deadlines_EndDeadLine_Id)) and deadline1_.escalated=0 order by deadline1_.deadline_date

2013-09-29 03:33:43,761 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Before registering Identification Task Handler

2013-09-29 03:33:43,762 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Created ksession 1658

2013-09-29 03:33:43,762 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Before startProcess

2013-09-29 03:33:43,762 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Starting process on ksession 1658

2013-09-29 03:33:43,766 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select hibernate_sequence.nextval from dual

2013-09-29 03:33:43,768 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,770 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,771 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,773 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,779 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,780 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,782 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,784 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,785 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,787 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,789 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,790 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,792 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,794 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select PROC_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,796 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,798 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,799 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,801 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,803 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,804 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,806 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,808 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,809 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 03:33:43,812 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select WORKITEMINFO_ID_SEQ.nextval from dual

2013-09-29 03:33:43,815 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select hibernate_sequence.nextval from dual

2013-09-29 03:33:43,817 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select user_.id from OrganizationalEntity user_ where user_.id=?

2013-09-29 03:33:43,819 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 03:33:43,821 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 03:33:43,823 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 03:33:43,825 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: select CONTENT_ID_SEQ.nextval from dual

2013-09-29 03:33:43,827 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: update SessionInfo set lastModificationDate=?, rulesByteArray=?, startDate=?, OPTLOCK=? where id=? and OPTLOCK=?

2013-09-29 03:33:43,834 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into ProcessInstanceInfo (OPTLOCK, processId, startDate, lastReadDate, lastModificationDate, state, processInstanceByteArray, InstanceId) values (?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,836 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into VariableInstanceLog (log_date, processId, processInstanceId, value, variableId, variableInstanceId, id) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,837 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into VariableInstanceLog (log_date, processId, processInstanceId, value, variableId, variableInstanceId, id) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,841 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into ProcessInstanceLog (end_date, processId, processInstanceId, start_date, id) values (?, ?, ?, ?, ?)

2013-09-29 03:33:43,844 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,845 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,846 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into VariableInstanceLog (log_date, processId, processInstanceId, value, variableId, variableInstanceId, id) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,847 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,848 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into WorkItemInfo (creationDate, name, processInstanceId, state, OPTLOCK, workItemByteArray, workItemId) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,855 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: update ProcessInstanceInfo set OPTLOCK=?, processId=?, startDate=?, lastReadDate=?, lastModificationDate=?, state=?, processInstanceByteArray=? where InstanceId=? and OPTLOCK=?

2013-09-29 03:33:43,856 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: update WorkItemInfo set creationDate=?, name=?, processInstanceId=?, state=?, OPTLOCK=?, workItemByteArray=? where workItemId=? and OPTLOCK=?

2013-09-29 03:33:43,859 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into Task (archived, allowedToDelegate, taskInitiator_id, priority, activationTime, actualOwner_id, createdBy_id, createdOn, documentAccessType, documentContentId, documentType, expirationTime, faultAccessType, faultContentId, faultName, faultType, outputAccessType, outputContentId, outputType, parentId, previousStatus, processId, processInstanceId, processSessionId, skipable, status, workItemId, OPTLOCK, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 03:33:43,862 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into I18NText (language, text, id) values (?, ?, ?)

2013-09-29 03:33:43,863 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into I18NText (language, text, id) values (?, ?, ?)

2013-09-29 03:33:43,864 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into Content (content, id) values (?, ?)

2013-09-29 03:33:43,868 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: update Task set archived=?, allowedToDelegate=?, taskInitiator_id=?, priority=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, OPTLOCK=? where id=? and OPTLOCK=?

2013-09-29 03:33:43,869 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: update I18NText set Task_Descriptions_Id=? where id=?

2013-09-29 03:33:43,870 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: update I18NText set Task_Names_Id=? where id=?

2013-09-29 03:33:43,871 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into PeopleAssignments_BAs (task_id, entity_id) values (?, ?)

2013-09-29 03:33:43,872 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: insert into PeopleAssignments_PotOwners (task_id, entity_id) values (?, ?)

2013-09-29 03:33:43,873 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Hibernate: update I18NText set Task_Subjects_Id=? where id=?

2013-09-29 03:33:43,877 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Started process instance 4682 on ksession 1658

2013-09-29 03:33:43,878 INFO [STDOUT] (ajp-3.156.34.176-8009-1) Disposing ksession 1658

Step 2: First task is approved and the first iteration is completed to create a task on second iteration (only one task in this case)

2013-09-29 04:04:18,065 INFO [com.ge.nbc.pdm.deal.listener.handler.PDMMessageHandler] (jmsContainer-1) <--- replyMsg action --> approved <-- Comments --> test

2013-09-29 04:04:18,066 INFO [com.ge.nbc.pdm.deal.listener.handler.PDMMessageHandler] (jmsContainer-1) +++ Its approval flow ++++

2013-09-29 04:04:18,066 INFO [com.ge.nbc.pdm.deal.listener.handler.PDMMessageHandler] (jmsContainer-1) DealId -> 4682 -- Token -> 4683 -- Action -> a -- Category -> null -- isApproved Y

2013-09-29 04:04:18,066 INFO [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (jmsContainer-1) approveOrRejectDRM - taskid --> 4683 --> 1658processid --> 4682 comments -> test

2013-09-29 04:04:18,066 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The serviceType is : DB

2013-09-29 04:04:18,066 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The prefix is : java:

2013-09-29 04:04:18,066 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The JNDI Name is : java:oradb356

2013-09-29 04:04:18,071 INFO [STDOUT] (jmsContainer-1) Hibernate: select task0_.id as id85_3_, task0_.archived as archived85_3_, task0_.allowedToDelegate as allowedT3_85_3_, task0_.taskInitiator_id as taskIni27_85_3_, task0_.priority as priority85_3_, task0_.activationTime as activati5_85_3_, task0_.actualOwner_id as actualO28_85_3_, task0_.createdBy_id as createdBy29_85_3_, task0_.createdOn as createdOn85_3_, task0_.documentAccessType as document7_85_3_, task0_.documentContentId as document8_85_3_, task0_.documentType as document9_85_3_, task0_.expirationTime as expirat10_85_3_, task0_.faultAccessType as faultAc11_85_3_, task0_.faultContentId as faultCo12_85_3_, task0_.faultName as faultName85_3_, task0_.faultType as faultType85_3_, task0_.outputAccessType as outputA15_85_3_, task0_.outputContentId as outputC16_85_3_, task0_.outputType as outputType85_3_, task0_.parentId as parentId85_3_, task0_.previousStatus as previou19_85_3_, task0_.processId as processId85_3_, task0_.processInstanceId as process21_85_3_, task0_.processSessionId as process22_85_3_, task0_.skipable as skipable85_3_, task0_.status as status85_3_, task0_.workItemId as workItemId85_3_, task0_.OPTLOCK as OPTLOCK85_3_, user1_.id as id80_0_, user2_.id as id80_1_, user3_.id as id80_2_ from Task task0_ left outer join OrganizationalEntity user1_ on task0_.taskInitiator_id=user1_.id left outer join OrganizationalEntity user2_ on task0_.actualOwner_id=user2_.id left outer join OrganizationalEntity user3_ on task0_.createdBy_id=user3_.id where task0_.id=?

2013-09-29 04:04:18,080 INFO [STDOUT] (jmsContainer-1) Hibernate: select * from ( select processins0_.id as id71_, processins0_.end_date as end2_71_, processins0_.processId as processId71_, processins0_.processInstanceId as processI4_71_, processins0_.start_date as start5_71_ from ProcessInstanceLog processins0_ where processins0_.processInstanceId=? ) where rownum <= ?

2013-09-29 04:04:18,085 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.factory.WorkflowBusinessDelegate] (jmsContainer-1) Entering getProcess for a processInstance:::

2013-09-29 04:04:18,088 INFO [STDOUT] (jmsContainer-1) Hibernate: select variablein0_.id as id73_, variablein0_.log_date as log2_73_, variablein0_.processId as processId73_, variablein0_.processInstanceId as processI4_73_, variablein0_.value as value73_, variablein0_.variableId as variableId73_, variablein0_.variableInstanceId as variable7_73_ from VariableInstanceLog variablein0_ where variablein0_.processInstanceId=? order by variablein0_.log_date

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> ProjectTypeId Value -> 2

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> DealRequestCategoryId Value -> 3

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> BusinessUnitId Value -> 32

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> ProjectStateId Value -> 1

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> submitterId Value -> 501884277

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> DealRequestTypeId Value -> 12

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> ProductionGroupId Value -> 0

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> DealRequestSubtypeId Value -> -1

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> DevelopedFor Value -> I

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> DealRequestId Value -> 14522

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> ProgramTypeId Value -> 1

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> DayPart Value -> N

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> TaskInfo Value -> [com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@3c1f82d0]

2013-09-29 04:04:18,097 INFO [STDOUT] (jmsContainer-1) Key -> 11:2:taskAssignmentInfo Value -> com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@3c1f82d0

2013-09-29 04:04:18,097 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.factory.WorkflowBusinessDelegate] (jmsContainer-1) Before returning process::

2013-09-29 04:04:18,098 INFO [STDOUT] (jmsContainer-1) Hibernate: select names0_.Task_Names_Id as Task5_85_1_, names0_.id as id1_, names0_.id as id81_0_, names0_.language as language81_0_, names0_.text as text81_0_ from I18NText names0_ where names0_.Task_Names_Id=?

2013-09-29 04:04:18,109 INFO [STDOUT] (jmsContainer-1) Hibernate: select descriptio0_.Task_Descriptions_Id as Task6_85_1_, descriptio0_.id as id1_, descriptio0_.id as id81_0_, descriptio0_.language as language81_0_, descriptio0_.text as text81_0_ from I18NText descriptio0_ where descriptio0_.Task_Descriptions_Id=?

2013-09-29 04:04:18,119 INFO [STDOUT] (jmsContainer-1) Hibernate: select comments0_.TaskData_Comments_Id as TaskData5_85_2_, comments0_.id as id2_, comments0_.id as id77_1_, comments0_.addedAt as addedAt77_1_, comments0_.addedBy_id as addedBy4_77_1_, comments0_.text as text77_1_, user1_.id as id80_0_ from task_comment comments0_ left outer join OrganizationalEntity user1_ on comments0_.addedBy_id=user1_.id where comments0_.TaskData_Comments_Id=?

2013-09-29 04:04:18,121 INFO [STDOUT] (jmsContainer-1) task Id -> 4683 task status -> Reserved for user 501884277 and logged in user is 501884277

2013-09-29 04:04:18,121 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (jmsContainer-1) Validating e-mail approver..!

2013-09-29 04:04:18,121 DEBUG [com.ge.nbc.pdm.deal.bus.bd.CommonBD] (jmsContainer-1) CommonBD : initializeEJBCreate : Entered in initializeEJBCreate

2013-09-29 04:04:18,122 DEBUG [com.ge.nbc.pdm.deal.bus.bd.CommonBD] (jmsContainer-1) Exiting ProductionProjectTVBD.initializeEJBCreate

2013-09-29 04:04:18,122 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The serviceType is : DB

2013-09-29 04:04:18,122 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The prefix is : java:

2013-09-29 04:04:18,122 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The JNDI Name is : java:oradb356

2013-09-29 04:04:18,208 INFO [STDOUT] (jmsContainer-1) status 111 --->

2013-09-29 04:04:18,208 INFO [STDOUT] (jmsContainer-1) --- status --

2013-09-29 04:04:18,209 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The serviceType is : DB

2013-09-29 04:04:18,209 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The prefix is : java:

2013-09-29 04:04:18,209 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The JNDI Name is : java:oradb356

2013-09-29 04:04:18,212 INFO [STDOUT] (jmsContainer-1) The string is -> SELECT WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID WORKFLOW_APPROVAL_LEVEL_ID FROM APPLICATION_WORKFLOW, WORKFLOW_BUSINESS_UNIT_ASC , WORKFLOW_APPROVAL_LEVEL, APPROVAL_LEVEL, t3486_approval_action WHERE APPLICATION_WORKFLOW.APPLICATION_WORKFLOW_ID = WORKFLOW_BUSINESS_UNIT_ASC.APPLICATION_WORKFLOW_ID AND WORKFLOW_APPROVAL_LEVEL.WORKFLOW_BUSINESS_UNIT_ASC_ID = WORKFLOW_BUSINESS_UNIT_ASC.WORKFLOW_BUSINESS_UNIT_ASC_ID AND WORKFLOW_APPROVAL_LEVEL.APPROVAL_LEVEL_ID = APPROVAL_LEVEL.APPROVAL_LEVEL_ID AND T3486_APPROVAL_ACTION.WORKFLOW_APPROVAL_LEVEL_ID = WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID AND APPLICATION_WORKFLOW.PDM_TYPE_ID = ? AND WORKFLOW_BUSINESS_UNIT_ASC.C2082_BUSINESS_UNIT_ID = ? AND C3486_DEAL_REQUEST_ID = ? AND APPROVAL_LEVEL.APPROVAL_LEVEL_NAME = ? AND c3486_approved_yn != 'A' 12 32 14522 Genre Dept Head Approval

2013-09-29 04:04:18,212 INFO [STDOUT] (jmsContainer-1) Action string -> false

2013-09-29 04:04:18,212 INFO [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (jmsContainer-1) approver --> 501884277 task name --> Genre Dept Head Approval --> 501884277

2013-09-29 04:04:18,212 DEBUG [com.ge.nbc.pdm.deal.bus.share.util.LookupCache] (jmsContainer-1) Looking up DRMWorkflow

2013-09-29 04:04:18,212 INFO [STDOUT] (jmsContainer-1) get procespetive tasks

2013-09-29 04:04:18,214 INFO [STDOUT] (jmsContainer-1) Hibernate: select * from ( select task0_.id as col_0_0_, task0_.processInstanceId as col_1_0_, names4_.text as col_2_0_, subjects2_.text as col_3_0_, descriptio3_.text as col_4_0_, task0_.status as col_5_0_, task0_.priority as col_6_0_, task0_.skipable as col_7_0_, task0_.actualOwner_id as col_8_0_, task0_.createdBy_id as col_9_0_, task0_.createdOn as col_10_0_, task0_.activationTime as col_11_0_, task0_.expirationTime as col_12_0_, task0_.processId as col_13_0_, task0_.processSessionId as col_14_0_ from Task task0_ left outer join OrganizationalEntity user1_ on task0_.createdBy_id=user1_.id left outer join I18NText subjects2_ on task0_.id=subjects2_.Task_Subjects_Id left outer join I18NText descriptio3_ on task0_.id=descriptio3_.Task_Descriptions_Id left outer join I18NText names4_ on task0_.id=names4_.Task_Names_Id inner join OrganizationalEntity user5_ on task0_.actualOwner_id=user5_.id where task0_.archived=0 and task0_.status='Reserved' and task0_.processInstanceId='4682' and (names4_.language='en-UK' or (select count(names7_.Task_Names_Id) from I18NText names7_ where task0_.id=names7_.Task_Names_Id)=0) and (subjects2_.language='en-UK' or (select count(subjects8_.Task_Subjects_Id) from I18NText subjects8_ where task0_.id=subjects8_.Task_Subjects_Id)=0) and (descriptio3_.language='en-UK' or (select count(descriptio9_.Task_Descriptions_Id) from I18NText descriptio9_ where task0_.id=descriptio9_.Task_Descriptions_Id)=0) and (task0_.expirationTime is null) ) where rownum <= ?

2013-09-29 04:04:18,240 INFO [STDOUT] (jmsContainer-1) [org.jbpm.task.query.TaskSummary@5023c317] prospectiveTasks.sizeeeeeeeeeeeeeeeeeeeeeee

2013-09-29 04:04:18,240 INFO [STDOUT] (jmsContainer-1) 1 prospectiveTasks.sizeeeeeeeeeeeeeeeeeeeeeee

2013-09-29 04:04:18,240 INFO [STDOUT] (jmsContainer-1) Genre Dept Head Approval ---> Activity <----> Approver ---> 501884277

2013-09-29 04:04:18,240 INFO [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (jmsContainer-1) pla flag value..false

2013-09-29 04:04:18,240 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (jmsContainer-1) Before making a call jBPM to approve the task

2013-09-29 04:04:18,240 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (jmsContainer-1) In Complete task

2013-09-29 04:04:18,258 INFO [STDOUT] (jmsContainer-1) Hibernate: select sessioninf0_.id as id69_0_, sessioninf0_.lastModificationDate as lastModi2_69_0_, sessioninf0_.rulesByteArray as rulesByt3_69_0_, sessioninf0_.startDate as startDate69_0_, sessioninf0_.OPTLOCK as OPTLOCK69_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=?

2013-09-29 04:04:18,274 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (jmsContainer-1) In Approve task

2013-09-29 04:04:18,274 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (jmsContainer-1) pl flag value..null

2013-09-29 04:04:18,277 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (jmsContainer-1) to get the local task service..

2013-09-29 04:04:18,277 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (jmsContainer-1) to get the task service..

2013-09-29 04:04:18,293 INFO [STDOUT] (jmsContainer-1) Hibernate: select task0_.id as col_0_0_, deadline1_.id as col_1_0_, deadline1_.deadline_date as col_2_0_ from Task task0_, Deadline deadline1_ where task0_.archived=0 and (deadline1_.id in (select startdeadl2_.id from Deadline startdeadl2_ where task0_.id=startdeadl2_.Deadlines_StartDeadLine_Id) or deadline1_.id in (select enddeadlin3_.id from Deadline enddeadlin3_ where task0_.id=enddeadlin3_.Deadlines_EndDeadLine_Id)) and deadline1_.escalated=0 order by deadline1_.deadline_date

2013-09-29 04:04:18,411 INFO [STDOUT] (jmsContainer-1) Hibernate: select task0_.id as id85_3_, task0_.archived as archived85_3_, task0_.allowedToDelegate as allowedT3_85_3_, task0_.taskInitiator_id as taskIni27_85_3_, task0_.priority as priority85_3_, task0_.activationTime as activati5_85_3_, task0_.actualOwner_id as actualO28_85_3_, task0_.createdBy_id as createdBy29_85_3_, task0_.createdOn as createdOn85_3_, task0_.documentAccessType as document7_85_3_, task0_.documentContentId as document8_85_3_, task0_.documentType as document9_85_3_, task0_.expirationTime as expirat10_85_3_, task0_.faultAccessType as faultAc11_85_3_, task0_.faultContentId as faultCo12_85_3_, task0_.faultName as faultName85_3_, task0_.faultType as faultType85_3_, task0_.outputAccessType as outputA15_85_3_, task0_.outputContentId as outputC16_85_3_, task0_.outputType as outputType85_3_, task0_.parentId as parentId85_3_, task0_.previousStatus as previou19_85_3_, task0_.processId as processId85_3_, task0_.processInstanceId as process21_85_3_, task0_.processSessionId as process22_85_3_, task0_.skipable as skipable85_3_, task0_.status as status85_3_, task0_.workItemId as workItemId85_3_, task0_.OPTLOCK as OPTLOCK85_3_, user1_.id as id80_0_, user2_.id as id80_1_, user3_.id as id80_2_ from Task task0_ left outer join OrganizationalEntity user1_ on task0_.taskInitiator_id=user1_.id left outer join OrganizationalEntity user2_ on task0_.actualOwner_id=user2_.id left outer join OrganizationalEntity user3_ on task0_.createdBy_id=user3_.id where task0_.id=?

2013-09-29 04:04:18,417 INFO [STDOUT] (jmsContainer-1) Hibernate: update Task set archived=?, allowedToDelegate=?, taskInitiator_id=?, priority=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, OPTLOCK=? where id=? and OPTLOCK=?

2013-09-29 04:04:18,443 INFO [STDOUT] (jmsContainer-1) Hibernate: select CONTENT_ID_SEQ.nextval from dual

2013-09-29 04:04:18,445 INFO [STDOUT] (jmsContainer-1) Hibernate: select subtaskstr0_.Task_Id as Task4_85_1_, subtaskstr0_.id as id1_, subtaskstr0_.id as id86_0_, subtaskstr0_.name as name86_0_, subtaskstr0_.DTYPE as DTYPE86_0_ from SubTasksStrategy subtaskstr0_ where subtaskstr0_.Task_Id=?

2013-09-29 04:04:18,448 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into Content (content, id) values (?, ?)

2013-09-29 04:04:18,449 INFO [STDOUT] (jmsContainer-1) Hibernate: update Task set archived=?, allowedToDelegate=?, taskInitiator_id=?, priority=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, OPTLOCK=? where id=? and OPTLOCK=?

2013-09-29 04:04:18,467 INFO [STDOUT] (jmsContainer-1) Hibernate: select workitemin0_.workItemId as workItemId70_0_, workitemin0_.creationDate as creation2_70_0_, workitemin0_.name as name70_0_, workitemin0_.processInstanceId as processI4_70_0_, workitemin0_.state as state70_0_, workitemin0_.OPTLOCK as OPTLOCK70_0_, workitemin0_.workItemByteArray as workItem7_70_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=?

2013-09-29 04:04:18,471 INFO [STDOUT] (jmsContainer-1) Hibernate: select processins0_.InstanceId as InstanceId67_0_, processins0_.OPTLOCK as OPTLOCK67_0_, processins0_.processId as processId67_0_, processins0_.startDate as startDate67_0_, processins0_.lastReadDate as lastRead5_67_0_, processins0_.lastModificationDate as lastModi6_67_0_, processins0_.state as state67_0_, processins0_.processInstanceByteArray as processI8_67_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=?

2013-09-29 04:04:18,476 INFO [STDOUT] (jmsContainer-1) BEFORE RULEFLOW VARIABLE CHANGED Result={taskId=4683, taskValue=0, taskName=Genre Dept Head Approval, actorName=501884277, plFlag=null} process:PDM[id=PDM]

2013-09-29 04:04:18,477 INFO [STDOUT] (jmsContainer-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,478 INFO [STDOUT] (jmsContainer-1) AFTER RULEFLOW VARIABLE CHANGED Result={taskId=4683, taskValue=0, taskName=Genre Dept Head Approval, actorName=501884277, plFlag=null} process:PDM[id=PDM]

2013-09-29 04:04:18,478 INFO [STDOUT] (jmsContainer-1) Exiting user task node

2013-09-29 04:04:18,478 INFO [STDOUT] (jmsContainer-1) taskAssignmentInfo in task node...com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@235e805a

2013-09-29 04:04:18,479 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,480 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE EXITED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

2013-09-29 04:04:18,481 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,482 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE TRIGGERED node:End[id=11:3] process:PDM[id=PDM]

2013-09-29 04:04:18,482 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,484 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE EXITED node:End[id=11:3] process:PDM[id=PDM]

2013-09-29 04:04:18,484 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,486 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE EXITED node:Multiple Instances[id=11] process:PDM[id=PDM]

2013-09-29 04:04:18,486 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,488 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE TRIGGERED node:Evaluate Process Flow[id=17] process:PDM[id=PDM]

2013-09-29 04:04:18,488 INFO [STDOUT] (jmsContainer-1) Hibernate: select WORKITEMINFO_ID_SEQ.nextval from dual

2013-09-29 04:04:18,490 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) work item name in eval...Task Evaluation

2013-09-29 04:04:18,490 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) execution path name...null

2013-09-29 04:04:18,490 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) execution path name...{taskId=4683, taskValue=0, taskName=Genre Dept Head Approval, actorName=501884277, plFlag=null}

2013-09-29 04:04:18,490 DEBUG [com.ge.nbc.pdm.deal.bus.share.util.LookupCache] (jmsContainer-1) Looking up DRMWorkflow

2013-09-29 04:04:18,490 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) task request type... work item name...Task Evaluation

2013-09-29 04:04:18,491 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) I DevelopedFor: I

2013-09-29 04:04:18,491 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) Approver name...501884277

2013-09-29 04:04:18,491 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) Task name...Genre Dept Head Approval

2013-09-29 04:04:18,491 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) PL Flag...null

2013-09-29 04:04:18,491 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) Entering the getAssignees method

2013-09-29 04:04:18,491 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) drmCharacteristics.getDealRequestType()12

2013-09-29 04:04:18,491 INFO [STDOUT] (jmsContainer-1) drmCharacteristics.getDealRequestType()12

2013-09-29 04:04:18,491 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) Before entering getNextTasksAndApproversForPDM method

2013-09-29 04:04:18,491 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The serviceType is : DB

2013-09-29 04:04:18,491 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The prefix is : java:

2013-09-29 04:04:18,491 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The JNDI Name is : java:oradb356

2013-09-29 04:04:18,493 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) getApprovers query: SELECT APPROVAL_LEVEL.APPROVAL_LEVEL_NAME, WORKFLOW_APPROVAL_USER.USER_ID, WORKFLOW_APPROVAL_LEVEL.LEVEL_NUM FROM DRM_ASSIGNEE_NEW, APPLICATION_ATTRIBUTE, APP_WORKFLOW_APPROVAL, WORKFLOW_APPROVAL_USER, APPROVAL_LEVEL, WORKFLOW_APPROVAL_LEVEL, WORKFLOW_BUSINESS_UNIT_ASC, APPLICATION_WORKFLOW, T2030_USER WHERE DRM_ASSIGNEE_NEW_ID = APPLICATION_ATTRIBUTE.ATTRIBUTE_ID AND APPLICATION_ATTRIBUTE.APPLICATION_ATTRIBUTE_ID = APP_WORKFLOW_APPROVAL.APPLICATION_ATTRIBUTE_ID AND APP_WORKFLOW_APPROVAL.APP_WORKFLOW_APPROVAL_ID = WORKFLOW_APPROVAL_USER.APP_WORKFLOW_APPROVAL_ID AND WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID = APP_WORKFLOW_APPROVAL.WORKFLOW_APPROVAL_LEVEL_ID AND APPROVAL_LEVEL.APPROVAL_LEVEL_ID = WORKFLOW_APPROVAL_LEVEL.APPROVAL_LEVEL_ID AND APPLICATION_WORKFLOW.APPLICATION_WORKFLOW_ID =WORKFLOW_BUSINESS_UNIT_ASC.APPLICATION_WORKFLOW_ID AND WORKFLOW_BUSINESS_UNIT_ASC.WORKFLOW_BUSINESS_UNIT_ASC_ID = WORKFLOW_APPROVAL_LEVEL.WORKFLOW_BUSINESS_UNIT_ASC_ID AND WORKFLOW_BUSINESS_UNIT_ASC.DELETED_FLAG = WORKFLOW_APPROVAL_LEVEL.DELETED_FLAG AND WORKFLOW_APPROVAL_LEVEL.DELETED_FLAG = APP_WORKFLOW_APPROVAL.DELETED_FLAG AND APP_WORKFLOW_APPROVAL.DELETED_FLAG = WORKFLOW_APPROVAL_USER.DELETED_FLAG AND WORKFLOW_APPROVAL_USER.DELETED_FLAG = 'N' AND WORKFLOW_APPROVAL_USER.USER_ID = T2030_USER.C2030_USER_ID AND APPLICATION_WORKFLOW.PDM_TYPE_ID = ? AND WORKFLOW_BUSINESS_UNIT_ASC.C2082_BUSINESS_UNIT_ID = ? AND C3482_BUSINESS_UNIT_ID = ? AND C3482_DEAL_REQUEST_TYPE_ID = ? AND C3482_PROJECT_STATE_ID = 1 AND C3482_PROGRAM_TYPE_ID = 1 AND C3482_PROJECT_TYPE_ID = 2 AND C3482_DAY_PART_YN = 'N' AND C3482_DRM_PROD_GRP_ID = 0 AND C3482_DEVELOPED_FOR = 'I'AND C3482_DEAL_REQUEST_SUBTYPE_ID is null order by LEVEL_NUM,PARALLEL_LEVEL drmCharacteristics :DRMCharacteristics: dealRequestType=12,dealRequestSubtype=-1,projectState=1,businessUnit=32,activity='null',projectType=2,programType=1,DayPart=N,ProductionGroup=0

2013-09-29 04:04:18,516 INFO [STDOUT] (jmsContainer-1) Info -> num -> Genre Dept Head Approval 1

2013-09-29 04:04:18,516 INFO [STDOUT] (jmsContainer-1) Info -> num -> Finance Approval 2

2013-09-29 04:04:18,516 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) The assignees are:loaded

2013-09-29 04:04:18,516 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) After exiting getNextTasksAndApproversForPDM method

2013-09-29 04:04:18,516 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) Task Info....[com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad]

2013-09-29 04:04:18,516 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) Before entering getDelegateIfExists method

2013-09-29 04:04:18,516 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) In getDelegateIfExists for 501933269

2013-09-29 04:04:18,516 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The serviceType is : DB

2013-09-29 04:04:18,516 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The prefix is : java:

2013-09-29 04:04:18,516 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The JNDI Name is : java:oradb356

2013-09-29 04:04:18,519 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) After exiting getDelegateIfExists method

2013-09-29 04:04:18,519 INFO [STDOUT] (jmsContainer-1) assignee_delegate output...null

2013-09-29 04:04:18,519 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) The Final assignees after delegateCheck: com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad

2013-09-29 04:04:18,519 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (jmsContainer-1) Exiting out of the getAssignees method

2013-09-29 04:04:18,519 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) exit check entry variable..true

2013-09-29 04:04:18,519 INFO [STDOUT] (jmsContainer-1) BEFORE RULEFLOW VARIABLE CHANGED ExitCheck=true process:PDM[id=PDM]

2013-09-29 04:04:18,520 INFO [STDOUT] (jmsContainer-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,522 INFO [STDOUT] (jmsContainer-1) AFTER RULEFLOW VARIABLE CHANGED ExitCheck=true process:PDM[id=PDM]

2013-09-29 04:04:18,522 INFO [STDOUT] (jmsContainer-1) BEFORE RULEFLOW VARIABLE CHANGED TaskInfo=[com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad] process:PDM[id=PDM]

2013-09-29 04:04:18,522 INFO [STDOUT] (jmsContainer-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,524 INFO [STDOUT] (jmsContainer-1) AFTER RULEFLOW VARIABLE CHANGED TaskInfo=[com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad] process:PDM[id=PDM]

2013-09-29 04:04:18,524 INFO [STDOUT] (jmsContainer-1) exiting evaluate process flow..

2013-09-29 04:04:18,524 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,526 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE EXITED node:Evaluate Process Flow[id=17] process:PDM[id=PDM]

2013-09-29 04:04:18,526 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,527 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE TRIGGERED node:Gateway[id=5] process:PDM[id=PDM]

2013-09-29 04:04:18,528 INFO [STDOUT] (jmsContainer-1) ExitChecker..true

2013-09-29 04:04:18,528 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,529 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE EXITED node:Gateway[id=5] process:PDM[id=PDM]

2013-09-29 04:04:18,529 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,531 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE TRIGGERED node:Loop Back[id=12] process:PDM[id=PDM]

2013-09-29 04:04:18,531 INFO [STDOUT] (jmsContainer-1) looping back...entering next iteration..

2013-09-29 04:04:18,531 INFO [STDOUT] (jmsContainer-1) TaskInfo Obj -> [com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad]

2013-09-29 04:04:18,532 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,533 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE EXITED node:Loop Back[id=12] process:PDM[id=PDM]

2013-09-29 04:04:18,534 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,538 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE TRIGGERED node:Gateway[id=18] process:PDM[id=PDM]

2013-09-29 04:04:18,538 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,540 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE EXITED node:Gateway[id=18] process:PDM[id=PDM]

2013-09-29 04:04:18,540 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,541 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE TRIGGERED node:Multiple Instances[id=11] process:PDM[id=PDM]

2013-09-29 04:04:18,541 INFO [STDOUT] (jmsContainer-1) BEFORE RULEFLOW VARIABLE CHANGED 11:2:taskAssignmentInfo=com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad process:PDM[id=PDM]

2013-09-29 04:04:18,542 INFO [STDOUT] (jmsContainer-1) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,543 INFO [STDOUT] (jmsContainer-1) AFTER RULEFLOW VARIABLE CHANGED 11:2:taskAssignmentInfo=com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad process:PDM[id=PDM]

2013-09-29 04:04:18,543 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,545 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE TRIGGERED node:Start[id=11:2] process:PDM[id=PDM]

2013-09-29 04:04:18,545 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,547 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE EXITED node:Start[id=11:2] process:PDM[id=PDM]

2013-09-29 04:04:18,548 INFO [STDOUT] (jmsContainer-1) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:04:18,549 INFO [STDOUT] (jmsContainer-1) BEFORE PROCESS NODE TRIGGERED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

2013-09-29 04:04:18,550 INFO [STDOUT] (jmsContainer-1) Hibernate: select WORKITEMINFO_ID_SEQ.nextval from dual

2013-09-29 04:04:18,552 INFO [STDOUT] (jmsContainer-1) Hibernate: select hibernate_sequence.nextval from dual

2013-09-29 04:04:18,554 INFO [STDOUT] (jmsContainer-1) Hibernate: select user_.id from OrganizationalEntity user_ where user_.id=?

2013-09-29 04:04:18,556 INFO [STDOUT] (jmsContainer-1) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 04:04:18,558 INFO [STDOUT] (jmsContainer-1) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 04:04:18,560 INFO [STDOUT] (jmsContainer-1) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 04:04:18,561 INFO [STDOUT] (jmsContainer-1) Hibernate: select CONTENT_ID_SEQ.nextval from dual

2013-09-29 04:04:18,563 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

2013-09-29 04:04:18,563 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Start[id=11:2] process:PDM[id=PDM]

2013-09-29 04:04:18,563 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Multiple Instances[id=11] process:PDM[id=PDM]

2013-09-29 04:04:18,563 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Gateway[id=18] process:PDM[id=PDM]

2013-09-29 04:04:18,563 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Loop Back[id=12] process:PDM[id=PDM]

2013-09-29 04:04:18,563 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Gateway[id=5] process:PDM[id=PDM]

2013-09-29 04:04:18,564 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Evaluate Process Flow[id=17] process:PDM[id=PDM]

2013-09-29 04:04:18,564 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (jmsContainer-1) After Complete workItem

2013-09-29 04:04:18,564 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Evaluate Process Flow[id=17] process:PDM[id=PDM]

2013-09-29 04:04:18,564 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Multiple Instances[id=11] process:PDM[id=PDM]

2013-09-29 04:04:18,564 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:End[id=11:3] process:PDM[id=PDM]

2013-09-29 04:04:18,564 INFO [STDOUT] (jmsContainer-1) AFTER PROCESS NODE TRIGGERED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

2013-09-29 04:04:18,567 INFO [STDOUT] (jmsContainer-1) Hibernate: select eventtypes0_.InstanceId as InstanceId67_0_, eventtypes0_.element as element0_ from EventTypes eventtypes0_ where eventtypes0_.InstanceId=?

2013-09-29 04:04:18,570 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into VariableInstanceLog (log_date, processId, processInstanceId, value, variableId, variableInstanceId, id) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,572 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,577 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into WorkItemInfo (creationDate, name, processInstanceId, state, OPTLOCK, workItemByteArray, workItemId) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,579 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into VariableInstanceLog (log_date, processId, processInstanceId, value, variableId, variableInstanceId, id) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,580 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,581 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,582 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into VariableInstanceLog (log_date, processId, processInstanceId, value, variableId, variableInstanceId, id) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,583 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into NodeInstanceLog (log_date, nodeId, nodeInstanceId, nodeName, processId, processInstanceId, type, id) values (?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,584 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into WorkItemInfo (creationDate, name, processInstanceId, state, OPTLOCK, workItemByteArray, workItemId) values (?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,585 INFO [STDOUT] (jmsContainer-1) Hibernate: update ProcessInstanceInfo set OPTLOCK=?, processId=?, startDate=?, lastReadDate=?, lastModificationDate=?, state=?, processInstanceByteArray=? where InstanceId=? and OPTLOCK=?

2013-09-29 04:04:18,587 INFO [STDOUT] (jmsContainer-1) Hibernate: update WorkItemInfo set creationDate=?, name=?, processInstanceId=?, state=?, OPTLOCK=?, workItemByteArray=? where workItemId=? and OPTLOCK=?

2013-09-29 04:04:18,588 INFO [STDOUT] (jmsContainer-1) Hibernate: delete from WorkItemInfo where workItemId=? and OPTLOCK=?

2013-09-29 04:04:18,589 INFO [STDOUT] (jmsContainer-1) Hibernate: delete from WorkItemInfo where workItemId=? and OPTLOCK=?

2013-09-29 04:04:18,592 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into Task (archived, allowedToDelegate, taskInitiator_id, priority, activationTime, actualOwner_id, createdBy_id, createdOn, documentAccessType, documentContentId, documentType, expirationTime, faultAccessType, faultContentId, faultName, faultType, outputAccessType, outputContentId, outputType, parentId, previousStatus, processId, processInstanceId, processSessionId, skipable, status, workItemId, OPTLOCK, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:04:18,594 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into I18NText (language, text, id) values (?, ?, ?)

2013-09-29 04:04:18,595 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into Content (content, id) values (?, ?)

2013-09-29 04:04:18,597 INFO [STDOUT] (jmsContainer-1) Hibernate: update Task set archived=?, allowedToDelegate=?, taskInitiator_id=?, priority=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, OPTLOCK=? where id=? and OPTLOCK=?

2013-09-29 04:04:18,598 INFO [STDOUT] (jmsContainer-1) Hibernate: update I18NText set Task_Descriptions_Id=? where id=?

2013-09-29 04:04:18,599 INFO [STDOUT] (jmsContainer-1) Hibernate: update I18NText set Task_Names_Id=? where id=?

2013-09-29 04:04:18,600 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into PeopleAssignments_BAs (task_id, entity_id) values (?, ?)

2013-09-29 04:04:18,602 INFO [STDOUT] (jmsContainer-1) Hibernate: insert into PeopleAssignments_PotOwners (task_id, entity_id) values (?, ?)

2013-09-29 04:04:18,603 INFO [STDOUT] (jmsContainer-1) Hibernate: update I18NText set Task_Subjects_Id=? where id=?

2013-09-29 04:04:18,615 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (jmsContainer-1) into the finally block..

2013-09-29 04:04:18,653 INFO [STDOUT] (jmsContainer-1) SELECT WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID FROM APP_WORKFLOW_APPROVAL, APPROVAL_LEVEL, WORKFLOW_APPROVAL_LEVEL, DRM_ASSIGNEE_NEW, T3485_DEAL_REQUEST, APPLICATION_ATTRIBUTE, WORKFLOW_BUSINESS_UNIT_ASC, APPLICATION_WORKFLOW WHERE DRM_ASSIGNEE_NEW_ID = APPLICATION_ATTRIBUTE.ATTRIBUTE_ID AND APPLICATION_ATTRIBUTE.APPLICATION_ATTRIBUTE_ID = APP_WORKFLOW_APPROVAL.APPLICATION_ATTRIBUTE_ID AND WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID = APP_WORKFLOW_APPROVAL.WORKFLOW_APPROVAL_LEVEL_ID AND APPROVAL_LEVEL.APPROVAL_LEVEL_ID = WORKFLOW_APPROVAL_LEVEL.APPROVAL_LEVEL_ID AND WORKFLOW_BUSINESS_UNIT_ASC.WORKFLOW_BUSINESS_UNIT_ASC_ID = WORKFLOW_APPROVAL_LEVEL.WORKFLOW_BUSINESS_UNIT_ASC_ID AND APPLICATION_WORKFLOW.APPLICATION_WORKFLOW_ID = WORKFLOW_BUSINESS_UNIT_ASC.APPLICATION_WORKFLOW_ID AND WORKFLOW_BUSINESS_UNIT_ASC.DELETED_FLAG = WORKFLOW_APPROVAL_LEVEL.DELETED_FLAG AND WORKFLOW_APPROVAL_LEVEL.DELETED_FLAG = APP_WORKFLOW_APPROVAL.DELETED_FLAG AND APP_WORKFLOW_APPROVAL.DELETED_FLAG = 'N' AND C3485_JBPM_PROCESS_ID = ? AND APPROVAL_LEVEL.APPROVAL_LEVEL_NAME = ? AND C3482_BUSINESS_UNIT_ID = C3485_BUSINESS_UNIT_ID AND C3482_PROJECT_STATE_ID = C3485_PROJECT_STATE_ID AND C3482_PROGRAM_TYPE_ID = C3485_PROGRAM_TYPE_ID AND C3482_PROJECT_TYPE_ID = C3485_PROJECT_TYPE_ID AND C3482_DRM_PROD_GRP_ID = C3485_DRM_PROD_GRP_ID AND C3482_DEVELOPED_FOR = NVL(C3485_DEVELOPED,'I') AND NVL(C3482_DAY_PART_YN,'N') = NVL(C3485_DAY_PART_YN,'N') AND NVL(C3482_DEAL_REQUEST_SUBTYPE_ID,0) = NVL(C3485_DEAL_REQUEST_SUBTYPE_ID,0) AND C3482_DEAL_REQUEST_TYPE_ID = C3485_DEAL_REQUEST_TYPE_ID - QUERY to get the wrkFlwAppID -

2013-09-29 04:04:18,654 INFO [STDOUT] (jmsContainer-1) Sysdate :09/29/13 04:04:18

2013-09-29 04:04:18,654 INFO [STDOUT] (jmsContainer-1) Insert into approval action ---> Genre Dept Head Approvalssoid501884277approve:true

2013-09-29 04:04:18,654 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (jmsContainer-1) Insert into approval action ---> Genre Dept Head Approvalssoid501884277approve:true

2013-09-29 04:04:18,656 INFO [STDOUT] (jmsContainer-1) get procespetive tasks

2013-09-29 04:04:18,658 INFO [STDOUT] (jmsContainer-1) Hibernate: select * from ( select task0_.id as col_0_0_, task0_.processInstanceId as col_1_0_, names4_.text as col_2_0_, subjects2_.text as col_3_0_, descriptio3_.text as col_4_0_, task0_.status as col_5_0_, task0_.priority as col_6_0_, task0_.skipable as col_7_0_, task0_.actualOwner_id as col_8_0_, task0_.createdBy_id as col_9_0_, task0_.createdOn as col_10_0_, task0_.activationTime as col_11_0_, task0_.expirationTime as col_12_0_, task0_.processId as col_13_0_, task0_.processSessionId as col_14_0_ from Task task0_ left outer join OrganizationalEntity user1_ on task0_.createdBy_id=user1_.id left outer join I18NText subjects2_ on task0_.id=subjects2_.Task_Subjects_Id left outer join I18NText descriptio3_ on task0_.id=descriptio3_.Task_Descriptions_Id left outer join I18NText names4_ on task0_.id=names4_.Task_Names_Id inner join OrganizationalEntity user5_ on task0_.actualOwner_id=user5_.id where task0_.archived=0 and task0_.status='Reserved' and task0_.processInstanceId='4682' and (names4_.language='en-UK' or (select count(names7_.Task_Names_Id) from I18NText names7_ where task0_.id=names7_.Task_Names_Id)=0) and (subjects2_.language='en-UK' or (select count(subjects8_.Task_Subjects_Id) from I18NText subjects8_ where task0_.id=subjects8_.Task_Subjects_Id)=0) and (descriptio3_.language='en-UK' or (select count(descriptio9_.Task_Descriptions_Id) from I18NText descriptio9_ where task0_.id=descriptio9_.Task_Descriptions_Id)=0) and (task0_.expirationTime is null) ) where rownum <= ?

2013-09-29 04:04:18,684 INFO [STDOUT] (jmsContainer-1) [org.jbpm.task.query.TaskSummary@5626518] prospectiveTasks.sizeeeeeeeeeeeeeeeeeeeeeee

2013-09-29 04:04:18,684 INFO [STDOUT] (jmsContainer-1) 1 prospectiveTasks.sizeeeeeeeeeeeeeeeeeeeeeee

2013-09-29 04:04:18,684 INFO [STDOUT] (jmsContainer-1) Finance Approval ---> Activity <----> Approver ---> 501933269

2013-09-29 04:04:18,685 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The serviceType is : DB

2013-09-29 04:04:18,685 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The prefix is : java:

2013-09-29 04:04:18,685 DEBUG [com.ge.nbc.common.util.ServiceLocator] (jmsContainer-1) The JNDI Name is : java:oradb356

2013-09-29 04:04:18,689 INFO [STDOUT] (jmsContainer-1) DRMApprovalProcessEJB :: approveOrreject :: fileNames : null

Step 3: Task created out of second iteration is approved and the engine proceeds for 3rd iteration to create a human task (only one task in this case)

2013-09-29 04:35:36,242 INFO [org.apache.struts.action.RequestProcessor] (ajp-3.156.34.175-8009-3) Processing a 'POST' for path '/approveDealAction'

2013-09-29 04:35:36,242 INFO [com.ge.nbc.pdm.deal.app.action.CommonPDMDealAction] (ajp-3.156.34.175-8009-3) Entered into CommonPDMDealAction approveOrRejectPDM method

2013-09-29 04:35:36,242 INFO [STDOUT] (ajp-3.156.34.175-8009-3) navTab ---*****************---------> Pending Approval

2013-09-29 04:35:36,242 DEBUG [com.ge.nbc.pdm.deal.bus.share.util.LookupCache] (ajp-3.156.34.175-8009-3) Looking up DRMApprovalProcess

2013-09-29 04:35:36,243 INFO [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (ajp-3.156.34.175-8009-3) approveOrRejectDRM - taskid --> 4684 --> 1658processid --> 4682 comments -> approve 2 - pdm

2013-09-29 04:35:36,243 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The serviceType is : DB

2013-09-29 04:35:36,243 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The prefix is : java:

2013-09-29 04:35:36,243 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The JNDI Name is : java:oradb356

2013-09-29 04:35:36,248 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select task0_.id as id85_3_, task0_.archived as archived85_3_, task0_.allowedToDelegate as allowedT3_85_3_, task0_.taskInitiator_id as taskIni27_85_3_, task0_.priority as priority85_3_, task0_.activationTime as activati5_85_3_, task0_.actualOwner_id as actualO28_85_3_, task0_.createdBy_id as createdBy29_85_3_, task0_.createdOn as createdOn85_3_, task0_.documentAccessType as document7_85_3_, task0_.documentContentId as document8_85_3_, task0_.documentType as document9_85_3_, task0_.expirationTime as expirat10_85_3_, task0_.faultAccessType as faultAc11_85_3_, task0_.faultContentId as faultCo12_85_3_, task0_.faultName as faultName85_3_, task0_.faultType as faultType85_3_, task0_.outputAccessType as outputA15_85_3_, task0_.outputContentId as outputC16_85_3_, task0_.outputType as outputType85_3_, task0_.parentId as parentId85_3_, task0_.previousStatus as previou19_85_3_, task0_.processId as processId85_3_, task0_.processInstanceId as process21_85_3_, task0_.processSessionId as process22_85_3_, task0_.skipable as skipable85_3_, task0_.status as status85_3_, task0_.workItemId as workItemId85_3_, task0_.OPTLOCK as OPTLOCK85_3_, user1_.id as id80_0_, user2_.id as id80_1_, user3_.id as id80_2_ from Task task0_ left outer join OrganizationalEntity user1_ on task0_.taskInitiator_id=user1_.id left outer join OrganizationalEntity user2_ on task0_.actualOwner_id=user2_.id left outer join OrganizationalEntity user3_ on task0_.createdBy_id=user3_.id where task0_.id=?

2013-09-29 04:35:36,256 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select * from ( select processins0_.id as id71_, processins0_.end_date as end2_71_, processins0_.processId as processId71_, processins0_.processInstanceId as processI4_71_, processins0_.start_date as start5_71_ from ProcessInstanceLog processins0_ where processins0_.processInstanceId=? ) where rownum <= ?

2013-09-29 04:35:36,259 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.factory.WorkflowBusinessDelegate] (ajp-3.156.34.175-8009-3) Entering getProcess for a processInstance:::

2013-09-29 04:35:36,262 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select variablein0_.id as id73_, variablein0_.log_date as log2_73_, variablein0_.processId as processId73_, variablein0_.processInstanceId as processI4_73_, variablein0_.value as value73_, variablein0_.variableId as variableId73_, variablein0_.variableInstanceId as variable7_73_ from VariableInstanceLog variablein0_ where variablein0_.processInstanceId=? order by variablein0_.log_date

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> ProjectTypeId Value -> 2

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> DealRequestCategoryId Value -> 3

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> BusinessUnitId Value -> 32

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> ProjectStateId Value -> 1

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> submitterId Value -> 501884277

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> DealRequestTypeId Value -> 12

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> ProductionGroupId Value -> 0

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> DealRequestSubtypeId Value -> -1

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> DevelopedFor Value -> I

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> DealRequestId Value -> 14522

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> ProgramTypeId Value -> 1

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> DayPart Value -> N

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> TaskInfo Value -> [com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@3c1f82d0]

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> 11:2:taskAssignmentInfo Value -> com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@3c1f82d0

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> Result Value -> {taskId=4683, taskValue=0, taskName=Genre Dept Head Approval, actorName=501884277, plFlag=null}

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> ExitCheck Value -> true

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> TaskInfo Value -> [com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad]

2013-09-29 04:35:36,270 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Key -> 11:2:taskAssignmentInfo Value -> com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@6a7a38ad

2013-09-29 04:35:36,270 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.factory.WorkflowBusinessDelegate] (ajp-3.156.34.175-8009-3) Before returning process::

2013-09-29 04:35:36,271 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select names0_.Task_Names_Id as Task5_85_1_, names0_.id as id1_, names0_.id as id81_0_, names0_.language as language81_0_, names0_.text as text81_0_ from I18NText names0_ where names0_.Task_Names_Id=?

2013-09-29 04:35:36,279 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select descriptio0_.Task_Descriptions_Id as Task6_85_1_, descriptio0_.id as id1_, descriptio0_.id as id81_0_, descriptio0_.language as language81_0_, descriptio0_.text as text81_0_ from I18NText descriptio0_ where descriptio0_.Task_Descriptions_Id=?

2013-09-29 04:35:36,285 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select comments0_.TaskData_Comments_Id as TaskData5_85_2_, comments0_.id as id2_, comments0_.id as id77_1_, comments0_.addedAt as addedAt77_1_, comments0_.addedBy_id as addedBy4_77_1_, comments0_.text as text77_1_, user1_.id as id80_0_ from task_comment comments0_ left outer join OrganizationalEntity user1_ on comments0_.addedBy_id=user1_.id where comments0_.TaskData_Comments_Id=?

2013-09-29 04:35:36,286 INFO [STDOUT] (ajp-3.156.34.175-8009-3) task Id -> 4684 task status -> Reserved for user 501199979 and logged in user is 501199979

2013-09-29 04:35:36,286 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (ajp-3.156.34.175-8009-3) Validating e-mail approver..!

2013-09-29 04:35:36,286 DEBUG [com.ge.nbc.pdm.deal.bus.bd.CommonBD] (ajp-3.156.34.175-8009-3) CommonBD : initializeEJBCreate : Entered in initializeEJBCreate

2013-09-29 04:35:36,287 DEBUG [com.ge.nbc.pdm.deal.bus.bd.CommonBD] (ajp-3.156.34.175-8009-3) Exiting ProductionProjectTVBD.initializeEJBCreate

2013-09-29 04:35:36,287 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The serviceType is : DB

2013-09-29 04:35:36,287 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The prefix is : java:

2013-09-29 04:35:36,287 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The JNDI Name is : java:oradb356

2013-09-29 04:35:36,340 INFO [STDOUT] (ajp-3.156.34.175-8009-3) status 111 --->

2013-09-29 04:35:36,340 INFO [STDOUT] (ajp-3.156.34.175-8009-3) --- status --

2013-09-29 04:35:36,340 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The serviceType is : DB

2013-09-29 04:35:36,340 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The prefix is : java:

2013-09-29 04:35:36,340 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The JNDI Name is : java:oradb356

2013-09-29 04:35:36,344 INFO [STDOUT] (ajp-3.156.34.175-8009-3) The string is -> SELECT WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID WORKFLOW_APPROVAL_LEVEL_ID FROM APPLICATION_WORKFLOW, WORKFLOW_BUSINESS_UNIT_ASC , WORKFLOW_APPROVAL_LEVEL, APPROVAL_LEVEL, t3486_approval_action WHERE APPLICATION_WORKFLOW.APPLICATION_WORKFLOW_ID = WORKFLOW_BUSINESS_UNIT_ASC.APPLICATION_WORKFLOW_ID AND WORKFLOW_APPROVAL_LEVEL.WORKFLOW_BUSINESS_UNIT_ASC_ID = WORKFLOW_BUSINESS_UNIT_ASC.WORKFLOW_BUSINESS_UNIT_ASC_ID AND WORKFLOW_APPROVAL_LEVEL.APPROVAL_LEVEL_ID = APPROVAL_LEVEL.APPROVAL_LEVEL_ID AND T3486_APPROVAL_ACTION.WORKFLOW_APPROVAL_LEVEL_ID = WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID AND APPLICATION_WORKFLOW.PDM_TYPE_ID = ? AND WORKFLOW_BUSINESS_UNIT_ASC.C2082_BUSINESS_UNIT_ID = ? AND C3486_DEAL_REQUEST_ID = ? AND APPROVAL_LEVEL.APPROVAL_LEVEL_NAME = ? AND c3486_approved_yn != 'A' 12 32 14522 Finance Approval

2013-09-29 04:35:36,344 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Action string -> false

2013-09-29 04:35:36,344 INFO [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (ajp-3.156.34.175-8009-3) approver --> 501199979 task name --> Finance Approval --> 501199979

2013-09-29 04:35:36,344 DEBUG [com.ge.nbc.pdm.deal.bus.share.util.LookupCache] (ajp-3.156.34.175-8009-3) Looking up DRMWorkflow

2013-09-29 04:35:36,344 INFO [STDOUT] (ajp-3.156.34.175-8009-3) get procespetive tasks

2013-09-29 04:35:36,363 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select * from ( select task0_.id as col_0_0_, task0_.processInstanceId as col_1_0_, names4_.text as col_2_0_, subjects2_.text as col_3_0_, descriptio3_.text as col_4_0_, task0_.status as col_5_0_, task0_.priority as col_6_0_, task0_.skipable as col_7_0_, task0_.actualOwner_id as col_8_0_, task0_.createdBy_id as col_9_0_, task0_.createdOn as col_10_0_, task0_.activationTime as col_11_0_, task0_.expirationTime as col_12_0_, task0_.processId as col_13_0_, task0_.processSessionId as col_14_0_ from Task task0_ left outer join OrganizationalEntity user1_ on task0_.createdBy_id=user1_.id left outer join I18NText subjects2_ on task0_.id=subjects2_.Task_Subjects_Id left outer join I18NText descriptio3_ on task0_.id=descriptio3_.Task_Descriptions_Id left outer join I18NText names4_ on task0_.id=names4_.Task_Names_Id inner join OrganizationalEntity user5_ on task0_.actualOwner_id=user5_.id where task0_.archived=0 and task0_.status='Reserved' and task0_.processInstanceId='4682' and (names4_.language='en-UK' or (select count(names7_.Task_Names_Id) from I18NText names7_ where task0_.id=names7_.Task_Names_Id)=0) and (subjects2_.language='en-UK' or (select count(subjects8_.Task_Subjects_Id) from I18NText subjects8_ where task0_.id=subjects8_.Task_Subjects_Id)=0) and (descriptio3_.language='en-UK' or (select count(descriptio9_.Task_Descriptions_Id) from I18NText descriptio9_ where task0_.id=descriptio9_.Task_Descriptions_Id)=0) and (task0_.expirationTime is null) ) where rownum <= ?

2013-09-29 04:35:36,380 INFO [STDOUT] (ajp-3.156.34.175-8009-3) [org.jbpm.task.query.TaskSummary@12552bfc] prospectiveTasks.sizeeeeeeeeeeeeeeeeeeeeeee

2013-09-29 04:35:36,380 INFO [STDOUT] (ajp-3.156.34.175-8009-3) 1 prospectiveTasks.sizeeeeeeeeeeeeeeeeeeeeeee

2013-09-29 04:35:36,380 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Finance Approval ---> Activity <----> Approver ---> 501199979

2013-09-29 04:35:36,380 INFO [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (ajp-3.156.34.175-8009-3) pla flag value..false

2013-09-29 04:35:36,380 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (ajp-3.156.34.175-8009-3) Before making a call jBPM to approve the task

2013-09-29 04:35:36,380 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (ajp-3.156.34.175-8009-3) In Complete task

2013-09-29 04:35:36,394 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select sessioninf0_.id as id69_0_, sessioninf0_.lastModificationDate as lastModi2_69_0_, sessioninf0_.rulesByteArray as rulesByt3_69_0_, sessioninf0_.startDate as startDate69_0_, sessioninf0_.OPTLOCK as OPTLOCK69_0_ from SessionInfo sessioninf0_ where sessioninf0_.id=?

2013-09-29 04:35:36,407 DEBUG [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (ajp-3.156.34.175-8009-3) In Approve task

2013-09-29 04:35:36,407 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (ajp-3.156.34.175-8009-3) pl flag value..null

2013-09-29 04:35:36,411 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (ajp-3.156.34.175-8009-3) to get the local task service..

2013-09-29 04:35:36,411 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (ajp-3.156.34.175-8009-3) to get the task service..

2013-09-29 04:35:36,424 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select task0_.id as col_0_0_, deadline1_.id as col_1_0_, deadline1_.deadline_date as col_2_0_ from Task task0_, Deadline deadline1_ where task0_.archived=0 and (deadline1_.id in (select startdeadl2_.id from Deadline startdeadl2_ where task0_.id=startdeadl2_.Deadlines_StartDeadLine_Id) or deadline1_.id in (select enddeadlin3_.id from Deadline enddeadlin3_ where task0_.id=enddeadlin3_.Deadlines_EndDeadLine_Id)) and deadline1_.escalated=0 order by deadline1_.deadline_date

2013-09-29 04:35:36,533 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select task0_.id as id85_3_, task0_.archived as archived85_3_, task0_.allowedToDelegate as allowedT3_85_3_, task0_.taskInitiator_id as taskIni27_85_3_, task0_.priority as priority85_3_, task0_.activationTime as activati5_85_3_, task0_.actualOwner_id as actualO28_85_3_, task0_.createdBy_id as createdBy29_85_3_, task0_.createdOn as createdOn85_3_, task0_.documentAccessType as document7_85_3_, task0_.documentContentId as document8_85_3_, task0_.documentType as document9_85_3_, task0_.expirationTime as expirat10_85_3_, task0_.faultAccessType as faultAc11_85_3_, task0_.faultContentId as faultCo12_85_3_, task0_.faultName as faultName85_3_, task0_.faultType as faultType85_3_, task0_.outputAccessType as outputA15_85_3_, task0_.outputContentId as outputC16_85_3_, task0_.outputType as outputType85_3_, task0_.parentId as parentId85_3_, task0_.previousStatus as previou19_85_3_, task0_.processId as processId85_3_, task0_.processInstanceId as process21_85_3_, task0_.processSessionId as process22_85_3_, task0_.skipable as skipable85_3_, task0_.status as status85_3_, task0_.workItemId as workItemId85_3_, task0_.OPTLOCK as OPTLOCK85_3_, user1_.id as id80_0_, user2_.id as id80_1_, user3_.id as id80_2_ from Task task0_ left outer join OrganizationalEntity user1_ on task0_.taskInitiator_id=user1_.id left outer join OrganizationalEntity user2_ on task0_.actualOwner_id=user2_.id left outer join OrganizationalEntity user3_ on task0_.createdBy_id=user3_.id where task0_.id=?

2013-09-29 04:35:36,538 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: update Task set archived=?, allowedToDelegate=?, taskInitiator_id=?, priority=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, OPTLOCK=? where id=? and OPTLOCK=?

2013-09-29 04:35:36,616 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select CONTENT_ID_SEQ.nextval from dual

2013-09-29 04:35:36,618 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select subtaskstr0_.Task_Id as Task4_85_1_, subtaskstr0_.id as id1_, subtaskstr0_.id as id86_0_, subtaskstr0_.name as name86_0_, subtaskstr0_.DTYPE as DTYPE86_0_ from SubTasksStrategy subtaskstr0_ where subtaskstr0_.Task_Id=?

2013-09-29 04:35:36,620 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: insert into Content (content, id) values (?, ?)

2013-09-29 04:35:36,621 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: update Task set archived=?, allowedToDelegate=?, taskInitiator_id=?, priority=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, OPTLOCK=? where id=? and OPTLOCK=?

2013-09-29 04:35:36,655 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select workitemin0_.workItemId as workItemId70_0_, workitemin0_.creationDate as creation2_70_0_, workitemin0_.name as name70_0_, workitemin0_.processInstanceId as processI4_70_0_, workitemin0_.state as state70_0_, workitemin0_.OPTLOCK as OPTLOCK70_0_, workitemin0_.workItemByteArray as workItem7_70_0_ from WorkItemInfo workitemin0_ where workitemin0_.workItemId=?

2013-09-29 04:35:36,658 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select processins0_.InstanceId as InstanceId67_0_, processins0_.OPTLOCK as OPTLOCK67_0_, processins0_.processId as processId67_0_, processins0_.startDate as startDate67_0_, processins0_.lastReadDate as lastRead5_67_0_, processins0_.lastModificationDate as lastModi6_67_0_, processins0_.state as state67_0_, processins0_.processInstanceByteArray as processI8_67_0_ from ProcessInstanceInfo processins0_ where processins0_.InstanceId=?

2013-09-29 04:35:36,667 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE RULEFLOW VARIABLE CHANGED Result={taskId=4684, taskValue=0, taskName=Finance Approval, actorName=501199979, plFlag=null} process:PDM[id=PDM]

2013-09-29 04:35:36,667 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,669 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER RULEFLOW VARIABLE CHANGED Result={taskId=4684, taskValue=0, taskName=Finance Approval, actorName=501199979, plFlag=null} process:PDM[id=PDM]

2013-09-29 04:35:36,669 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Exiting user task node

2013-09-29 04:35:36,669 INFO [STDOUT] (ajp-3.156.34.175-8009-3) taskAssignmentInfo in task node...com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@132254ed

2013-09-29 04:35:36,669 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,671 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE EXITED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

2013-09-29 04:35:36,671 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,672 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:End[id=11:3] process:PDM[id=PDM]

2013-09-29 04:35:36,672 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,673 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE EXITED node:End[id=11:3] process:PDM[id=PDM]

2013-09-29 04:35:36,674 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,675 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE EXITED node:Multiple Instances[id=11] process:PDM[id=PDM]

2013-09-29 04:35:36,675 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,676 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:Evaluate Process Flow[id=17] process:PDM[id=PDM]

2013-09-29 04:35:36,677 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select WORKITEMINFO_ID_SEQ.nextval from dual

2013-09-29 04:35:36,678 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) work item name in eval...Task Evaluation

2013-09-29 04:35:36,678 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) execution path name...null

2013-09-29 04:35:36,678 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) execution path name...{taskId=4684, taskValue=0, taskName=Finance Approval, actorName=501199979, plFlag=null}

2013-09-29 04:35:36,678 DEBUG [com.ge.nbc.pdm.deal.bus.share.util.LookupCache] (ajp-3.156.34.175-8009-3) Looking up DRMWorkflow

2013-09-29 04:35:36,679 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) task request type... work item name...Task Evaluation

2013-09-29 04:35:36,679 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) I DevelopedFor: I

2013-09-29 04:35:36,679 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) Approver name...501933269

2013-09-29 04:35:36,679 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) Task name...Finance Approval

2013-09-29 04:35:36,679 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) PL Flag...null

2013-09-29 04:35:36,679 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) Entering the getAssignees method

2013-09-29 04:35:36,679 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) drmCharacteristics.getDealRequestType()12

2013-09-29 04:35:36,679 INFO [STDOUT] (ajp-3.156.34.175-8009-3) drmCharacteristics.getDealRequestType()12

2013-09-29 04:35:36,679 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) Before entering getNextTasksAndApproversForPDM method

2013-09-29 04:35:36,679 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The serviceType is : DB

2013-09-29 04:35:36,679 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The prefix is : java:

2013-09-29 04:35:36,679 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The JNDI Name is : java:oradb356

2013-09-29 04:35:36,680 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) getApprovers query: SELECT APPROVAL_LEVEL.APPROVAL_LEVEL_NAME, WORKFLOW_APPROVAL_USER.USER_ID, WORKFLOW_APPROVAL_LEVEL.LEVEL_NUM FROM DRM_ASSIGNEE_NEW, APPLICATION_ATTRIBUTE, APP_WORKFLOW_APPROVAL, WORKFLOW_APPROVAL_USER, APPROVAL_LEVEL, WORKFLOW_APPROVAL_LEVEL, WORKFLOW_BUSINESS_UNIT_ASC, APPLICATION_WORKFLOW, T2030_USER WHERE DRM_ASSIGNEE_NEW_ID = APPLICATION_ATTRIBUTE.ATTRIBUTE_ID AND APPLICATION_ATTRIBUTE.APPLICATION_ATTRIBUTE_ID = APP_WORKFLOW_APPROVAL.APPLICATION_ATTRIBUTE_ID AND APP_WORKFLOW_APPROVAL.APP_WORKFLOW_APPROVAL_ID = WORKFLOW_APPROVAL_USER.APP_WORKFLOW_APPROVAL_ID AND WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID = APP_WORKFLOW_APPROVAL.WORKFLOW_APPROVAL_LEVEL_ID AND APPROVAL_LEVEL.APPROVAL_LEVEL_ID = WORKFLOW_APPROVAL_LEVEL.APPROVAL_LEVEL_ID AND APPLICATION_WORKFLOW.APPLICATION_WORKFLOW_ID =WORKFLOW_BUSINESS_UNIT_ASC.APPLICATION_WORKFLOW_ID AND WORKFLOW_BUSINESS_UNIT_ASC.WORKFLOW_BUSINESS_UNIT_ASC_ID = WORKFLOW_APPROVAL_LEVEL.WORKFLOW_BUSINESS_UNIT_ASC_ID AND WORKFLOW_BUSINESS_UNIT_ASC.DELETED_FLAG = WORKFLOW_APPROVAL_LEVEL.DELETED_FLAG AND WORKFLOW_APPROVAL_LEVEL.DELETED_FLAG = APP_WORKFLOW_APPROVAL.DELETED_FLAG AND APP_WORKFLOW_APPROVAL.DELETED_FLAG = WORKFLOW_APPROVAL_USER.DELETED_FLAG AND WORKFLOW_APPROVAL_USER.DELETED_FLAG = 'N' AND WORKFLOW_APPROVAL_USER.USER_ID = T2030_USER.C2030_USER_ID AND APPLICATION_WORKFLOW.PDM_TYPE_ID = ? AND WORKFLOW_BUSINESS_UNIT_ASC.C2082_BUSINESS_UNIT_ID = ? AND C3482_BUSINESS_UNIT_ID = ? AND C3482_DEAL_REQUEST_TYPE_ID = ? AND C3482_PROJECT_STATE_ID = 1 AND C3482_PROGRAM_TYPE_ID = 1 AND C3482_PROJECT_TYPE_ID = 2 AND C3482_DAY_PART_YN = 'N' AND C3482_DRM_PROD_GRP_ID = 0 AND C3482_DEVELOPED_FOR = 'I'AND C3482_DEAL_REQUEST_SUBTYPE_ID is null order by LEVEL_NUM,PARALLEL_LEVEL drmCharacteristics :DRMCharacteristics: dealRequestType=12,dealRequestSubtype=-1,projectState=1,businessUnit=32,activity='null',projectType=2,programType=1,DayPart=N,ProductionGroup=0

2013-09-29 04:35:36,691 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Info -> num -> Genre Dept Head Approval 1

2013-09-29 04:35:36,691 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Info -> num -> Finance Approval 2

2013-09-29 04:35:36,691 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Info -> num -> Negotiator Assignment 3

2013-09-29 04:35:36,691 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) The assignees are:loaded

2013-09-29 04:35:36,691 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) After exiting getNextTasksAndApproversForPDM method

2013-09-29 04:35:36,691 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) Task Info....[com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@7cf74d87]

2013-09-29 04:35:36,691 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) Before entering getDelegateIfExists method

2013-09-29 04:35:36,691 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) In getDelegateIfExists for 501884277

2013-09-29 04:35:36,691 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The serviceType is : DB

2013-09-29 04:35:36,691 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The prefix is : java:

2013-09-29 04:35:36,691 DEBUG [com.ge.nbc.common.util.ServiceLocator] (ajp-3.156.34.175-8009-3) The JNDI Name is : java:oradb356

2013-09-29 04:35:36,694 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) After exiting getDelegateIfExists method

2013-09-29 04:35:36,694 INFO [STDOUT] (ajp-3.156.34.175-8009-3) assignee_delegate output...null

2013-09-29 04:35:36,694 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) The Final assignees after delegateCheck: com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@7cf74d87

2013-09-29 04:35:36,694 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMWorkflowEJB] (ajp-3.156.34.175-8009-3) Exiting out of the getAssignees method

2013-09-29 04:35:36,694 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) exit check entry variable..true

2013-09-29 04:35:36,694 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE RULEFLOW VARIABLE CHANGED TaskInfo=[com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@7cf74d87] process:PDM[id=PDM]

2013-09-29 04:35:36,694 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,696 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER RULEFLOW VARIABLE CHANGED TaskInfo=[com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@7cf74d87] process:PDM[id=PDM]

2013-09-29 04:35:36,696 INFO [STDOUT] (ajp-3.156.34.175-8009-3) exiting evaluate process flow..

2013-09-29 04:35:36,696 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,697 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE EXITED node:Evaluate Process Flow[id=17] process:PDM[id=PDM]

2013-09-29 04:35:36,697 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,699 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:Gateway[id=5] process:PDM[id=PDM]

2013-09-29 04:35:36,699 INFO [STDOUT] (ajp-3.156.34.175-8009-3) ExitChecker..true

2013-09-29 04:35:36,699 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,700 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE EXITED node:Gateway[id=5] process:PDM[id=PDM]

2013-09-29 04:35:36,701 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,702 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:Loop Back[id=12] process:PDM[id=PDM]

2013-09-29 04:35:36,702 INFO [STDOUT] (ajp-3.156.34.175-8009-3) looping back...entering next iteration..

2013-09-29 04:35:36,702 INFO [STDOUT] (ajp-3.156.34.175-8009-3) TaskInfo Obj -> [com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@7cf74d87]

2013-09-29 04:35:36,702 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,704 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE EXITED node:Loop Back[id=12] process:PDM[id=PDM]

2013-09-29 04:35:36,704 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,705 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:Gateway[id=18] process:PDM[id=PDM]

2013-09-29 04:35:36,705 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,707 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE EXITED node:Gateway[id=18] process:PDM[id=PDM]

2013-09-29 04:35:36,707 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,708 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:Multiple Instances[id=11] process:PDM[id=PDM]

2013-09-29 04:35:36,708 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE RULEFLOW VARIABLE CHANGED 11:2:taskAssignmentInfo=com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@7cf74d87 process:PDM[id=PDM]

2013-09-29 04:35:36,708 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select VAR_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,710 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER RULEFLOW VARIABLE CHANGED 11:2:taskAssignmentInfo=com.ge.nbc.pdm.deal.bus.domain.TaskAssignmentInfo@7cf74d87 process:PDM[id=PDM]

2013-09-29 04:35:36,710 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,711 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:Start[id=11:2] process:PDM[id=PDM]

2013-09-29 04:35:36,711 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,714 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE EXITED node:Start[id=11:2] process:PDM[id=PDM]

2013-09-29 04:35:36,714 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select NODE_INST_LOG_ID_SEQ.nextval from dual

2013-09-29 04:35:36,716 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

2013-09-29 04:35:36,716 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select WORKITEMINFO_ID_SEQ.nextval from dual

2013-09-29 04:35:36,718 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select hibernate_sequence.nextval from dual

2013-09-29 04:35:36,720 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select user_.id from OrganizationalEntity user_ where user_.id=?

2013-09-29 04:35:36,721 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 04:35:36,723 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 04:35:36,724 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual

2013-09-29 04:35:36,726 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select CONTENT_ID_SEQ.nextval from dual

2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Start[id=11:2] process:PDM[id=PDM]

2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Multiple Instances[id=11] process:PDM[id=PDM]

2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Gateway[id=18] process:PDM[id=PDM]

2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Loop Back[id=12] process:PDM[id=PDM]

2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Gateway[id=5] process:PDM[id=PDM]

2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Evaluate Process Flow[id=17] process:PDM[id=PDM]

2013-09-29 04:35:36,727 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.handler.TaskEvaluationWIHandler] (ajp-3.156.34.175-8009-3) After Complete workItem

2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Evaluate Process Flow[id=17] process:PDM[id=PDM]

2013-09-29 04:35:36,728 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Multiple Instances[id=11] process:PDM[id=PDM]

2013-09-29 04:35:36,728 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:End[id=11:3] process:PDM[id=PDM]

2013-09-29 04:35:36,728 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

2013-09-29 04:35:36,728 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: insert into Task (archived, allowedToDelegate, taskInitiator_id, priority, activationTime, actualOwner_id, createdBy_id, createdOn, documentAccessType, documentContentId, documentType, expirationTime, faultAccessType, faultContentId, faultName, faultType, outputAccessType, outputContentId, outputType, parentId, previousStatus, processId, processInstanceId, processSessionId, skipable, status, workItemId, OPTLOCK, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)

2013-09-29 04:35:36,730 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: insert into I18NText (language, text, id) values (?, ?, ?)

2013-09-29 04:35:36,731 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: insert into Content (content, id) values (?, ?)

2013-09-29 04:35:36,732 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: update Task set archived=?, allowedToDelegate=?, taskInitiator_id=?, priority=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, OPTLOCK=? where id=? and OPTLOCK=?

2013-09-29 04:35:36,733 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: update I18NText set Task_Descriptions_Id=? where id=?

2013-09-29 04:35:36,734 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: update I18NText set Task_Names_Id=? where id=?

2013-09-29 04:35:36,735 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: insert into PeopleAssignments_BAs (task_id, entity_id) values (?, ?)

2013-09-29 04:35:36,736 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: insert into PeopleAssignments_PotOwners (task_id, entity_id) values (?, ?)

2013-09-29 04:35:36,737 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: update I18NText set Task_Subjects_Id=? where id=?

2013-09-29 04:35:36,765 INFO [com.ge.nbc.pdm.deal.bus.share.workflow.util.JBPMHelper] (ajp-3.156.34.175-8009-3) into the finally block..

2013-09-29 04:35:36,804 INFO [STDOUT] (ajp-3.156.34.175-8009-3) SELECT WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID FROM APP_WORKFLOW_APPROVAL, APPROVAL_LEVEL, WORKFLOW_APPROVAL_LEVEL, DRM_ASSIGNEE_NEW, T3485_DEAL_REQUEST, APPLICATION_ATTRIBUTE, WORKFLOW_BUSINESS_UNIT_ASC, APPLICATION_WORKFLOW WHERE DRM_ASSIGNEE_NEW_ID = APPLICATION_ATTRIBUTE.ATTRIBUTE_ID AND APPLICATION_ATTRIBUTE.APPLICATION_ATTRIBUTE_ID = APP_WORKFLOW_APPROVAL.APPLICATION_ATTRIBUTE_ID AND WORKFLOW_APPROVAL_LEVEL.WORKFLOW_APPROVAL_LEVEL_ID = APP_WORKFLOW_APPROVAL.WORKFLOW_APPROVAL_LEVEL_ID AND APPROVAL_LEVEL.APPROVAL_LEVEL_ID = WORKFLOW_APPROVAL_LEVEL.APPROVAL_LEVEL_ID AND WORKFLOW_BUSINESS_UNIT_ASC.WORKFLOW_BUSINESS_UNIT_ASC_ID = WORKFLOW_APPROVAL_LEVEL.WORKFLOW_BUSINESS_UNIT_ASC_ID AND APPLICATION_WORKFLOW.APPLICATION_WORKFLOW_ID = WORKFLOW_BUSINESS_UNIT_ASC.APPLICATION_WORKFLOW_ID AND WORKFLOW_BUSINESS_UNIT_ASC.DELETED_FLAG = WORKFLOW_APPROVAL_LEVEL.DELETED_FLAG AND WORKFLOW_APPROVAL_LEVEL.DELETED_FLAG = APP_WORKFLOW_APPROVAL.DELETED_FLAG AND APP_WORKFLOW_APPROVAL.DELETED_FLAG = 'N' AND C3485_JBPM_PROCESS_ID = ? AND APPROVAL_LEVEL.APPROVAL_LEVEL_NAME = ? AND C3482_BUSINESS_UNIT_ID = C3485_BUSINESS_UNIT_ID AND C3482_PROJECT_STATE_ID = C3485_PROJECT_STATE_ID AND C3482_PROGRAM_TYPE_ID = C3485_PROGRAM_TYPE_ID AND C3482_PROJECT_TYPE_ID = C3485_PROJECT_TYPE_ID AND C3482_DRM_PROD_GRP_ID = C3485_DRM_PROD_GRP_ID AND C3482_DEVELOPED_FOR = NVL(C3485_DEVELOPED,'I') AND NVL(C3482_DAY_PART_YN,'N') = NVL(C3485_DAY_PART_YN,'N') AND NVL(C3482_DEAL_REQUEST_SUBTYPE_ID,0) = NVL(C3485_DEAL_REQUEST_SUBTYPE_ID,0) AND C3482_DEAL_REQUEST_TYPE_ID = C3485_DEAL_REQUEST_TYPE_ID - QUERY to get the wrkFlwAppID -

2013-09-29 04:35:36,804 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Sysdate :09/29/13 04:35:36

2013-09-29 04:35:36,804 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Insert into approval action ---> Finance Approvalssoid501199979approve:true

2013-09-29 04:35:36,804 DEBUG [com.ge.nbc.pdm.deal.bus.ejb.DRMApprovalProcessEJB] (ajp-3.156.34.175-8009-3) Insert into approval action ---> Finance Approvalssoid501199979approve:true

2013-09-29 04:35:36,806 INFO [STDOUT] (ajp-3.156.34.175-8009-3) get procespetive tasks

2013-09-29 04:35:36,808 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select * from ( select task0_.id as col_0_0_, task0_.processInstanceId as col_1_0_, names4_.text as col_2_0_, subjects2_.text as col_3_0_, descriptio3_.text as col_4_0_, task0_.status as col_5_0_, task0_.priority as col_6_0_, task0_.skipable as col_7_0_, task0_.actualOwner_id as col_8_0_, task0_.createdBy_id as col_9_0_, task0_.createdOn as col_10_0_, task0_.activationTime as col_11_0_, task0_.expirationTime as col_12_0_, task0_.processId as col_13_0_, task0_.processSessionId as col_14_0_ from Task task0_ left outer join OrganizationalEntity user1_ on task0_.createdBy_id=user1_.id left outer join I18NText subjects2_ on task0_.id=subjects2_.Task_Subjects_Id left outer join I18NText descriptio3_ on task0_.id=descriptio3_.Task_Descriptions_Id left outer join I18NText names4_ on task0_.id=names4_.Task_Names_Id inner join OrganizationalEntity user5_ on task0_.actualOwner_id=user5_.id where task0_.archived=0 and task0_.status='Reserved' and task0_.processInstanceId='4682' and (names4_.language='en-UK' or (select count(names7_.Task_Names_Id) from I18NText names7_ where task0_.id=names7_.Task_Names_Id)=0) and (subjects2_.language='en-UK' or (select count(subjects8_.Task_Subjects_Id) from I18NText subjects8_ where task0_.id=subjects8_.Task_Subjects_Id)=0) and (descriptio3_.language='en-UK' or (select count(descriptio9_.Task_Descriptions_Id) from I18NText descriptio9_ where task0_.id=descriptio9_.Task_Descriptions_Id)=0) and (task0_.expirationTime is null) ) where rownum <= ?

2013-09-29 04:35:36,827 INFO [STDOUT] (ajp-3.156.34.175-8009-3) [org.jbpm.task.query.TaskSummary@9445e1e9] prospectiveTasks.sizeeeeeeeeeeeeeeeeeeeeeee

2013-09-29 04:35:36,827 INFO [STDOUT] (ajp-3.156.34.175-8009-3) 1 prospectiveTasks.sizeeeeeeeeeeeeeeeeeeeeeee

2013-09-29 04:35:36,827 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Negotiator Assignment ---> Activity <----> Approver ---> 501884277

If we compare the logs from step 2 & step 3 we could figure out that node instances, work items are not created in the step 3 wheare tasks are created. This leads to an abnormal interruption of the process when the tasks created out of step 3 are approved because the engine is not able to identify the corresponding work item in the work item info table.

Per Business logic, my data input requires 4 iterations that can create 4 set of tasks. So now, the issue here is I'm getting only 3 set of tasks created and my Business Process is incomplete.

Any insight/assistance/troubleshooting would be really helpful as it is highly critical in our organization.

Thanks,

Aadav

1. Re: Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

swiderski.maciej Oct 1, 2013 1:52 AM (in response to aadav86)
it looks like the user task is directly completed and by that work item is completed as well and that's why there is not insert into db:

2013-09-29 04:35:36,716 INFO [STDOUT] (ajp-3.156.34.175-8009-3) BEFORE PROCESS NODE TRIGGERED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]
2013-09-29 04:35:36,716 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select WORKITEMINFO_ID_SEQ.nextval from dual
2013-09-29 04:35:36,718 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select hibernate_sequence.nextval from dual
2013-09-29 04:35:36,720 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select user_.id from OrganizationalEntity user_ where user_.id=?
2013-09-29 04:35:36,721 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual
2013-09-29 04:35:36,723 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual
2013-09-29 04:35:36,724 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select I18NTEXT_ID_SEQ.nextval from dual
2013-09-29 04:35:36,726 INFO [STDOUT] (ajp-3.156.34.175-8009-3) Hibernate: select CONTENT_ID_SEQ.nextval from dual
2013-09-29 04:35:36,727 INFO [STDOUT] (ajp-3.156.34.175-8009-3) AFTER PROCESS NODE TRIGGERED node:Approve Task(s)[id=11:4] process:PDM[id=PDM]

when you look at first and last line of this log you will notice to important things:
work item id was taken from sequence
Approve Task user task has been left very quickly after it was triggered
now the main question is why it gets completed? That might be due to an error which calls actually abort on the handler and the work item is aborted.
I would recommend to try to use a handler that gives you more information on what it does and why it gets completed so fast.

HTH
Actions
2. Re: Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

aadav86 Oct 1, 2013 7:00 AM (in response to swiderski.maciej)

Hi Macijes,

Thanks very much for the comments. Can you suggest me a Human Task Handler to use in this place. I'm using jBPM 5.3 with local task handler.

Thanks,
Aadav
Actions
3. Re: Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

josdel Oct 1, 2013 7:28 AM (in response to aadav86)

HumanTaskHandler, WSHumanTaskHandler are two Human Task Handlers.
Actions
4. Re: Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

aadav86 Oct 1, 2013 10:08 AM (in response to josdel)

Thanks Josny,

Aadav
Actions
5. Re: Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

swiderski.maciej Oct 1, 2013 1:28 PM (in response to aadav86)

Aadav, I had in mind more like a custom handler (extension of those already existing) that would be enhanced with more logging information to track what is going on and why it does complete/abort the task so quickly.

HTH
Actions
6. Re: Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

aadav86 Oct 1, 2013 11:39 PM (in response to swiderski.maciej)

Maciejs,

Is there any way to enable the jBPM logging to check the logs immediately in the production. Because issue is occurring in production only and for us it is not easy and immediately doable to change the code and push it to production. Please advise.

Thanks,
Aadav
Actions
7. Re: Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

swiderski.maciej Oct 3, 2013 10:01 AM (in response to aadav86)

I am afraid there is not much logging available there and that's why I suggested to use custom handler for it. Could you please file a jira issue for enhancing logging for ht handlers so we add that in v6?

Cheers
Actions
8. Re: Facing issues in WorkItem creation for Human Task node placed inside Multiple Instances

aadav86 Oct 3, 2013 5:19 PM (in response to swiderski.maciej)

Sure Maciej..
Actions

Go to original post