ode-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Alex Boisvert" <boisv...@intalio.com>
Subject Re: Invoke - with communication error
Date Mon, 10 Sep 2007 22:04:56 GMT
You're most likely getting some sort of failure from the service you're
invoking, and Axis2 has a hard time parsing the resulting fault message.   I
would recommend setting the "httpclient" log category to DEBUG to see what's
going on the wire.

alex


On 9/10/07, Anup Chandran <anup.chandran@3ds.com> wrote:
>
>
> Alex/Matthieu,
>
> I know this is pretty silly but cant figure what is the issue here...... I
> have a runtime error with the following trace..... If i remove the invoke.
> from BPEL.. the process runs without errors. Can you tell me what is going
> on from the trace? Thanks...
>
> DEBUG - GeronimoLog.debug(66) | InvokeResponse event for iid 1057
> 17:40:22,965 DEBUG [BpelProcess] InvokeResponse event for iid 1057
> DEBUG - GeronimoLog.debug(66) | Invoking message response for mexid
> hqejbhcnphr2kte2v4jbl5 and channel 40
> 17:40:22,965 DEBUG [BpelRuntimeContextImpl] Invoking message response for
> mexid hqejbhcnphr2kte2v4jbl5 and channel 40
> DEBUG - GeronimoLog.debug(66) | Triggering response
> 17:40:22,965 DEBUG [BpelRuntimeContextImpl] Triggering response
> DEBUG - GeronimoLog.trace(54) | >>
> createScopeInstance(parentScopeId=1059,scope={OScope 'UpdateCBPWorkflow'
> id=144})
> 17:40:23,255 DEBUG [BpelProcess] >>
> createScopeInstance(parentScopeId=1059,scope={OScope 'UpdateCBPWorkflow'
> id=144})
> DEBUG - GeronimoLog.trace(54) | >>
> initializeEndpointReferences(parentScopeId=1125,partnerLinks=[])
> 17:40:23,506 DEBUG [BpelProcess] >>
> initializeEndpointReferences(parentScopeId=1125,partnerLinks=[])
> DEBUG - GeronimoLog.debug(66) | INVOKING PARTNER:
> partnerLink={PartnerLinkInstance partnerLinkDecl=OPartnerLink#44,scope
> InstanceId=1058}, op=setAttribute channel=InvokeResponseChannel#54)
> 17:40:23,526 DEBUG [BpelProcess] INVOKING PARTNER:
> partnerLink={PartnerLinkInstance partnerLinkDecl=OPartnerLink#44,scop
> eInstanceId=1058}, op=setAttribute channel=InvokeResponseChannel#54)
> DEBUG - GeronimoLog.debug(66) | INVOKE PARTNER (SEP): sessionId=null
> partnerSessionId=null
> 17:40:23,526 DEBUG [BpelRuntimeContextImpl] INVOKE PARTNER (SEP):
> sessionId=null partnerSessionId=null
> DEBUG - GeronimoLog.trace(54) | Mex[hqejbhcnphr2kte2v4jbl8].setPortOp(...)
> 17:40:23,526 DEBUG [MessageExchangeImpl]
> Mex[hqejbhcnphr2kte2v4jbl8].setPortOp(...)
> DEBUG - GeronimoLog.debug(66) | Routed: svcQname
> {http://client.engineering.cbp.jpo}CBPWorkflowService --> null
> 17:40:23,526 DEBUG [BpelEngineImpl] Routed: svcQname
> {http://client.engineering.cbp.jpo}CBPWorkflowService --> null
> DEBUG - GeronimoLog.debug(66) | Invoking a partner operation: setAttribute
> 17:40:23,526 DEBUG [MessageExchangeContextImpl] Invoking a partner
> operation: setAttribute
> DEBUG - GeronimoLog.debug(66) | The service to invoke is the external
> service org.apache.ode.axis2.ExternalService@1858f
> 02
> 17:40:23,536 DEBUG [MessageExchangeContextImpl] The service to invoke is
> the
> external service org.apache.ode.axis2.Exter
> nalService@1858f02
> DEBUG - GeronimoLog.debug(66) | Resolving endpoint reference <?xml
> version="1.0" encoding="UTF-8"?>
> <service-ref
> xmlns="http://docs.oasis-open.org/wsbpel/2.0/serviceref
> "><EndpointReference
> xmlns="http://www.w3.org/2005/0
> 8/addressing"><Metadata><ServiceName
> xmlns="http://www.w3.org/2006/05/addressing/wsdl"
> EndpointName="JpoCbpEngineeringCB
> PWorkflow"
> xmlns:servicens="http://client.engineering.cbp.jpo
> ">servicens:CBPWorkflowService</ServiceName></Metadata><Add
> ress>http://localhost:8080/ematrix/services/JpoCbpEngineeringCBPWorkflow
> </Address></EndpointReference></service-ref>
> 17:40:23,536 DEBUG [EndpointReferenceContextImpl] Resolving endpoint
> reference <?xml version="1.0" encoding="UTF-8"?>
> <service-ref
> xmlns="http://docs.oasis-open.org/wsbpel/2.0/serviceref
> "><EndpointReference
> xmlns="http://www.w3.org/2005/0
> 8/addressing"><Metadata><ServiceName
> xmlns="http://www.w3.org/2006/05/addressing/wsdl"
> EndpointName="JpoCbpEngineeringCB
> PWorkflow"
> xmlns:servicens="http://client.engineering.cbp.jpo
> ">servicens:CBPWorkflowService</ServiceName></Metadata><Add
> ress>http://localhost:8080/ematrix/services/JpoCbpEngineeringCBPWorkflow
> </Address></EndpointReference></service-ref>
> DEBUG - GeronimoLog.debug(66) | GET MEX property
> org.apache.ode.bpel.partnerRoleSessionId = null
> 17:40:23,536 DEBUG [MessageExchangeImpl] GET MEX property
> org.apache.ode.bpel.partnerRoleSessionId = null
> DEBUG - GeronimoLog.debug(66) | GET MEX property
> org.apache.ode.bpel.myRoleSessionId = null
> 17:40:23,536 DEBUG [MessageExchangeImpl] GET MEX property
> org.apache.ode.bpel.myRoleSessionId = null
> DEBUG - GeronimoLog.debug(66) | My-Role EPR not specified, SEP will not be
> used.
> 17:40:23,536 DEBUG [ExternalService] My-Role EPR not specified, SEP will
> not
> be used.
> DEBUG - GeronimoLog.debug(66) | Axis2 sending message to
> http://localhost:8080/ematrix/services/JpoCbpEngineeringCBPWork
> flow using MEX {PartnerRoleMex#hqejbhcnphr2kte2v4jbl8 [PID
> {http://eclipse.org/bpel/sample}ECRProcess-9] calling org.apa
> che.ode.bpel.epr.WSAEndpoint@16fd757.setAttribute(...)}
> 17:40:23,536 DEBUG [ExternalService] Axis2 sending message to
> http://localhost:8080/ematrix/services/JpoCbpEngineeringCB
> PWorkflow using MEX {PartnerRoleMex#hqejbhcnphr2kte2v4jbl8 [PID
> {http://eclipse.org/bpel/sample}ECRProcess-9] calling or
> g.apache.ode.bpel.epr.WSAEndpoint@16fd757.setAttribute(...)}
> DEBUG - GeronimoLog.debug(66) | Message: <?xml version='1.0'
> encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://s
> chemas.xmlsoap.org/soap/envelope/"><soapenv:Body><axis2ns16:setAttribute
> xmlns:axis2ns16="http://engineering.cbp.jpo" xm
> lns:tns1="http://engineering.cbp.jpo">
>                    <axis2ns16:in2
> xmlns:ns="http://www.apache.org/ode/pmapi/types/2006/08/02/"
> xmlns="http://www.apache.
> org/ode/pmapi/types/2006/08/02/">1057</axis2ns16:in2>
>
>                 </axis2ns16:setAttribute></soapenv:Body></soapenv:Envelope>
> 17:40:23,536 DEBUG [ExternalService] Message: <?xml version='1.0'
> encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="htt
>
> p://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><axis2ns16:setAttribute
> xmlns:axis2ns16="http://engineering.cbp.jp
> o" xmlns:tns1="http://engineering.cbp.jpo">
>                    <axis2ns16:in2
> xmlns:ns="http://www.apache.org/ode/pmapi/types/2006/08/02/"
> xmlns="http://www.apache.
> org/ode/pmapi/types/2006/08/02/">1057</axis2ns16:in2>
>
>                 </axis2ns16:setAttribute></soapenv:Body></soapenv:Envelope>
> DEBUG - GeronimoLog.debug(66) | replyAsync mex=hqejbhcnphr2kte2v4jbl8
> 17:40:23,536 DEBUG [PartnerRoleMessageExchangeImpl] replyAsync
> mex=hqejbhcnphr2kte2v4jbl8
> DEBUG - GeronimoLog.debug(66) | Setting execution state on instance 1057
> 17:40:23,546 DEBUG [BpelRuntimeContextImpl] Setting execution state on
> instance 1057
> DEBUG - GeronimoLog.debug(66) | Thread[pool-2-thread-9,5,main]:
> unlock(iid=1057)
> 17:40:23,707 DEBUG [InstanceLockManager] Thread[pool-2-thread-9,5,main]:
> unlock(iid=1057)
> DEBUG - GeronimoLog.debug(66) | Sending stateful TO epr in message header
> using session null
> 17:40:23,717 DEBUG [SessionOutHandler] Sending stateful TO epr in message
> header using session null
> DEBUG - GeronimoLog.debug(66) | Sending a message containing wsa endpoints
> in headers for session passing.
> 17:40:23,717 DEBUG [SessionOutHandler] Sending a message containing wsa
> endpoints in headers for session passing.
> DEBUG - GeronimoLog.debug(66) | <?xml version='1.0'
> encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xm
> lsoap.org/soap/envelope/"><soapenv:Header><addr:To
> xmlns:addr="http://www.w3.org/2005/08/addressing">http://localhost:80
> 80/ematrix/services/JpoCbpEngineeringCBPWorkflow</addr:To><addr:Action
> xmlns:addr="http://www.w3.org/2005/08/addressing"
> ></addr:Action><addr:ReplyTo
> xmlns:addr="http://www.w3.org/2005/08/addressing"><addr:Address>
> http://www.w3.org/2005/08/a
> ddressing/anonymous</addr:Address></addr:ReplyTo><addr:MessageID
> xmlns:addr="http://www.w3.org/2005/08/addressing">uuid:
>
> hqejbhcnphr2kte2v4jbl9</addr:MessageID></soapenv:Header><soapenv:Body><axis2ns16:setAttribute
> xmlns:axis2ns16="http://en
> gineering.cbp.jpo" xmlns:tns1="http://engineering.cbp.jpo">
>                    <axis2ns16:in2
> xmlns:ns="http://www.apache.org/ode/pmapi/types/2006/08/02/"
> xmlns="http://www.apache.
> org/ode/pmapi/types/2006/08/02/">1057</axis2ns16:in2>
>
>                 </axis2ns16:setAttribute></soapenv:Body></soapenv:Envelope>
> 17:40:23,717 DEBUG [SessionOutHandler] <?xml version='1.0'
> encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://sch
> emas.xmlsoap.org/soap/envelope/"><soapenv:Header><addr:To
> xmlns:addr="http://www.w3.org/2005/08/addressing">http://local
>
> host:8080/ematrix/services/JpoCbpEngineeringCBPWorkflow</addr:To><addr:Action
> xmlns:addr="http://www.w3.org/2005/08/addr
> essing"></addr:Action><addr:ReplyTo
> xmlns:addr="http://www.w3.org/2005/08/addressing"><addr:Address>
> http://www.w3.org/20
> 05/08/addressing/anonymous</addr:Address></addr:ReplyTo><addr:MessageID
> xmlns:addr="http://www.w3.org/2005/08/addressing
>
> ">uuid:hqejbhcnphr2kte2v4jbl9</addr:MessageID></soapenv:Header><soapenv:Body><axis2ns16:setAttribute
> xmlns:axis2ns16="ht
> tp://engineering.cbp.jpo" xmlns:tns1="http://engineering.cbp.jpo">
>                    <axis2ns16:in2
> xmlns:ns="http://www.apache.org/ode/pmapi/types/2006/08/02/"
> xmlns="http://www.apache.
> org/ode/pmapi/types/2006/08/02/">1057</axis2ns16:in2>
>
>                 </axis2ns16:setAttribute></soapenv:Body></soapenv:Envelope>
> ERROR - GeronimoLog.error(108) | Error sending message
> (mex={PartnerRoleMex#hqejbhcnphr2kte2v4jbl8 [PID {http://eclipse.
> org/bpel/sample}ECRProcess-9] calling
> org.apache.ode.bpel.epr.WSAEndpoint@16fd757.setAttribute(...)}):
> java.lang.NullPoi
> nterException
> org.apache.axis2.AxisFault: java.lang.NullPointerException
>         at
> org.apache.axis2.util.Utils.getInboundFaultFromMessageContext(Utils.java
> :486)
>         at
> org.apache.axis2.description.OutInAxisOperationClient.handleResponse(
> OutInAxisOperation.java:343)
>         at
> org.apache.axis2.description.OutInAxisOperationClient.send(
> OutInAxisOperation.java:389)
>         at
> org.apache.axis2.description.OutInAxisOperationClient.executeImpl(
> OutInAxisOperation.java:211)
>         at
> org.apache.axis2.client.OperationClient.execute(OperationClient.java:163)
>         at
> org.apache.ode.axis2.ExternalService$1$1.call(ExternalService.java:150)
>         at
> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:123)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(
> ThreadPoolExecutor.java:650)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java
> :675)
>         at java.lang.Thread.run(Thread.java:595)
> 17:40:23,737 ERROR [ExternalService] Error sending message
> (mex={PartnerRoleMex#hqejbhcnphr2kte2v4jbl8 [PID {http://ecli
> pse.org/bpel/sample}ECRProcess-9] calling
> org.apache.ode.bpel.epr.WSAEndpoint@16fd757.setAttribute(...)}):
> java.lang.Nul
> lPointerException
> org.apache.axis2.AxisFault: java.lang.NullPointerException
>         at
> org.apache.axis2.util.Utils.getInboundFaultFromMessageContext(Utils.java
> :486)
>         at
> org.apache.axis2.description.OutInAxisOperationClient.handleResponse(
> OutInAxisOperation.java:343)
>         at
> org.apache.axis2.description.OutInAxisOperationClient.send(
> OutInAxisOperation.java:389)
>         at
> org.apache.axis2.description.OutInAxisOperationClient.executeImpl(
> OutInAxisOperation.java:211)
>         at
> org.apache.axis2.client.OperationClient.execute(OperationClient.java:163)
>         at
> org.apache.ode.axis2.ExternalService$1$1.call(ExternalService.java:150)
>         at
> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:123)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(
> ThreadPoolExecutor.java:650)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java
> :675)
>         at java.lang.Thread.run(Thread.java:595)
> DEBUG - GeronimoLog.trace(54) | Mex[hqejbhcnphr2kte2v4jbl8].setPortOp(...)
> 17:40:23,747 DEBUG [MessageExchangeImpl]
> Mex[hqejbhcnphr2kte2v4jbl8].setPortOp(...)
> DEBUG - GeronimoLog.debug(66) | replyWithFailure
> mex=hqejbhcnphr2kte2v4jbl8
> failureType=COMMUNICATION_ERROR description=
> Error sending message (mex={PartnerRoleMex#hqejbhcnphr2kte2v4jbl8 [PID
> {http://eclipse.org/bpel/sample}ECRProcess-9] cal
> ling org.apache.ode.bpel.epr.WSAEndpoint@16fd757.setAttribute(...)}):
> java.lang.NullPointerException details=null
> 17:40:23,747 DEBUG [PartnerRoleMessageExchangeImpl] replyWithFailure
> mex=hqejbhcnphr2kte2v4jbl8 failureType=COMMUNICATIO
> N_ERROR description=Error sending message
> (mex={PartnerRoleMex#hqejbhcnphr2kte2v4jbl8 [PID
> {http://eclipse.org/bpel/samp
> le}ECRProcess-9] calling
> org.apache.ode.bpel.epr.WSAEndpoint@16fd757.setAttribute(...)}):
> java.lang.NullPointerException
> details=null
> DEBUG - GeronimoLog.debug(66) | create work event for
> mex=hqejbhcnphr2kte2v4jbl8
> 17:40:23,747 DEBUG [PartnerRoleMessageExchangeImpl] create work event for
> mex=hqejbhcnphr2kte2v4jbl8
> DEBUG - GeronimoLog.debug(66) | Thread[pool-2-thread-9,5,main]:
> lock(iid=1057, time=1MICROSECONDS)
> 17:40:23,757 DEBUG [InstanceLockManager] Thread[pool-2-thread-9,5,main]:
> lock(iid=1057, time=1MICROSECONDS)
> DEBUG - GeronimoLog.debug(66) | Thread[pool-2-thread-9,5,main]:
> lock(iid=1057, time=1MICROSECONDS)-->GRANTED
> 17:40:23,757 DEBUG [InstanceLockManager] Thread[pool-2-thread-9,5,main]:
> lock(iid=1057, time=1MICROSECONDS)-->GRANTED
> DEBUG - GeronimoLog.debug(66) | >>
> handleWorkEvent(jobData={type=INVOKE_RESPONSE,
> mexid=hqejbhcnphr2kte2v4jbl8,
> channel=
> 54, iid=1057})
> 17:40:23,757 DEBUG [BpelProcess] >>
> handleWorkEvent(jobData={type=INVOKE_RESPONSE,
> mexid=hqejbhcnphr2kte2v4jbl8,
> channel
> =54, iid=1057})
> DEBUG - GeronimoLog.debug(66) | BpelRuntimeContextImpl created for
> instance
> 1057. INDEXED STATE={{OScope 'Design Change
> Proposal' id=46}::4=[ACTIVE(...)], {OScope 'Design Change Proposal'
> id=46}::4=[SCOPE(...)], {OScope 'UpdateCBPWorkflow'
> id=144}::29=[ACTIVITYGUARD(...)],
>
> OSequence#47-HiddenSequence::6=[SEQUENCE(self=(OSequence#47-HiddenSequence,Termination
> Channel#9,ParentScopeChannel#11),
> linkframe=org.apache.ode.bpel.runtime.LinkFrame@1c90d2c,
> remaining=[{OScope
> 'UpdateCBP
> Workflow' id=144}, {OScope 'callbackClient' id=151}])],
> OSequence#45-main::2=[SEQUENCE(self=(OSequence#45-main,Terminati
> onChannel#3,ParentScopeChannel#5),
> linkframe=org.apache.ode.bpel.runtime.LinkFrame@1c90d2c,
> remaining=[{OScope
> 'Design C
> hange Proposal' id=46}])], {OScope 'UpdateCBPWorkflow'
> id=144}::30=[ACTIVE(...)], OInvoke#145-UpdateCBPWorkflow::31=[ACT
> IVITYGUARD(...)], {OScope 'UpdateCBPWorkflow' id=144}::30=[SCOPE(...)],
> {OScope '__PROCESS_SCOPE:ECRProcess' id=3}::0=[S
> COPE(...)], {OScope '__PROCESS_SCOPE:ECRProcess' id=3}::0=[ACTIVE(...)],
> OSequence#47-HiddenSequence::5=[ACTIVITYGUARD(.
> ..)], OSequence#45-main::1=[ACTIVITYGUARD(...)],
> OInvoke#145-UpdateCBPWorkflow::32=[INVOKE(...)], {OScope 'Design Change
> Proposal' id=46}::3=[ACTIVITYGUARD(...)]}
> 17:40:23,777 DEBUG [BpelRuntimeContextImpl] BpelRuntimeContextImpl created
> for instance 1057. INDEXED STATE={{OScope 'De
> sign Change Proposal' id=46}::4=[ACTIVE(...)], {OScope 'Design Change
> Proposal' id=46}::4=[SCOPE(...)], {OScope 'UpdateC
> BPWorkflow' id=144}::29=[ACTIVITYGUARD(...)],
> OSequence#47-HiddenSequence::6=[SEQUENCE(self=(OSequence#47-HiddenSequence
> ,TerminationChannel#9,ParentScopeChannel#11),
> linkframe=org.apache.ode.bpel.runtime.LinkFrame@1c90d2c, remaining=[{OScop
> e 'UpdateCBPWorkflow' id=144}, {OScope 'callbackClient' id=151}])],
> OSequence#45-main::2=[SEQUENCE(self=(OSequence#45-ma
> in,TerminationChannel#3,ParentScopeChannel#5),
> linkframe=org.apache.ode.bpel.runtime.LinkFrame@1c90d2c, remaining=[{OSco
> pe 'Design Change Proposal' id=46}])], {OScope 'UpdateCBPWorkflow'
> id=144}::30=[ACTIVE(...)], OInvoke#145-UpdateCBPWorkf
> low::31=[ACTIVITYGUARD(...)], {OScope 'UpdateCBPWorkflow'
> id=144}::30=[SCOPE(...)], {OScope '__PROCESS_SCOPE:ECRProcess'
> id=3}::0=[SCOPE(...)], {OScope '__PROCESS_SCOPE:ECRProcess'
> id=3}::0=[ACTIVE(...)], OSequence#47-HiddenSequence::5=[ACT
> IVITYGUARD(...)], OSequence#45-main::1=[ACTIVITYGUARD(...)],
> OInvoke#145-UpdateCBPWorkflow::32=[INVOKE(...)], {OScope 'D
> esign Change Proposal' id=46}::3=[ACTIVITYGUARD(...)]}
> DEBUG - GeronimoLog.debug(66) | InvokeResponse event for iid 1057
> 17:40:23,777 DEBUG [BpelProcess] InvokeResponse event for iid 1057
> DEBUG - GeronimoLog.debug(66) | Invoking message response for mexid
> hqejbhcnphr2kte2v4jbl8 and channel 54
> --
> View this message in context:
> http://www.nabble.com/Invoke---with-communication-error-tf4418802.html#a12603692
> Sent from the Apache Ode User mailing list archive at Nabble.com.
>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message