ode-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "raulvk.soa" <raulvk....@gmail.com>
Subject Re: ODE picking wrong instance on bpel:reply
Date Thu, 28 Oct 2010 17:38:16 GMT

Thanks for the overwhelming amount of replies!

Fixed the problem.

Regards.



raulvk.soa wrote:
> 
> Hello.... no one has a clue on this?
> 
> Thanks.
> 
> 
> raulvk.soa wrote:
>> 
>> Hi,
>> 
>> We are seeing a strange issue with Apache ODE 1.3.4 in a JBI environment
>> (ServiceMix). 
>> We have a business process with various bpel:invoke activities, calling
>> In-Out synchronous JBI endpoints.
>> 
>> When the process finishes, it collects all the responses from the
>> bpel:invoke activities, builds an aggregate message, and sends the
>> message back via a bpel:reply activity.
>> 
>> When the bpel:reply activity executes, we see the following Exception:
>> 
>> javax.jbi.messaging.MessagingException: Out message is already set
>>         at
>> org.apache.servicemix.jbi.messaging.MessageExchangeImpl.setMessage(MessageExchangeImpl.java:360)
>>         at
>> org.apache.servicemix.jbi.messaging.MessageExchangeImpl.setOutMessage(MessageExchangeImpl.java:550)
>>         at org.apache.ode.jbi.OdeService.outResponse(OdeService.java:340)
>>         at org.apache.ode.jbi.OdeService.onResponse(OdeService.java:211)
>>         at
>> org.apache.ode.jbi.MessageExchangeContextImpl.onAsyncReply(MessageExchangeContextImpl.java:53)
>>         at
>> org.apache.ode.bpel.engine.BpelRuntimeContextImpl.doAsyncReply(BpelRuntimeContextImpl.java:581)
>>         at
>> org.apache.ode.bpel.engine.BpelRuntimeContextImpl.reply2(BpelRuntimeContextImpl.java:622)
>>         at
>> org.apache.ode.bpel.engine.BpelRuntimeContextImpl.reply(BpelRuntimeContextImpl.java:589)
>>         at org.apache.ode.bpel.runtime.REPLY.run(REPLY.java:68)
>>         at sun.reflect.GeneratedMethodAccessor187.invoke(Unknown Source)
>>         at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>         at java.lang.reflect.Method.invoke(Method.java:597)
>>         at
>> org.apache.ode.jacob.vpu.JacobVPU$JacobThreadImpl.run(JacobVPU.java:451)
>>         at org.apache.ode.jacob.vpu.JacobVPU.execute(JacobVPU.java:139)
>>         [...]
>> 
>> It looks like the OUT message was already set! However, no bpel:reply has
>> executed previously!
>> 
>> To figure out what is happening, and if we grep the log file for the
>> mexid that fails (hqejbhcnphr5opnw0po5d0), we see the following:
>> 
>> 2010-10-21 16:01:23,023 | DEBUG | ServiceBridge |
>> org.apache.ode.jbi.ServiceBridge | {MyRoleMex#hqejbhcnphr5otnqi165q2
>> [Client ID:10.10.10.10-12bcf3a00b8-5:250] calling
>> {http://www.mycompany.org}MyProcess.MyProcessOperation(...)}: mmex
>> copyProperties
>> 2010-10-21 16:01:23,027 | DEBUG | OdeService |
>> org.apache.ode.jbi.OdeService | ODE MEX {MyRoleMex#hqejbhcnphr5otnqi165q2
>> [Client ID:10.10.10.10-12bcf3a00b8-5:250] calling
>> {http://www.mycompany.org}MyProcess.MyProcessOperation(...)} completed
>> ASYNCHRONOUSLY.
>> 2010-10-21 16:01:23,027 | DEBUG | OdeService |
>> org.apache.ode.jbi.OdeService | Commiting ODE MEX
>> {MyRoleMex#hqejbhcnphr5otnqi165q2 [Client
>> ID:10.10.10.10-12bcf3a00b8-5:250] calling
>> {http://www.mycompany.org}MyProcess.MyProcessOperation(...)}
>> 2010-10-21 16:01:23,054 | DEBUG | BpelEngineImpl |
>> org.apache.ode.bpel.engine.BpelEngineImpl | handleJobDetails:
>> InvokeInternal event for mexid hqejbhcnphr5otnqi165q2
>> 2010-10-21 16:01:23,059 | DEBUG | BpelProcess |
>> org.apache.ode.bpel.engine.BpelProcess | >>
>> handleJobDetails(jobData=JobDetails( instanceId: null mexId:
>> hqejbhcnphr5otnqi165q2 processId: {http://www.mycompany.org}MyProcess-0
>> type: INVOKE_INTERNAL channel: null correlatorId: null correlationKeySet:
>> null retryCount: null inMem: false detailsExt: {}))
>> 2010-10-21 16:01:23,059 | DEBUG | BpelProcess |
>> org.apache.ode.bpel.engine.BpelProcess | InvokeInternal event for mexid
>> hqejbhcnphr5otnqi165q2
>> 2010-10-21 16:01:23,079 | DEBUG | BpelProcess |
>> org.apache.ode.bpel.engine.BpelRuntimeContextImpl | SELECT:
>> PickResponseChannel#9: FOUND match for NEW instance
>> mexRef={MyRoleMex#hqejbhcnphr5otnqi165q2 [Client
>> ID:10.10.10.10-12bcf3a00b8-5:250] calling
>> {http://www.mycompany.org}MyProcess.MyProcessOperation(...)}
>> 2010-10-21 16:01:24,647 | DEBUG | OdeService |
>> org.apache.ode.jbi.OdeService | Processing MEX tracker mexId:
>> hqejbhcnphr5otnqi165q2 clientId: ID:10.10.10.10-12bcf3a00b8-5:250
>> 2010-10-21 16:01:24,652 | DEBUG | MyRoleMessageExchangeImpl |
>> org.apache.ode.bpel.engine.MyRoleMessageExchangeImpl | Releasing mex
>> hqejbhcnphr5otnqi165q2
>> 2010-10-21 16:01:25,531 | DEBUG | OdeService |
>> org.apache.ode.jbi.OdeService$1 | Consuming MEX tracker mexId:
>> hqejbhcnphr5otnqi165q2 clientId: ID:10.10.10.10-12bcf3a00b8-5:250
>> [smx@abanar /usr/local/apache-servicemix-3.3.1/data/log/ProcesosNegocio]$
>> grep hqejbhcnphr5opnw0po5d0 ProcesosNegocio.log
>> 2010-10-21 14:41:23,062 | DEBUG | ServiceBridge |
>> org.apache.ode.jbi.ServiceBridge | {MyRoleMex#hqejbhcnphr5opnw0po5d0
>> [Client ID:10.10.10.10-12bc8bd6a88-5:1288] calling
>> {http://www.mycompany.org}MyProcess.MyProcessOperation(...)}: mmex
>> copyProperties
>> 2010-10-21 14:41:23,065 | DEBUG | OdeService |
>> org.apache.ode.jbi.OdeService | ODE MEX {MyRoleMex#hqejbhcnphr5opnw0po5d0
>> [Client ID:10.10.10.10-12bc8bd6a88-5:1288] calling
>> {http://www.mycompany.org}MyProcess.MyProcessOperation(...)} completed
>> ASYNCHRONOUSLY.
>> 2010-10-21 14:41:23,065 | DEBUG | OdeService |
>> org.apache.ode.jbi.OdeService | Commiting ODE MEX
>> {MyRoleMex#hqejbhcnphr5opnw0po5d0 [Client
>> ID:10.10.10.10-12bc8bd6a88-5:1288] calling
>> {http://www.mycompany.org}MyProcess.MyProcessOperation(...)}
>> 2010-10-21 14:41:23,103 | DEBUG | BpelEngineImpl |
>> org.apache.ode.bpel.engine.BpelEngineImpl | handleJobDetails:
>> InvokeInternal event for mexid hqejbhcnphr5opnw0po5d0
>> 2010-10-21 14:41:23,107 | DEBUG | BpelProcess |
>> org.apache.ode.bpel.engine.BpelProcess | >>
>> handleJobDetails(jobData=JobDetails( instanceId: null mexId:
>> hqejbhcnphr5opnw0po5d0 processId: {http://www.mycompany.org}MyProcess-0
>> type: INVOKE_INTERNAL channel: null correlatorId: null correlationKeySet:
>> null retryCount: null inMem: false detailsExt: {}))
>> 2010-10-21 14:41:23,107 | DEBUG | BpelProcess |
>> org.apache.ode.bpel.engine.BpelProcess | InvokeInternal event for mexid
>> hqejbhcnphr5opnw0po5d0
>> 2010-10-21 14:41:23,120 | DEBUG | BpelProcess |
>> org.apache.ode.bpel.engine.BpelRuntimeContextImpl | SELECT:
>> PickResponseChannel#9: FOUND match for NEW instance
>> mexRef={MyRoleMex#hqejbhcnphr5opnw0po5d0 [Client
>> ID:10.10.10.10-12bc8bd6a88-5:1288] calling
>> {http://www.mycompany.org}MyProcess.MyProcessOperation(...)}
>> 2010-10-21 14:41:24,871 | DEBUG | OdeService |
>> org.apache.ode.jbi.OdeService | Processing MEX tracker mexId:
>> hqejbhcnphr5opnw0po5d0 clientId: ID:10.10.10.10-12bc8bd6a88-5:1288
>> 2010-10-21 14:41:24,873 | DEBUG | MyRoleMessageExchangeImpl |
>> org.apache.ode.bpel.engine.MyRoleMessageExchangeImpl | Releasing mex
>> hqejbhcnphr5opnw0po5d0
>> 2010-10-21 14:41:50,623 | DEBUG | OdeService |
>> org.apache.ode.jbi.OdeService | Processing MEX tracker mexId:
>> hqejbhcnphr5opnw0po5d0 clientId: ID:10.10.10.10-12bc8bd6a88-5:1288
>> 2010-10-21 14:41:50,625 | ERROR | OdeService |
>> org.apache.ode.jbi.OdeService | Error processing response from ODE to JBI
>> mexId: hqejbhcnphr5opnw0po5d0 clientId: ID:10.10.10.10-12bc8bd6a88-5:1288
>> 
>> (Notice the like "Releasing..." line, and then notice the process being
>> picked up again).
>> 
>> We have spent hours trying to figure out the problem, but we can't get
>> our heads around it. Any ideas?
>> 
>> Many thanks!
>> 
>> 
>> 
> 
> 

-- 
View this message in context: http://old.nabble.com/ODE-picking-wrong-instance-on-bpel%3Areply-tp30020659p30078965.html
Sent from the Apache Ode User mailing list archive at Nabble.com.


Mime
View raw message