ode-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Anup Chandran <anup.chand...@3ds.com>
Subject Re: Invoke - with communication error
Date Tue, 11 Sep 2007 13:51:31 GMT


The Service works fine when i send request via soapUI.

I turned on the httpclient DEBUG.

This is trace..

DEBUG - GeronimoLog.debug(66) | InvokeResponse event for iid 1202
09:46:35,240 DEBUG [BpelProcess] InvokeResponse event for iid 1202
DEBUG - GeronimoLog.debug(66) | Invoking message response for mexid
hqejbhcnphr2kvk6gstpxt and channel 40
09:46:35,240 DEBUG [BpelRuntimeContextImpl] Invoking message response for
mexid hqejbhcnphr2kvk6gstpxt and channel 40
DEBUG - GeronimoLog.debug(66) | Triggering response
09:46:35,240 DEBUG [BpelRuntimeContextImpl] Triggering response
DEBUG - GeronimoLog.trace(54) | >>
createScopeInstance(parentScopeId=1204,scope={OScope 'UpdateCBPWorkflow'
id=144})
09:46:35,536 DEBUG [BpelProcess] >>
createScopeInstance(parentScopeId=1204,scope={OScope 'UpdateCBPWorkflow'
id=144})
DEBUG - GeronimoLog.trace(54) | >>
initializeEndpointReferences(parentScopeId=1270,partnerLinks=[])
09:46:35,546 DEBUG [BpelProcess] >>
initializeEndpointReferences(parentScopeId=1270,partnerLinks=[])
DEBUG - GeronimoLog.debug(66) | INVOKING PARTNER:
partnerLink={PartnerLinkInstance partnerLinkDecl=OPartnerLink#44,scope
InstanceId=1203}, op=setAttribute channel=InvokeResponseChannel#54)
09:46:35,566 DEBUG [BpelProcess] INVOKING PARTNER:
partnerLink={PartnerLinkInstance partnerLinkDecl=OPartnerLink#44,scop
eInstanceId=1203}, op=setAttribute channel=InvokeResponseChannel#54)
DEBUG - GeronimoLog.debug(66) | INVOKE PARTNER (SEP): sessionId=null
partnerSessionId=null
09:46:35,566 DEBUG [BpelRuntimeContextImpl] INVOKE PARTNER (SEP):
sessionId=null partnerSessionId=null
DEBUG - GeronimoLog.trace(54) | Mex[hqejbhcnphr2kvk6gstpxw].setPortOp(...)
09:46:35,566 DEBUG [MessageExchangeImpl]
Mex[hqejbhcnphr2kvk6gstpxw].setPortOp(...)
DEBUG - GeronimoLog.debug(66) | Routed: svcQname
{http://client.engineering.cbp.jpo}CBPWorkflowService --> null
09:46:35,566 DEBUG [BpelEngineImpl] Routed: svcQname
{http://client.engineering.cbp.jpo}CBPWorkflowService --> null
DEBUG - GeronimoLog.debug(66) | Invoking a partner operation: setAttribute
09:46:35,566 DEBUG [MessageExchangeContextImpl] Invoking a partner
operation: setAttribute
DEBUG - GeronimoLog.debug(66) | The service to invoke is the external
service org.apache.ode.axis2.ExternalService@d3852
5
09:46:35,566 DEBUG [MessageExchangeContextImpl] The service to invoke is the
external service org.apache.ode.axis2.Exter
nalService@d38525
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>
09:46:35,566 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
09:46:35,566 DEBUG [MessageExchangeImpl] GET MEX property
org.apache.ode.bpel.partnerRoleSessionId = null
DEBUG - GeronimoLog.debug(66) | GET MEX property
org.apache.ode.bpel.myRoleSessionId = null
09:46:35,566 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.
09:46:35,566 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#hqejbhcnphr2kvk6gstpxw [PID
{http://eclipse.org/bpel/sample}ECRProcess-9] calling org.apa
che.ode.bpel.epr.WSAEndpoint@11dca40.setAttribute(...)}
09:46:35,566 DEBUG [ExternalService] Axis2 sending message to
http://localhost:8080/ematrix/services/JpoCbpEngineeringCB
PWorkflow using MEX {PartnerRoleMex#hqejbhcnphr2kvk6gstpxw [PID
{http://eclipse.org/bpel/sample}ECRProcess-9] calling or
g.apache.ode.bpel.epr.WSAEndpoint@11dca40.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><axis2ns4:setAttribute
xmlns:axis2ns4="http://engineering.cbp.jpo" xmln
s:tns1="http://engineering.cbp.jpo">
                   <tns1:in2
xmlns:ns="http://www.apache.org/ode/pmapi/types/2006/08/02/"
xmlns="http://www.apache.org/o
de/pmapi/types/2006/08/02/">1202</tns1:in2>
                </axis2ns4:setAttribute></soapenv:Body></soapenv:Envelope>
09:46:35,577 DEBUG [ExternalService] Message: <?xml version='1.0'
encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="htt
p://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><axis2ns4:setAttribute
xmlns:axis2ns4="http://engineering.cbp.jpo"
 xmlns:tns1="http://engineering.cbp.jpo">
                   <tns1:in2
xmlns:ns="http://www.apache.org/ode/pmapi/types/2006/08/02/"
xmlns="http://www.apache.org/o
de/pmapi/types/2006/08/02/">1202</tns1:in2>
                </axis2ns4:setAttribute></soapenv:Body></soapenv:Envelope>
DEBUG - GeronimoLog.debug(66) | replyAsync mex=hqejbhcnphr2kvk6gstpxw
09:46:35,577 DEBUG [PartnerRoleMessageExchangeImpl] replyAsync
mex=hqejbhcnphr2kvk6gstpxw
DEBUG - GeronimoLog.debug(66) | Setting execution state on instance 1202
09:46:35,577 DEBUG [BpelRuntimeContextImpl] Setting execution state on
instance 1202
DEBUG - GeronimoLog.debug(66) | Thread[pool-2-thread-2,5,main]:
unlock(iid=1202)
09:46:36,230 DEBUG [InstanceLockManager] Thread[pool-2-thread-2,5,main]:
unlock(iid=1202)
DEBUG - GeronimoLog.debug(66) | Sending stateful TO epr in message header
using session null
09:46:36,251 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.
09:46:36,251 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:
hqejbhcnphr2kvk6gstpxx</addr:MessageID></soapenv:Header><soapenv:Body><axis2ns4:setAttribute
xmlns:axis2ns4="http://engi
neering.cbp.jpo" xmlns:tns1="http://engineering.cbp.jpo">
                   <tns1:in2
xmlns:ns="http://www.apache.org/ode/pmapi/types/2006/08/02/"
xmlns="http://www.apache.org/o
de/pmapi/types/2006/08/02/">1202</tns1:in2>
                </axis2ns4:setAttribute></soapenv:Body></soapenv:Envelope>
09:46:36,271 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:hqejbhcnphr2kvk6gstpxx</addr:MessageID></soapenv:Header><soapenv:Body><axis2ns4:setAttribute
xmlns:axis2ns4="http
://engineering.cbp.jpo" xmlns:tns1="http://engineering.cbp.jpo">
                   <tns1:in2
xmlns:ns="http://www.apache.org/ode/pmapi/types/2006/08/02/"
xmlns="http://www.apache.org/o
de/pmapi/types/2006/08/02/">1202</tns1:in2>
                </axis2ns4:setAttribute></soapenv:Body></soapenv:Envelope>
DEBUG - GeronimoLog.debug(66) | Set parameter http.connection.timeout =
60000
09:46:36,271 DEBUG [DefaultHttpParams] Set parameter http.connection.timeout
= 60000
DEBUG - GeronimoLog.debug(66) | Set parameter http.socket.timeout = 60000
09:46:36,271 DEBUG [DefaultHttpParams] Set parameter http.socket.timeout =
60000
DEBUG - GeronimoLog.debug(66) | Set parameter http.socket.timeout = 60000
09:46:36,271 DEBUG [DefaultHttpParams] Set parameter http.socket.timeout =
60000
DEBUG - GeronimoLog.trace(54) | enter PostMethod.clearRequestBody()
09:46:36,271 DEBUG [PostMethod] enter PostMethod.clearRequestBody()
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.clearRequestBody()
09:46:36,271 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.clearRequestBody()
DEBUG - GeronimoLog.trace(54) | enter
HttpClient.executeMethod(HostConfiguration,HttpMethod)
09:46:36,281 DEBUG [HttpClient] enter
HttpClient.executeMethod(HostConfiguration,HttpMethod)
DEBUG - GeronimoLog.trace(54) | enter
HttpClient.executeMethod(HostConfiguration,HttpMethod,HttpState)
09:46:36,281 DEBUG [HttpClient] enter
HttpClient.executeMethod(HostConfiguration,HttpMethod,HttpState)
DEBUG - GeronimoLog.trace(54) | enter
HttpConnectionManager.getConnectionWithTimeout(HostConfiguration, long)
09:46:36,281 DEBUG [MultiThreadedHttpConnectionManager] enter
HttpConnectionManager.getConnectionWithTimeout(HostConfigu
ration, long)
DEBUG - GeronimoLog.debug(66) | HttpConnectionManager.getConnection:  config
= HostConfiguration[host=http://localhost:8
080], timeout = 0
09:46:36,281 DEBUG [MultiThreadedHttpConnectionManager]
HttpConnectionManager.getConnection:  config = HostConfiguration
[host=http://localhost:8080], timeout = 0
DEBUG - GeronimoLog.trace(54) | enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration)
09:46:36,281 DEBUG [MultiThreadedHttpConnectionManager] enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfi
guration)
DEBUG - GeronimoLog.trace(54) | enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration)
09:46:36,281 DEBUG [MultiThreadedHttpConnectionManager] enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfi
guration)
DEBUG - GeronimoLog.debug(66) | Allocating new connection,
hostConfig=HostConfiguration[host=http://localhost:8080]
09:46:36,281 DEBUG [MultiThreadedHttpConnectionManager] Allocating new
connection, hostConfig=HostConfiguration[host=htt
p://localhost:8080]
DEBUG - GeronimoLog.trace(54) | Attempt number 1 to process request
09:46:36,281 DEBUG [HttpMethodDirector] Attempt number 1 to process request
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.open()
09:46:36,281 DEBUG [HttpConnection] enter HttpConnection.open()
DEBUG - GeronimoLog.debug(66) | Open connection to localhost:8080
09:46:36,281 DEBUG [HttpConnection] Open connection to localhost:8080
DEBUG - GeronimoLog.trace(54) | enter HttpMethodBase.execute(HttpState,
HttpConnection)
09:46:36,281 DEBUG [HttpMethodBase] enter HttpMethodBase.execute(HttpState,
HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter HttpMethodBase.writeRequest(HttpState,
HttpConnection)
09:46:36,281 DEBUG [HttpMethodBase] enter
HttpMethodBase.writeRequest(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.writeRequestLine(HttpState, HttpConnection)
09:46:36,291 DEBUG [HttpMethodBase] enter
HttpMethodBase.writeRequestLine(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.generateRequestLine(HttpConnection, String, String, String,
String)

09:46:36,291 DEBUG [HttpMethodBase] enter
HttpMethodBase.generateRequestLine(HttpConnection, String, String, String,
Str
ing)
DEBUG - GeronimoLog.debug(66) | >> "POST
/ematrix/services/JpoCbpEngineeringCBPWorkflow HTTP/1.1[\r][\n]"
09:46:36,291 DEBUG [header] >> "POST
/ematrix/services/JpoCbpEngineeringCBPWorkflow HTTP/1.1[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.print(String)
09:46:36,291 DEBUG [HttpConnection] enter HttpConnection.print(String)
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[])
09:46:36,291 DEBUG [HttpConnection] enter HttpConnection.write(byte[])
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[], int, int)
09:46:36,291 DEBUG [HttpConnection] enter HttpConnection.write(byte[], int,
int)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.writeRequestHeaders(HttpState,HttpConnection)
09:46:36,291 DEBUG [HttpMethodBase] enter
HttpMethodBase.writeRequestHeaders(HttpState,HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.addRequestHeaders(HttpState, HttpConnection)
09:46:36,291 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.addRequestHeaders(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
ExpectContinueMethod.addRequestHeaders(HttpState, HttpConnection)
09:46:36,291 DEBUG [ExpectContinueMethod] enter
ExpectContinueMethod.addRequestHeaders(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.addRequestHeaders(HttpState, HttpConnection)
09:46:36,291 DEBUG [HttpMethodBase] enter
HttpMethodBase.addRequestHeaders(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.addUserAgentRequestHeaders(HttpState, HttpConnection)
09:46:36,312 DEBUG [HttpMethodBase] enter
HttpMethodBase.addUserAgentRequestHeaders(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.addHostRequestHeader(HttpState, HttpConnection)
09:46:36,312 DEBUG [HttpMethodBase] enter
HttpMethodBase.addHostRequestHeader(HttpState, HttpConnection)
DEBUG - GeronimoLog.debug(66) | Adding Host request header
09:46:36,312 DEBUG [HttpMethodBase] Adding Host request header
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.addCookieRequestHeader(HttpState, HttpConnection)
09:46:36,312 DEBUG [HttpMethodBase] enter
HttpMethodBase.addCookieRequestHeader(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter HttpState.getCookies()
09:46:36,312 DEBUG [HttpState] enter HttpState.getCookies()
DEBUG - GeronimoLog.trace(54) | enter CookieSpecBase.match(String, int,
String, boolean, Cookie[])
09:46:36,312 DEBUG [CookieSpec] enter CookieSpecBase.match(String, int,
String, boolean, Cookie[])
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.addProxyConnectionHeader(HttpState, HttpConnection)
09:46:36,322 DEBUG [HttpMethodBase] enter
HttpMethodBase.addProxyConnectionHeader(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.addContentLengthRequestHeader(HttpState,
HttpConnection)
09:46:36,322 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.addContentLengthRequestHeader(HttpState, HttpConn
ection)
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.getRequestContentLength()
09:46:36,322 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.getRequestContentLength()
DEBUG - GeronimoLog.trace(54) | enter PostMethod.hasRequestContent()
09:46:36,322 DEBUG [PostMethod] enter PostMethod.hasRequestContent()
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.hasRequestContent()
09:46:36,322 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.hasRequestContent()
DEBUG - GeronimoLog.trace(54) | HttpMethodBase.addRequestHeader(Header)
09:46:36,322 DEBUG [HttpMethodBase] HttpMethodBase.addRequestHeader(Header)
DEBUG - GeronimoLog.debug(66) | >> "Content-Type: text/xml;
charset=UTF-8[\r][\n]"
09:46:36,322 DEBUG [header] >> "Content-Type: text/xml;
charset=UTF-8[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.print(String)
09:46:36,322 DEBUG [HttpConnection] enter HttpConnection.print(String)
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[])
09:46:36,322 DEBUG [HttpConnection] enter HttpConnection.write(byte[])
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[], int, int)
09:46:36,322 DEBUG [HttpConnection] enter HttpConnection.write(byte[], int,
int)
DEBUG - GeronimoLog.debug(66) | >> "SOAPAction: "urn:anonOutInOp"[\r][\n]"
09:46:36,322 DEBUG [header] >> "SOAPAction: "urn:anonOutInOp"[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.print(String)
09:46:36,322 DEBUG [HttpConnection] enter HttpConnection.print(String)
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[])
09:46:36,322 DEBUG [HttpConnection] enter HttpConnection.write(byte[])
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[], int, int)
09:46:36,322 DEBUG [HttpConnection] enter HttpConnection.write(byte[], int,
int)
DEBUG - GeronimoLog.debug(66) | >> "User-Agent: Axis2[\r][\n]"
09:46:36,322 DEBUG [header] >> "User-Agent: Axis2[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.print(String)
09:46:36,322 DEBUG [HttpConnection] enter HttpConnection.print(String)
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[])
09:46:36,332 DEBUG [HttpConnection] enter HttpConnection.write(byte[])
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[], int, int)
09:46:36,332 DEBUG [HttpConnection] enter HttpConnection.write(byte[], int,
int)
DEBUG - GeronimoLog.debug(66) | >> "Host: localhost:8080[\r][\n]"
09:46:36,332 DEBUG [header] >> "Host: localhost:8080[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.print(String)
09:46:36,332 DEBUG [HttpConnection] enter HttpConnection.print(String)
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[])
09:46:36,332 DEBUG [HttpConnection] enter HttpConnection.write(byte[])
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[], int, int)
09:46:36,332 DEBUG [HttpConnection] enter HttpConnection.write(byte[], int,
int)
DEBUG - GeronimoLog.debug(66) | >> "Transfer-Encoding: chunked[\r][\n]"
09:46:36,343 DEBUG [header] >> "Transfer-Encoding: chunked[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.print(String)
09:46:36,343 DEBUG [HttpConnection] enter HttpConnection.print(String)
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[])
09:46:36,343 DEBUG [HttpConnection] enter HttpConnection.write(byte[])
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[], int, int)
09:46:36,343 DEBUG [HttpConnection] enter HttpConnection.write(byte[], int,
int)
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.writeLine()
09:46:36,343 DEBUG [HttpConnection] enter HttpConnection.writeLine()
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[])
09:46:36,343 DEBUG [HttpConnection] enter HttpConnection.write(byte[])
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.write(byte[], int, int)
09:46:36,343 DEBUG [HttpConnection] enter HttpConnection.write(byte[], int,
int)
DEBUG - GeronimoLog.debug(66) | >> "[\r][\n]"
09:46:36,343 DEBUG [header] >> "[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.writeRequestBody(HttpState, HttpConnection)
09:46:36,343 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.writeRequestBody(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter PostMethod.hasRequestContent()
09:46:36,343 DEBUG [PostMethod] enter PostMethod.hasRequestContent()
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.hasRequestContent()
09:46:36,343 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.hasRequestContent()
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.getRequestContentLength()
09:46:36,343 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.getRequestContentLength()
DEBUG - GeronimoLog.trace(54) | enter PostMethod.hasRequestContent()
09:46:36,343 DEBUG [PostMethod] enter PostMethod.hasRequestContent()
DEBUG - GeronimoLog.trace(54) | enter
EntityEnclosingMethod.hasRequestContent()
09:46:36,343 DEBUG [EntityEnclosingMethod] enter
EntityEnclosingMethod.hasRequestContent()
DEBUG - GeronimoLog.trace(54) | enter
HttpConnection.getRequestOutputStream()
09:46:36,343 DEBUG [HttpConnection] enter
HttpConnection.getRequestOutputStream()
DEBUG - GeronimoLog.debug(66) | Request body sent
09:46:36,353 DEBUG [EntityEnclosingMethod] Request body sent
DEBUG - GeronimoLog.trace(54) | enter
HttpConnection.flushRequestOutputStream()
09:46:36,363 DEBUG [HttpConnection] enter
HttpConnection.flushRequestOutputStream()
DEBUG - GeronimoLog.trace(54) | enter HttpMethodBase.readResponse(HttpState,
HttpConnection)
09:46:36,394 DEBUG [HttpMethodBase] enter
HttpMethodBase.readResponse(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.readStatusLine(HttpState, HttpConnection)
09:46:36,394 DEBUG [HttpMethodBase] enter
HttpMethodBase.readStatusLine(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter HttpConnection.readLine()
09:46:36,394 DEBUG [HttpConnection] enter HttpConnection.readLine()
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readLine(InputStream,
String)
09:46:36,496 DEBUG [HttpParser] enter HttpParser.readLine(InputStream,
String)
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readRawLine()
09:46:36,506 DEBUG [HttpParser] enter HttpParser.readRawLine()
DEBUG - GeronimoLog.debug(66) | << "HTTP/1.1 500 Internal Server
Error[\r][\n]"
09:46:37,507 DEBUG [header] << "HTTP/1.1 500 Internal Server Error[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.readResponseHeaders(HttpState,HttpConnection)
09:46:37,517 DEBUG [HttpMethodBase] enter
HttpMethodBase.readResponseHeaders(HttpState,HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpConnection.getResponseInputStream()
09:46:37,527 DEBUG [HttpConnection] enter
HttpConnection.getResponseInputStream()
DEBUG - GeronimoLog.trace(54) | enter HeaderParser.parseHeaders(InputStream,
String)
09:46:37,527 DEBUG [HttpParser] enter HeaderParser.parseHeaders(InputStream,
String)
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readLine(InputStream,
String)
09:46:37,537 DEBUG [HttpParser] enter HttpParser.readLine(InputStream,
String)
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readRawLine()
09:46:37,537 DEBUG [HttpParser] enter HttpParser.readRawLine()
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readLine(InputStream,
String)
09:46:37,537 DEBUG [HttpParser] enter HttpParser.readLine(InputStream,
String)
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readRawLine()
09:46:37,537 DEBUG [HttpParser] enter HttpParser.readRawLine()
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readLine(InputStream,
String)
09:46:37,537 DEBUG [HttpParser] enter HttpParser.readLine(InputStream,
String)
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readRawLine()
09:46:37,537 DEBUG [HttpParser] enter HttpParser.readRawLine()
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readLine(InputStream,
String)
09:46:37,537 DEBUG [HttpParser] enter HttpParser.readLine(InputStream,
String)
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readRawLine()
09:46:37,548 DEBUG [HttpParser] enter HttpParser.readRawLine()
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readLine(InputStream,
String)
09:46:37,548 DEBUG [HttpParser] enter HttpParser.readLine(InputStream,
String)
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readRawLine()
09:46:37,548 DEBUG [HttpParser] enter HttpParser.readRawLine()
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readLine(InputStream,
String)
09:46:37,548 DEBUG [HttpParser] enter HttpParser.readLine(InputStream,
String)
DEBUG - GeronimoLog.trace(54) | enter HttpParser.readRawLine()
09:46:37,548 DEBUG [HttpParser] enter HttpParser.readRawLine()
DEBUG - GeronimoLog.debug(66) | << "Server: Apache-Coyote/1.1[\r][\n]"
09:46:37,548 DEBUG [header] << "Server: Apache-Coyote/1.1[\r][\n]"
DEBUG - GeronimoLog.debug(66) | << "Content-Type:
text/xml;charset=utf-8[\r][\n]"
09:46:37,548 DEBUG [header] << "Content-Type:
text/xml;charset=utf-8[\r][\n]"
DEBUG - GeronimoLog.debug(66) | << "Transfer-Encoding: chunked[\r][\n]"
09:46:37,548 DEBUG [header] << "Transfer-Encoding: chunked[\r][\n]"
DEBUG - GeronimoLog.debug(66) | << "Date: Tue, 11 Sep 2007 13:46:37
GMT[\r][\n]"
09:46:37,558 DEBUG [header] << "Date: Tue, 11 Sep 2007 13:46:37 GMT[\r][\n]"
DEBUG - GeronimoLog.debug(66) | << "Connection: close[\r][\n]"
09:46:37,558 DEBUG [header] << "Connection: close[\r][\n]"
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.processResponseHeaders(HttpState, HttpConnection)
09:46:37,558 DEBUG [HttpMethodBase] enter
HttpMethodBase.processResponseHeaders(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.readResponseBody(HttpState, HttpConnection)
09:46:37,558 DEBUG [HttpMethodBase] enter
HttpMethodBase.readResponseBody(HttpState, HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.readResponseBody(HttpConnection)
09:46:37,578 DEBUG [HttpMethodBase] enter
HttpMethodBase.readResponseBody(HttpConnection)
DEBUG - GeronimoLog.trace(54) | enter
HttpConnection.getResponseInputStream()
09:46:37,578 DEBUG [HttpConnection] enter
HttpConnection.getResponseInputStream()
DEBUG - GeronimoLog.trace(54) | enter
HttpMethodBase.canResponseHaveBody(int)
09:46:37,578 DEBUG [HttpMethodBase] enter
HttpMethodBase.canResponseHaveBody(int)
DEBUG - GeronimoLog.trace(54) | enter HeaderElement.parseElements(String)
09:46:37,578 DEBUG [HeaderElement] enter HeaderElement.parseElements(String)
DEBUG - GeronimoLog.trace(54) | enter HeaderElement.parseElements(char[])
09:46:37,578 DEBUG [HeaderElement] enter HeaderElement.parseElements(char[])
DEBUG - GeronimoLog.trace(54) | enter
HttpConnection.isResponseAvailable(int)
09:46:37,691 DEBUG [HttpConnection] enter
HttpConnection.isResponseAvailable(int)
DEBUG - GeronimoLog.trace(54) | enter HeaderElement.parseElements(String)
09:46:37,701 DEBUG [HeaderElement] enter HeaderElement.parseElements(String)
DEBUG - GeronimoLog.trace(54) | enter HeaderElement.parseElements(char[])
09:46:37,701 DEBUG [HeaderElement] enter HeaderElement.parseElements(char[])
DEBUG - GeronimoLog.trace(54) | enter
HeaderElement.getParameterByName(String)
09:46:37,701 DEBUG [HeaderElement] enter
HeaderElement.getParameterByName(String)
ERROR - GeronimoLog.error(108) | Error sending message
(mex={PartnerRoleMex#hqejbhcnphr2kvk6gstpxw [PID {http://eclipse.
org/bpel/sample}ECRProcess-9] calling
org.apache.ode.bpel.epr.WSAEndpoint@11dca40.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)
09:46:37,772 ERROR [ExternalService] Error sending message
(mex={PartnerRoleMex#hqejbhcnphr2kvk6gstpxw [PID {http://ecli
pse.org/bpel/sample}ECRProcess-9] calling
org.apache.ode.bpel.epr.WSAEndpoint@11dca40.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[hqejbhcnphr2kvk6gstpxw].setPortOp(...)
09:46:37,803 DEBUG [MessageExchangeImpl]
Mex[hqejbhcnphr2kvk6gstpxw].setPortOp(...)
DEBUG - GeronimoLog.debug(66) | replyWithFailure mex=hqejbhcnphr2kvk6gstpxw
failureType=COMMUNICATION_ERROR description=
Error sending message (mex={PartnerRoleMex#hqejbhcnphr2kvk6gstpxw [PID
{http://eclipse.org/bpel/sample}ECRProcess-9] cal
ling org.apache.ode.bpel.epr.WSAEndpoint@11dca40.setAttribute(...)}):
java.lang.NullPointerException details=null
09:46:37,803 DEBUG [PartnerRoleMessageExchangeImpl] replyWithFailure
mex=hqejbhcnphr2kvk6gstpxw failureType=COMMUNICATIO
N_ERROR description=Error sending message
(mex={PartnerRoleMex#hqejbhcnphr2kvk6gstpxw [PID
{http://eclipse.org/bpel/samp
le}ECRProcess-9] calling
org.apache.ode.bpel.epr.WSAEndpoint@11dca40.setAttribute(...)}):
java.lang.NullPointerException
 details=null
DEBUG - GeronimoLog.debug(66) | create work event for
mex=hqejbhcnphr2kvk6gstpxw
09:46:37,803 DEBUG [PartnerRoleMessageExchangeImpl] create work event for
mex=hqejbhcnphr2kvk6gstpxw
DEBUG - GeronimoLog.debug(66) | Thread[pool-2-thread-2,5,main]:
lock(iid=1202, time=1MICROSECONDS)
09:46:37,864 DEBUG [InstanceLockManager] Thread[pool-2-thread-2,5,main]:
lock(iid=1202, time=1MICROSECONDS)
DEBUG - GeronimoLog.debug(66) | Thread[pool-2-thread-2,5,main]:
lock(iid=1202, time=1MICROSECONDS)-->GRANTED
09:46:37,864 DEBUG [InstanceLockManager] Thread[pool-2-thread-2,5,main]:
lock(iid=1202, time=1MICROSECONDS)-->GRANTED
DEBUG - GeronimoLog.debug(66) | >>
handleWorkEvent(jobData={type=INVOKE_RESPONSE, mexid=hqejbhcnphr2kvk6gstpxw,
channel=
54, iid=1202})
09:46:37,874 DEBUG [BpelProcess] >>
handleWorkEvent(jobData={type=INVOKE_RESPONSE, mexid=hqejbhcnphr2kvk6gstpxw,
channel
=54, iid=1202})
DEBUG - GeronimoLog.debug(66) | BpelRuntimeContextImpl created for instance
1202. INDEXED STATE={OSequence#45-main::1=[A
CTIVITYGUARD(...)], OInvoke#145-UpdateCBPWorkflow::32=[INVOKE(...)],
OSequence#47-HiddenSequence::6=[SEQUENCE(self=(OSeq
uence#47-HiddenSequence,TerminationChannel#9,ParentScopeChannel#11),
linkframe=org.apache.ode.bpel.runtime.LinkFrame@6c7
d22, remaining=[{OScope 'UpdateCBPWorkflow' id=144}, {OScope
'callbackClient' id=151}])], OSequence#47-HiddenSequence::5
=[ACTIVITYGUARD(...)], {OScope 'Design Change Proposal'
id=46}::4=[SCOPE(...)], {OScope '__PROCESS_SCOPE:ECRProcess' id=
3}::0=[ACTIVE(...)], {OScope 'UpdateCBPWorkflow' id=144}::30=[SCOPE(...)],
{OScope 'UpdateCBPWorkflow' id=144}::30=[ACTI
VE(...)], OInvoke#145-UpdateCBPWorkflow::31=[ACTIVITYGUARD(...)], {OScope
'UpdateCBPWorkflow' id=144}::29=[ACTIVITYGUARD
(...)], {OScope 'Design Change Proposal' id=46}::3=[ACTIVITYGUARD(...)],
{OScope 'Design Change Proposal' id=46}::4=[ACT
IVE(...)], {OScope '__PROCESS_SCOPE:ECRProcess' id=3}::0=[SCOPE(...)],
OSequence#45-main::2=[SEQUENCE(self=(OSequence#45
-main,TerminationChannel#3,ParentScopeChannel#5),
linkframe=org.apache.ode.bpel.runtime.LinkFrame@6c7d22, remaining=[{OS
cope 'Design Change Proposal' id=46}])]}
09:46:37,895 DEBUG [BpelRuntimeContextImpl] BpelRuntimeContextImpl created
for instance 1202. INDEXED STATE={OSequence#4
5-main::1=[ACTIVITYGUARD(...)],
OInvoke#145-UpdateCBPWorkflow::32=[INVOKE(...)],
OSequence#47-HiddenSequence::6=[SEQUENC
E(self=(OSequence#47-HiddenSequence,TerminationChannel#9,ParentScopeChannel#11),
linkframe=org.apache.ode.bpel.runtime.L
inkFrame@6c7d22, remaining=[{OScope 'UpdateCBPWorkflow' id=144}, {OScope
'callbackClient' id=151}])], OSequence#47-Hidde
nSequence::5=[ACTIVITYGUARD(...)], {OScope 'Design Change Proposal'
id=46}::4=[SCOPE(...)], {OScope '__PROCESS_SCOPE:ECR
Process' id=3}::0=[ACTIVE(...)], {OScope 'UpdateCBPWorkflow'
id=144}::30=[SCOPE(...)], {OScope 'UpdateCBPWorkflow' id=14
4}::30=[ACTIVE(...)],
OInvoke#145-UpdateCBPWorkflow::31=[ACTIVITYGUARD(...)], {OScope
'UpdateCBPWorkflow' id=144}::29=[A
CTIVITYGUARD(...)], {OScope 'Design Change Proposal'
id=46}::3=[ACTIVITYGUARD(...)], {OScope 'Design Change Proposal' id
=46}::4=[ACTIVE(...)], {OScope '__PROCESS_SCOPE:ECRProcess'
id=3}::0=[SCOPE(...)], OSequence#45-main::2=[SEQUENCE(self=(
OSequence#45-main,TerminationChannel#3,ParentScopeChannel#5),
linkframe=org.apache.ode.bpel.runtime.LinkFrame@6c7d22, re
maining=[{OScope 'Design Change Proposal' id=46}])]}
DEBUG - GeronimoLog.debug(66) | InvokeResponse event for iid 1202
09:46:37,905 DEBUG [BpelProcess] InvokeResponse event for iid 1202
DEBUG - GeronimoLog.debug(66) | Invoking message response for mexid
hqejbhcnphr2kvk6gstpxw and channel 54
09:46:37,905 DEBUG [BpelRuntimeContextImpl] Invoking message response for
mexid hqejbhcnphr2kvk6gstpxw and channel 54
DEBUG - GeronimoLog.debug(66) | Triggering response
09:46:37,905 DEBUG [BpelRuntimeContextImpl] Triggering response
INFO - GeronimoLog.info(79) | ActivityRecovery: Registering activity 31,
failure reason: Error sending message (mex={Par
tnerRoleMex#hqejbhcnphr2kvk6gstpxw [PID
{http://eclipse.org/bpel/sample}ECRProcess-9] calling
org.apache.ode.bpel.epr.WS
AEndpoint@11dca40.setAttribute(...)}): java.lang.NullPointerException on
channel 55
09:46:37,915 INFO  [BpelRuntimeContextImpl] ActivityRecovery: Registering
activity 31, failure reason: Error sending mes
sage (mex={PartnerRoleMex#hqejbhcnphr2kvk6gstpxw [PID
{http://eclipse.org/bpel/sample}ECRProcess-9] calling org.apache.o
de.bpel.epr.WSAEndpoint@11dca40.setAttribute(...)}):
java.lang.NullPointerException on channel 55
DEBUG - GeronimoLog.debug(66) | Setting execution state on instance 1202
09:46:38,068 DEBUG [BpelRuntimeContextImpl] Setting execution state on
instance 1202
DEBUG - GeronimoLog.debug(66) | Thread[pool-2-thread-2,5,main]:
unlock(iid=1202)
09:46:38,201 DEBUG [InstanceLockManager] Thread[pool-2-thread-2,5,main]:
unlock(iid=1202)
DEBUG - GeronimoLog.debug(66) | Connection reclaimed by garbage collector,
hostConfig=HostConfiguration[host=http://loca
lhost:8080]
09:47:31,939 DEBUG [MultiThreadedHttpConnectionManager] Connection reclaimed
by garbage collector, hostConfig=HostConfig
uration[host=http://localhost:8080]
DEBUG - GeronimoLog.trace(54) | enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration)
09:47:40,293 DEBUG [MultiThreadedHttpConnectionManager] enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfi
guration)
DEBUG - GeronimoLog.trace(54) | enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration)
09:47:40,303 DEBUG [MultiThreadedHttpConnectionManager] enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfi
guration)
DEBUG - GeronimoLog.debug(66) | Notifying no-one, there are no waiting
threads
09:47:40,303 DEBUG [MultiThreadedHttpConnectionManager] Notifying no-one,
there are no waiting threads
DEBUG - GeronimoLog.debug(66) | Connection reclaimed by garbage collector,
hostConfig=HostConfiguration[host=http://loca
lhost:8080]
09:47:40,303 DEBUG [MultiThreadedHttpConnectionManager] Connection reclaimed
by garbage collector, hostConfig=HostConfig
uration[host=http://localhost:8080]
DEBUG - GeronimoLog.trace(54) | enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration)
09:47:40,303 DEBUG [MultiThreadedHttpConnectionManager] enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfi
guration)
DEBUG - GeronimoLog.trace(54) | enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration)
09:47:40,314 DEBUG [MultiThreadedHttpConnectionManager] enter
HttpConnectionManager.ConnectionPool.getHostPool(HostConfi



Anup




Alex Boisvert wrote:
> 
> 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.
>>
>>
> 
> 

-- 
View this message in context: http://www.nabble.com/Invoke---with-communication-error-tf4418802.html#a12615259
Sent from the Apache Ode User mailing list archive at Nabble.com.


Mime
View raw message