You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@ode.apache.org by Mark Bullathsinghalage Cooray <mb...@groupwise.swin.edu.au> on 2011/09/15 08:00:16 UTC
axis2ns37:uninitializedPartnerRole
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 org.apache.ode.bpel.epr.WSAEndpoint@1a40fff.validateCreditCard(...) 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?
Re: axis2ns37:uninitializedPartnerRole
Posted by Mark Bullathsinghalage Cooray <mb...@groupwise.swin.edu.au>.
Thanks...
>>> Waruna Ranasinghe <wa...@gmail.com> 15/09/2011 10:52 PM >>>
The fault string means that you havnt update the deploy.xml for the new
invoke.
Thnx,
waruna
On Sep 15, 2011 11:31 AM, "Mark Bullathsinghalage Cooray" <
mbcooray@groupwise.swin.edu.au> wrote:
> 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/" ( '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" ( '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
org.apache.ode.bpel.epr.WSAEndpoint@1a40fff.validateCreditCard(...) 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?
>
>
>
Re: axis2ns37:uninitializedPartnerRole
Posted by Waruna Ranasinghe <wa...@gmail.com>.
The fault string means that you havnt update the deploy.xml for the new
invoke.
Thnx,
waruna
On Sep 15, 2011 11:31 AM, "Mark Bullathsinghalage Cooray" <
mbcooray@groupwise.swin.edu.au> wrote:
> 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
org.apache.ode.bpel.epr.WSAEndpoint@1a40fff.validateCreditCard(...) 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?
>
>
>