Hi,
I have created a process with 1 Partner and tested it. It is working fine. Now I added another partner. then I am getting a FAULT STRING - <soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/";> - <soapenv:Body> - <soapenv:Fault> <faultcode>soapenv:Serverfaultcode> <faultstring xmlns:axis2ns37="http://docs.oasis-open.org/wsbpel/2.0/process/executable";>axis2ns37:uninitializedPartnerRolefaultstring> <detail /> soapenv:Fault> soapenv:Body> soapenv:Envelope> THE ODE LOG IS AS BELOW; 15:46:15,618 DEBUG [Properties] Translating Properties for Axis2 15:46:15,618 DEBUG [ODEService] Starting transaction. 15:46:15,623 DEBUG [BpelEngineImpl] Routed: svcQname {org.booking.travel}travelBookingProcess --> [BpelProcess[{org.booking.travel}travelBookingProcess-25]] 15:46:15,646 DEBUG [ODEService] ODE routed to operation Operation: name=process style=REQUEST_RESPONSE,1 Input: name=null Message: name={org.booking.travel}travelBookingProcessRequestMessage Part: name=payload elementName={org.booking.travel}travelBookingProcessRequest Output: name=null Message: name={org.booking.travel}travelBookingProcessResponseMessage Part: name=payload elementName={org.booking.travel}travelBookingProcessResponse from service {org.booking.travel}travelBookingProcess 15:46:15,646 DEBUG [MessageExchangeImpl] SET MEX property isTwoWay = true 15:46:15,659 DEBUG [MessageDAOImpl] getData null null 15:46:15,660 DEBUG [MessageDAOImpl] setData null 969696 kjgkjg kgkjg kgjk kjgk kjgk kjg 15:46:15,661 DEBUG [ODEService] Invoking ODE using MEX {MyRoleMex#hqejbhcnphr6lhnqqfop8w [Client hqejbhcnphr6lhnqqfop8v] calling {org.booking.travel}travelBookingProcess.process(...)} 15:46:15,661 DEBUG [MessageDAOImpl] getData null 969696 kjgkjg kgkjg kgjk kjgk kjgk kjg 15:46:15,662 DEBUG [ODEService] Message content: 969696 kjgkjg kgkjg kgjk kjgk kjgk kjg 15:46:15,670 DEBUG [MyRoleMessageExchangeImpl] invoke() EPR= null ==> BpelProcess[{org.booking.travel}travelBookingProcess-25] 15:46:15,679 DEBUG [SimpleScheduler] scheduling JobDetails( instanceId: null mexId: hqejbhcnphr6lhnqqfop8w processId: {org.booking.travel}travelBookingProcess-25 type: INVOKE_INTERNAL channel: null correlatorId: null correlationKeySet: null retryCount: null inMem: false detailsExt: {}) for Thu Sep 15 15:46:15 EST 2011 15:46:15,680 DEBUG [JdbcDelegate] insertJob hqejbhcnphr6lhnqqfop8x on node hqejbhcnphr6lhnqqfop8u loaded=true 15:46:15,716 DEBUG [SimpleScheduler] scheduled immediate job: hqejbhcnphr6lhnqqfop8x 15:46:15,717 DEBUG [ODEService] Commiting ODE MEX {MyRoleMex#hqejbhcnphr6lhnqqfop8w [Client hqejbhcnphr6lhnqqfop8v] calling {org.booking.travel}travelBookingProcess.process(...)} 15:46:15,717 DEBUG [ODEService] Commiting transaction. 15:46:15,943 DEBUG [SimpleScheduler] Beginning a new transaction 15:46:15,943 DEBUG [JdbcDelegate] deleteJob hqejbhcnphr6lhnqqfop8x on node hqejbhcnphr6lhnqqfop8u 15:46:15,962 DEBUG [BpelEngineImpl] handleJobDetails: InvokeInternal event for mexid hqejbhcnphr6lhnqqfop8w 15:46:15,990 DEBUG [BpelProcess] >> handleJobDetails(jobData=JobDetails( instanceId: null mexId: hqejbhcnphr6lhnqqfop8w processId: {org.booking.travel}travelBookingProcess-25 type: INVOKE_INTERNAL channel: null correlatorId: null correlationKeySet: null retryCount: null inMem: false detailsExt: {})) 15:46:15,990 DEBUG [BpelProcess] InvokeInternal event for mexid hqejbhcnphr6lhnqqfop8w 15:46:16,046 DEBUG [MessageDAOImpl] getData 16901 969696 kjgkjg kgkjg kgjk kjgk kjgk kjg 15:46:16,049 DEBUG [MessageExchangeImpl] GET MEX property org.apache.ode.bpel.myRoleSessionId = null 15:46:16,049 DEBUG [MessageExchangeImpl] GET MEX property org.apache.ode.bpel.myRoleSessionId = null 15:46:16,049 DEBUG [MessageExchangeImpl] GET MEX property org.apache.ode.bpel.partnerRoleSessionId = null 15:46:16,049 DEBUG [BpelProcess] INPUTMSG: client.process: MSG RCVD keys=[] mySessionId=null partnerSessionId=null 15:46:16,049 DEBUG [CorrelatorDAOImpl] findRoute [] 15:46:16,295 DEBUG [CorrelatorDAOImpl] findRoute found nothing 15:46:16,297 DEBUG [BpelProcess] INPUTMSG: client.process: routing failed, CREATING NEW INSTANCE 15:46:16,353 DEBUG [JacobVPU] injecting PROCESS(...) 15:46:16,353 DEBUG [BpelRuntimeContextImpl] BpelRuntimeContextImpl created for instance 16951. INDEXED STATE={} 15:46:16,458 DEBUG [BpelProcess] SELECT: PickResponseChannel#9: USING CORRELATOR client.process 15:46:16,462 DEBUG [BpelProcess] SELECT: PickResponseChannel#9: CHECKING for NEW INSTANCE match 15:46:16,462 DEBUG [BpelProcess] INPUTMSGMATCH: Changing process instance state from ready to active 15:46:16,463 DEBUG [JacobVPU] injecting (...) 15:46:16,463 DEBUG [BpelProcess] SELECT: PickResponseChannel#9: FOUND match for NEW instance mexRef={MyRoleMex#hqejbhcnphr6lhnqqfop8w [Client hqejbhcnphr6lhnqqfop8v] calling {org.booking.travel}travelBookingProcess.process(...)} 15:46:16,470 DEBUG [MessageDAOImpl] getData 16901 969696 kjgkjg kgkjg kgjk kjgk kjgk kjg 15:46:16,472 DEBUG [ScopeFrame] Initialize variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)} value= 969696 kjgkjg kgkjg kgjk kjgk kjgk kjg 15:46:16,475 DEBUG [EMPTY] 15:46:16,491 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLRequest:OMessageVarType#18({http://checkCredit.apache.org}validateCreditCardRequest)}.parameters}={Literal ns:str_CardNumber ns:str_CardType }}) 15:46:16,492 DEBUG [ASSIGN] Evaluating FROM expression "{Literal ns:str_CardNumber ns:str_CardType }". 15:46:16,493 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:16,493 DEBUG [ASSIGN] content 15:46:16,498 DEBUG [ASSIGN] ASSIGN Writing variable 'creditCheckPLRequest' value ' ns:str_CardNumber ns:str_CardType ' 15:46:16,499 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLRequest:OMessageVarType#18({http://checkCredit.apache.org}validateCreditCardRequest)} value= ns:str_CardNumber ns:str_CardType 15:46:16,500 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLRequest:OMessageVarType#18({http://checkCredit.apache.org}validateCreditCardRequest)}.parameters{OXPath10Expression ns:str_CardNumber}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:cardNumber}}}) 15:46:16,500 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:cardNumber}}". 15:46:16,607 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,608 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,608 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,608 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,608 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,608 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,608 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,608 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:16,608 DEBUG [ASSIGN] content ns:str_CardNumber ns:str_CardType 15:46:16,609 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns)=http://checkCredit.apache.org 15:46:16,609 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns)=http://checkCredit.apache.org 15:46:16,609 DEBUG [ASSIGN] ASSIGN Writing variable 'creditCheckPLRequest' value ' 969696 ns:str_CardType ' 15:46:16,609 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLRequest:OMessageVarType#18({http://checkCredit.apache.org}validateCreditCardRequest)} value= 969696 ns:str_CardType 15:46:16,611 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLRequest:OMessageVarType#18({http://checkCredit.apache.org}validateCreditCardRequest)}.parameters{OXPath10Expression ns:str_CardType}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:cardType}}}) 15:46:16,611 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:cardType}}". 15:46:16,613 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,613 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,613 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,613 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,613 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,614 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,614 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:16,614 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:16,614 DEBUG [ASSIGN] content 969696 ns:str_CardType 15:46:16,614 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns)=http://checkCredit.apache.org 15:46:16,614 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns)=http://checkCredit.apache.org 15:46:16,615 DEBUG [ASSIGN] ASSIGN Writing variable 'creditCheckPLRequest' value ' 969696 kjgkjg ' 15:46:16,615 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLRequest:OMessageVarType#18({http://checkCredit.apache.org}validateCreditCardRequest)} value= 969696 kjgkjg 15:46:16,625 DEBUG [BpelProcess] INVOKING PARTNER: partnerLink={PartnerLinkInstance partnerLinkDecl=OPartnerLink#29,scopeInstanceId=17001}, op=validateCreditCard channel=InvokeResponseChannel#20) 15:46:16,626 DEBUG [BpelRuntimeContextImpl] INVOKE PARTNER (SEP): sessionId=null partnerSessionId=null 15:46:16,626 DEBUG [MessageDAOImpl] setData null 969696 kjgkjg 15:46:16,628 DEBUG [MessageExchangeImpl] SET MEX property activityId = 51 15:46:16,628 DEBUG [BpelEngineImpl] Routed: svcQname {http://checkCredit.apache.org}CreditCardService --> null 15:46:16,629 DEBUG [BpelRuntimeContextImpl] Creating invocation check event in 120000ms for mexid hqejbhcnphr6lhnqqfop91 15:46:16,629 DEBUG [SimpleScheduler] scheduling JobDetails( instanceId: null mexId: hqejbhcnphr6lhnqqfop91 processId: {org.booking.travel}travelBookingProcess-25 type: INVOKE_CHECK channel: null correlatorId: null correlationKeySet: null retryCount: null inMem: false detailsExt: {}) for Thu Sep 15 15:48:16 EST 2011 15:46:16,629 DEBUG [JdbcDelegate] insertJob hqejbhcnphr6lhnqqfop92 on node hqejbhcnphr6lhnqqfop8u loaded=false 15:46:16,630 DEBUG [SimpleScheduler] scheduled near-future job: hqejbhcnphr6lhnqqfop92 15:46:16,630 DEBUG [MessageExchangeImpl] SET MEX property invokeCheckJobId = hqejbhcnphr6lhnqqfop92 15:46:16,630 DEBUG [MessageExchangeContextImpl] Invoking a partner operation: validateCreditCard 15:46:16,630 DEBUG [MessageExchangeContextImpl] The service to invoke is the external service {http://checkCredit.apache.org}CreditCardService:CreditCardServiceHttpSoap11Endpoint 15:46:16,631 DEBUG [WatchDog] [C:\Apache2\apache-tomcat-6.0.32\webapps\ode\WEB-INF\processes\travelBooking\CreditCardService.axis2] check for changes 15:46:16,637 INFO [WatchDog] [C:\Apache2\apache-tomcat-6.0.32\webapps\ode\WEB-INF\processes\travelBooking\CreditCardService.axis2] initialized 15:46:16,637 DEBUG [WatchDog] [Properties for Endpoint: {http://checkCredit.apache.org}CreditCardService#CreditCardServiceHttpSoap11Endpoint] check for changes 15:46:16,637 DEBUG [Properties] Translating Properties for Axis2 15:46:16,637 INFO [WatchDog] [Properties for Endpoint: {http://checkCredit.apache.org}CreditCardService#CreditCardServiceHttpSoap11Endpoint] updated 15:46:16,638 DEBUG [ExternalService] Create a new ServiceClient for axis_service_for_{http://checkCredit.apache.org}CreditCardService#CreditCardServiceHttpSoap11Endpoint_hqejbhcnphr6lhnqqfop93 15:46:16,640 DEBUG [EndpointReferenceContextImpl] Resolving endpoint reference servicens:CreditCardServicehttp://localhost:8080/axis2/services/CreditCardService.CreditCardServiceHttpSoap11Endpoint/ 15:46:16,640 DEBUG [MessageExchangeImpl] GET MEX property org.apache.ode.bpel.partnerRoleSessionId = null 15:46:16,640 DEBUG [MessageExchangeImpl] GET MEX property org.apache.ode.bpel.myRoleSessionId = null 15:46:16,640 DEBUG [ExternalService] My-Role EPR not specified, SEP will not be used. 15:46:16,641 DEBUG [MessageDAOImpl] getData null 969696 kjgkjg 15:46:16,642 DEBUG [ClusterUrlTransformer] targets: [] base: http://localhost:8080/ode/processes/ 15:46:16,642 DEBUG [ClusterUrlTransformer] rewrite: http://localhost:8080/axis2/services/CreditCardService.CreditCardServiceHttpSoap11Endpoint/ to http://localhost:8080/axis2/services/CreditCardService.CreditCardServiceHttpSoap11Endpoint/ 15:46:16,642 DEBUG [ExternalService] Axis2 sending message to http://localhost:8080/axis2/services/CreditCardService.CreditCardServiceHttpSoap11Endpoint/ using MEX {PartnerRoleMex#hqejbhcnphr6lhnqqfop91 [PID {org.booking.travel}travelBookingProcess-25] calling [email protected](...) Status REQUEST} 15:46:16,643 DEBUG [ExternalService] Message: 969696 kjgkjg 15:46:16,647 DEBUG [MessageDAOImpl] getData null 969696 kjgkjg 15:46:16,648 DEBUG [PartnerRoleMessageExchangeImpl] replyAsync mex=hqejbhcnphr6lhnqqfop91 15:46:16,652 DEBUG [BpelRuntimeContextImpl] Setting execution state on instance 16951 15:46:16,671 DEBUG [ExecutionQueueImpl] ReplacmentMap: getReplacement({OScope '__PROCESS_SCOPE:travelBookingProcess' id=3}) = org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@17dbeaf 15:46:16,678 DEBUG [ExecutionQueueImpl] ReplacmentMap: getReplacement(OSequence#31-main) = org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@1c82208 15:46:16,681 DEBUG [ExecutionQueueImpl] ReplacmentMap: getReplacement(OProcess#0) = org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@1546c85 15:46:16,683 DEBUG [ExecutionQueueImpl] ReplacmentMap: getReplacement({OScope 'invokeCreditValidator' id=50}) = org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@67ad79 15:46:16,687 DEBUG [ExecutionQueueImpl] ReplacmentMap: getReplacement(OSwitch#57-If) = org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@1dd8136 15:46:16,692 DEBUG [ExecutionQueueImpl] ReplacmentMap: getReplacement(OInvoke#51-invokeCreditValidator) = org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@9de959 15:46:16,696 DEBUG [ExecutionQueueImpl] ReplacmentMap: getReplacement({Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLResponse:OMessageVarType#14({http://checkCredit.apache.org}validateCreditCardResponse)}) = org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@635421 15:46:16,698 DEBUG [ExecutionQueueImpl] GC Channel: {CFRAME TerminationChannel:null#6 refCount=0, msgs=0, objs=0} 15:46:16,698 DEBUG [ExecutionQueueImpl] GC Channel: {CFRAME ParentScopeChannel:null#7 refCount=0, msgs=0, objs=0} 15:46:16,698 DEBUG [ExecutionQueueImpl] GC Channel: {CFRAME ParentScopeChannel:null#8 refCount=0, msgs=0, objs=0} 15:46:16,698 DEBUG [ExecutionQueueImpl] GC Channel: {CFRAME ParentScopeChannel:null#10 refCount=0, msgs=0, objs=0} 15:46:16,698 DEBUG [ExecutionQueueImpl] GC Channel: {CFRAME TerminationChannel:null#11 refCount=0, msgs=0, objs=0} 15:46:16,698 DEBUG [ExecutionQueueImpl] GC Channel: {CFRAME ParentScopeChannel:null#12 refCount=0, msgs=0, objs=0} 15:46:16,698 DEBUG [ExecutionQueueImpl] GC Channel: {CFRAME ParentScopeChannel:null#13 refCount=0, msgs=0, objs=0} 15:46:16,698 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME TerminationChannel:null#1 refCount=0, msgs=0, objs=1} 15:46:16,698 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME ParentScopeChannel:null#2 refCount=0, msgs=0, objs=1} 15:46:16,698 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME TerminationChannel:null#3 refCount=0, msgs=0, objs=1} 15:46:16,698 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME ParentScopeChannel:null#4 refCount=0, msgs=0, objs=1} 15:46:16,698 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME ParentScopeChannel:null#5 refCount=0, msgs=0, objs=1} 15:46:16,699 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME PickResponseChannel:null#9 refCount=1, msgs=0, objs=0} 15:46:16,699 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME TerminationChannel:null#14 refCount=0, msgs=0, objs=1} 15:46:16,700 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME ParentScopeChannel:null#15 refCount=0, msgs=0, objs=1} 15:46:16,700 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME TerminationChannel:null#17 refCount=0, msgs=0, objs=1} 15:46:16,700 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME ParentScopeChannel:null#16 refCount=0, msgs=0, objs=1} 15:46:16,700 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME ParentScopeChannel:null#19 refCount=0, msgs=0, objs=1} 15:46:16,700 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME ParentScopeChannel:null#18 refCount=0, msgs=0, objs=1} 15:46:16,700 DEBUG [ExecutionQueueImpl] Writing Channel: {CFRAME InvokeResponseChannel:null#20 refCount=1, msgs=0, objs=1} 15:46:16,703 DEBUG [ExecutionQueueImpl] ReplacmentMap: getReplacement(OPartnerLink#28) = org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@a42c89 15:46:16,703 DEBUG [SimpleScheduler] Commiting on org.apache.geronimo.transaction.manager.GeronimoTransactionManager@5afcb1... 15:46:17,066 DEBUG [SessionOutHandler] Sending stateful TO epr in message header using session null 15:46:17,066 DEBUG [SessionOutHandler] Sending a message containing wsa endpoints in headers for session passing. 15:46:17,067 DEBUG [SessionOutHandler] http://localhost:8080/axis2/services/CreditCardService.CreditCardServiceHttpSoap11Endpoint/urn:validateCreditCardhttp://www.w3.org/2005/08/addressing/anonymousuuid:hqejbhcnphr6lhnqqfop94 969696 kjgkjg 15:46:17,195 DEBUG [SessionInHandler] Found a header in incoming message, checking if there are endpoints there. 15:46:17,195 DEBUG [ExternalService] Service response: urn:validateCreditCardResponseuuid:hqejbhcnphr6lhnqqfop94PASS 15:46:17,197 DEBUG [SimpleScheduler] Beginning a new transaction 15:46:17,206 DEBUG [ExternalService] Received response for MEX {PartnerRoleMex#hqejbhcnphr6lhnqqfop91 [PID {org.booking.travel}travelBookingProcess-25] calling null.validateCreditCard(...) Status ASYNC} 15:46:17,208 DEBUG [MessageDAOImpl] getData null null 15:46:17,209 DEBUG [MessageDAOImpl] setData null PASS 15:46:17,210 DEBUG [MessageDAOImpl] getData null PASS 15:46:17,210 DEBUG [MessageDAOImpl] getData null PASS 15:46:17,210 INFO [ExternalService] Response: PASS 15:46:17,210 DEBUG [PartnerRoleMessageExchangeImpl] reply mex=hqejbhcnphr6lhnqqfop91 15:46:17,211 DEBUG [PartnerRoleMessageExchangeImpl] create work event for mex=hqejbhcnphr6lhnqqfop91 15:46:17,222 DEBUG [SimpleScheduler] scheduling JobDetails( instanceId: 16951 mexId: hqejbhcnphr6lhnqqfop91 processId: null type: INVOKE_RESPONSE channel: 20 correlatorId: null correlationKeySet: null retryCount: null inMem: false detailsExt: {}) for Thu Sep 15 15:46:17 EST 2011 15:46:17,222 DEBUG [JdbcDelegate] insertJob hqejbhcnphr6lhnqqfop95 on node hqejbhcnphr6lhnqqfop8u loaded=true 15:46:17,223 DEBUG [SimpleScheduler] scheduled immediate job: hqejbhcnphr6lhnqqfop95 15:46:17,223 DEBUG [SimpleScheduler] Commiting on org.apache.geronimo.transaction.manager.GeronimoTransactionManager@5afcb1... 15:46:17,237 DEBUG [SimpleScheduler] Beginning a new transaction 15:46:17,238 DEBUG [JdbcDelegate] deleteJob hqejbhcnphr6lhnqqfop95 on node hqejbhcnphr6lhnqqfop8u 15:46:17,240 DEBUG [InstanceLockManager] Thread[ODEServer-1,5,main]: lock(iid=16951, time=1MICROSECONDS) 15:46:17,241 DEBUG [InstanceLockManager] Thread[ODEServer-1,5,main]: lock(iid=16951, time=1MICROSECONDS)-->GRANTED 15:46:17,245 DEBUG [BpelProcess] >> handleJobDetails(jobData=JobDetails( instanceId: 16951 mexId: hqejbhcnphr6lhnqqfop91 processId: null type: INVOKE_RESPONSE channel: 20 correlatorId: null correlationKeySet: null retryCount: null inMem: false detailsExt: {})) 15:46:17,251 DEBUG [ExecutionQueueImpl] ReplacementMap: getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@190690e) = {OScope '__PROCESS_SCOPE:travelBookingProcess' id=3} 15:46:17,252 DEBUG [ExecutionQueueImpl] ReplacementMap: getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@193229) = OSequence#31-main 15:46:17,254 DEBUG [ExecutionQueueImpl] ReplacementMap: getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@13cf887) = null 15:46:17,255 DEBUG [ExecutionQueueImpl] ReplacementMap: getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@1dbe1c9) = {OScope 'invokeCreditValidator' id=50} 15:46:17,256 DEBUG [ExecutionQueueImpl] ReplacementMap: getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@d18a80) = OSwitch#57-If 15:46:17,257 DEBUG [ExecutionQueueImpl] ReplacementMap: getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@167e003) = OInvoke#51-invokeCreditValidator 15:46:17,258 DEBUG [ExecutionQueueImpl] ReplacementMap: getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@1ca73bf) = {Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLResponse:OMessageVarType#14({http://checkCredit.apache.org}validateCreditCardResponse)} 15:46:17,259 DEBUG [ExecutionQueueImpl] ReplacementMap: getOriginal(org.apache.ode.bpel.engine.ReplacementMapImpl$OBaseReplacementImpl@6076f4) = OPartnerLink#28 15:46:17,261 DEBUG [BpelRuntimeContextImpl] BpelRuntimeContextImpl created for instance 16951. INDEXED STATE={OInvoke#51-invokeCreditValidator::12=[INVOKE(...)], {OScope '__PROCESS_SCOPE:travelBookingProcess' id=3}::0=[ACTIVE(...)], OInvoke#51-invokeCreditValidator::11=[ACTIVITYGUARD(...)], {OScope 'invokeCreditValidator' id=50}::9=[ACTIVITYGUARD(...)], OSequence#31-main::1=[ACTIVITYGUARD(...)], {OScope '__PROCESS_SCOPE:travelBookingProcess' id=3}::0=[SCOPE(...)], {OScope 'invokeCreditValidator' id=50}::10=[ACTIVE(...)], {OScope 'invokeCreditValidator' id=50}::10=[SCOPE(...)], OSequence#31-main::2=[SEQUENCE(self=(OSequence#31-main,TerminationChannel#3,ParentScopeChannel#5), linkframe=org.apache.ode.bpel.runtime.LinkFrame@c6c084, remaining=[{OScope 'invokeCreditValidator' id=50}, OSwitch#57-If])]} 15:46:17,262 DEBUG [BpelProcess] InvokeResponse event for iid 16951 15:46:17,262 DEBUG [BpelRuntimeContextImpl] Invoking message response for mexid hqejbhcnphr6lhnqqfop91 and channel 20 15:46:17,262 DEBUG [JacobVPU] injecting (...) 15:46:17,262 DEBUG [BpelRuntimeContextImpl] Triggering response 15:46:17,267 DEBUG [MessageDAOImpl] getData 16903 PASS 15:46:17,268 DEBUG [ScopeFrame] Initialize variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.creditCheckPLResponse:OMessageVarType#14({http://checkCredit.apache.org}validateCreditCardResponse)} value= PASSurn:validateCreditCardResponseuuid:hqejbhcnphr6lhnqqfop94 15:46:17,326 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri()=null 15:46:17,329 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns)=http://checkCredit.apache.org 15:46:17,332 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)}.parameters}={Literal ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival ns:str_CardNo ns:str_CardType }}) 15:46:17,332 DEBUG [ASSIGN] Evaluating FROM expression "{Literal ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival ns:str_CardNo ns:str_CardType }". 15:46:17,333 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:17,333 DEBUG [ASSIGN] content 15:46:17,333 DEBUG [ASSIGN] ASSIGN Writing variable 'flightBookingPLRequest' value ' ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival ns:str_CardNo ns:str_CardType ' 15:46:17,333 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)} value= ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival ns:str_CardNo ns:str_CardType 15:46:17,336 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)}.parameters{OXPath10Expression ns0:str_CardNo}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:cardNumber}}}) 15:46:17,336 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:cardNumber}}". 15:46:17,337 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,338 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,338 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,338 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,338 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,338 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,338 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,338 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:17,339 DEBUG [ASSIGN] content ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival ns:str_CardNo ns:str_CardType 15:46:17,339 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,339 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,339 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,339 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,339 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,339 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,339 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,340 DEBUG [ASSIGN] ASSIGN Writing variable 'flightBookingPLRequest' value ' ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 ns:str_CardType ' 15:46:17,341 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)} value= ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 ns:str_CardType 15:46:17,341 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)}.parameters{OXPath10Expression ns0:str_CardType}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:cardType}}}) 15:46:17,342 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:cardType}}". 15:46:17,343 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,343 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,343 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,343 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,343 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,343 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,343 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,343 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:17,343 DEBUG [ASSIGN] content ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 ns:str_CardType 15:46:17,344 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,344 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,344 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,344 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,344 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,344 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,344 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,349 DEBUG [ASSIGN] ASSIGN Writing variable 'flightBookingPLRequest' value ' ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg ' 15:46:17,351 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)} value= ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg 15:46:17,352 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)}.parameters{OXPath10Expression ns0:str_AirLine}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:airline}}}) 15:46:17,352 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:airline}}". 15:46:17,353 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,353 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,353 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,353 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,353 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,353 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,354 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,354 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:17,354 DEBUG [ASSIGN] content ns:str_AirLine ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg 15:46:17,354 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,354 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,354 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,354 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,355 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,355 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,355 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,355 DEBUG [ASSIGN] ASSIGN Writing variable 'flightBookingPLRequest' value ' kgkjg ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg ' 15:46:17,356 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)} value= kgkjg ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg 15:46:17,358 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)}.parameters{OXPath10Expression ns0:str_Source}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:source}}}) 15:46:17,358 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:source}}". 15:46:17,358 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,359 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,359 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,359 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,359 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,359 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,359 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,359 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:17,360 DEBUG [ASSIGN] content kgkjg ns:str_Source ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg 15:46:17,360 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,360 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,360 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,360 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,360 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,360 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,360 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,361 DEBUG [ASSIGN] ASSIGN Writing variable 'flightBookingPLRequest' value ' kgkjg kgjk ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg ' 15:46:17,361 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)} value= kgkjg kgjk ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg 15:46:17,362 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)}.parameters{OXPath10Expression ns0:str_Target}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:target}}}) 15:46:17,362 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:target}}". 15:46:17,363 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,363 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,363 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,363 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,363 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,363 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,363 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,363 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:17,364 DEBUG [ASSIGN] content kgkjg kgjk ns:str_Target ns:str_Depart ns:Arrival 969696 kjgkjg 15:46:17,364 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,364 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,364 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,364 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,364 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,364 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,364 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,364 DEBUG [ASSIGN] ASSIGN Writing variable 'flightBookingPLRequest' value ' kgkjg kgjk kjgk ns:str_Depart ns:Arrival 969696 kjgkjg ' 15:46:17,365 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)} value= kgkjg kgjk kjgk ns:str_Depart ns:Arrival 969696 kjgkjg 15:46:17,366 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)}.parameters{OXPath10Expression ns0:str_Depart}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:depart}}}) 15:46:17,366 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:depart}}". 15:46:17,367 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,367 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,367 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,367 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,367 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,367 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,367 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,368 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:17,368 DEBUG [ASSIGN] content kgkjg kgjk kjgk ns:str_Depart ns:Arrival 969696 kjgkjg 15:46:17,368 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,368 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,368 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,368 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,368 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,368 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,369 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,369 DEBUG [ASSIGN] ASSIGN Writing variable 'flightBookingPLRequest' value ' kgkjg kgjk kjgk kjgk ns:Arrival 969696 kjgkjg ' 15:46:17,369 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)} value= kgkjg kgjk kjgk kjgk ns:Arrival 969696 kjgkjg 15:46:17,370 DEBUG [ASSIGN] Assign.copy({OCopy {VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)}.parameters{OXPath10Expression ns0:Arrival}}={VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:arrival}}}) 15:46:17,370 DEBUG [ASSIGN] Evaluating FROM expression "{VarRef {Variable __PROCESS_SCOPE:travelBookingProcess.input:OMessageVarType#6({org.booking.travel}travelBookingProcessRequestMessage)}.payload{OXPath10Expression tns:arrival}}". 15:46:17,371 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,371 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,371 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,371 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,371 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,371 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,371 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(tns)=org.booking.travel 15:46:17,372 DEBUG [ASSIGN] lvalue after eval [message: null] 15:46:17,372 DEBUG [ASSIGN] content kgkjg kgjk kjgk kjgk ns:Arrival 969696 kjgkjg 15:46:17,372 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,372 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,372 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,372 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,372 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,372 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,372 DEBUG [JaxenNamespaceContextAdapter] translateNamespacePrefixToUri(ns0)=http://flight.apache.org 15:46:17,373 DEBUG [ASSIGN] ASSIGN Writing variable 'flightBookingPLRequest' value ' kgkjg kgjk kjgk kjgk kjg 969696 kjgkjg ' 15:46:17,373 DEBUG [ScopeFrame] Write variable: name={Variable __PROCESS_SCOPE:travelBookingProcess.flightBookingPLRequest:OMessageVarType#26({http://flight.apache.org}bookFlightRequest)} value= kgkjg kgjk kjgk kjgk kjg 969696 kjgkjg 15:46:17,386 ERROR [INVOKE] org.apache.ode.bpel.common.FaultException: {http://docs.oasis-open.org/wsbpel/2.0/process/executable}uninitializedPartnerRole 15:46:17,388 DEBUG [SCOPE] ({OScope 'invokeFlightBooking' id=99},TerminationChannel#29,ParentScopeChannel#31): has no fault handler for {http://docs.oasis-open.org/wsbpel/2.0/process/executable}uninitializedPartnerRole; scope will propagate FAULT! 15:46:17,393 DEBUG [SCOPE] ({OScope '__PROCESS_SCOPE:travelBookingProcess' id=3},TerminationChannel#1,ParentScopeChannel#2): has a fault handler for {http://docs.oasis-open.org/wsbpel/2.0/process/executable}uninitializedPartnerRole: {OCatch faultName=null, faultVariable=null} 15:46:17,412 DEBUG [SCOPE] ({OCatch faultName=null, faultVariable=null},TerminationChannel:FH#36,ParentScopeChannel:FH#37): has no fault handler for {http://docs.oasis-open.org/wsbpel/2.0/process/executable}uninitializedPartnerRole; scope will propagate FAULT! 15:46:17,413 DEBUG [BpelProcess] ProcessImpl completed with fault '{http://docs.oasis-open.org/wsbpel/2.0/process/executable}uninitializedPartnerRole' 15:46:17,418 DEBUG [MessageExchangeContextImpl] Processing an async reply from service {org.booking.travel}travelBookingProcess 15:46:17,419 DEBUG [SimpleScheduler] Commiting on org.apache.geronimo.transaction.manager.GeronimoTransactionManager@5afcb1... 15:46:17,571 DEBUG [ProcessInstanceDAOImpl] Cleaning up instance Data with [] 15:46:17,614 DEBUG [InstanceLockManager] Thread[ODEServer-1,5,main]: unlock(iid=16951) 15:46:17,620 DEBUG [MyRoleMessageExchangeImpl] Received myrole mex response callback 15:46:17,620 DEBUG [ODEService] Handling response for MEX {MyRoleMex#hqejbhcnphr6lhnqqfop8w [Client hqejbhcnphr6lhnqqfop8v] calling {org.booking.travel}travelBookingProcess.process(...)} 15:46:17,620 DEBUG [MyRoleMessageExchangeImpl] Received myrole mex response callback 15:46:17,620 DEBUG [ODEService] Starting transaction. 15:46:17,631 DEBUG [ODEService] Fault response message: {http://docs.oasis-open.org/wsbpel/2.0/process/executable}uninitializedPartnerRole 15:46:17,633 DEBUG [MessageDAOImpl] getData 16904 null 15:46:17,644 DEBUG [ODEService] Returning fault: soapenv:Serveraxis2ns37:uninitializedPartnerRole 15:46:17,644 DEBUG [MyRoleMessageExchangeImpl] Releasing mex hqejbhcnphr6lhnqqfop8w 15:46:17,644 DEBUG [ODEService] Comitting transaction. 15:46:17,645 DEBUG [ODEMessageReceiver] Reply for travelBookingProcess.{org.booking.travel}process 15:46:17,646 DEBUG [ODEMessageReceiver] Reply message soapenv:Serveraxis2ns37:uninitializedPartnerRole Can you let me know what I am doing wrong?
