You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@ode.apache.org by "Kharche, Jitendra" <Ji...@geometricglobal.com> on 2015/01/15 13:55:26 UTC
A message arrived before a receive is ready for a request/response
pattern
HI,
I randomly get following log lines on the ode console.
17:30:47,923 WARN [BpelRuntimeContextImpl] A message arrived before a receive is ready for a request/response pattern. This may be processed to success. However, you should consider revising your process since a TCP port and a container thread will be held for a longer time and the process will not scale under heavy load.
17:30:47,930 DEBUG [CorrelatorDAOImpl] removeLocalRoutes 268
17:30:47,933 DEBUG [CorrelatorDAOImpl] removing {CorrelationKey setId=@2[Session, values=[1421323225877]]} 0 one
17:30:47,935 DEBUG [CorrelatorDAOImpl] removeLocalRoutes 268
17:30:47,936 DEBUG [JacobVPU] injecting (...)
17:30:47,938 FATAL [BpelRuntimeContextImpl] Engine requested response while the message exchange hqejbhcnphr9x4h2860wp3 was in the state RESPONSE
17:30:47,939 ERROR [PICK] The message exchange seems to be in an unconsistent state, you're probably missing a reply on a request/response interaction.
17:30:47,942 DEBUG [EMPTY] <empty name=OEmpty#840>
17:30:47,945 DEBUG [ACTIVITYGUARD] ActivityRecovery: Activity 159 requires recovery
17:30:47,949 INFO [BpelRuntimeContextImpl] ActivityRecovery: Registering activity 159, failure reason: org.apache.ode.bpel.iapi.BpelEngineException: Engine requested response while the message exchange hqejbhcnphr9x4h2860wp3 was in the state RESPONSE on channel 270
What could be the reason and how can I fix it?
This is happening in test environment where there is no load. It happens even on the first process instance after the ODE restart.
Strange thing is this does not happen always. It happens randomly. So I think this is not a problem in my process.
Another thing is, though it says the activity is registered for recovery (ActivityRecovery: Registering activity 159), it fails to recover when I try from the InstanceManagement recoverActivity() API.
Regards,
Jitendra
Re: A message arrived before a receive is ready for a
request/response pattern
Posted by Sathwik B P <sa...@gmail.com>.
To log incoming/outgoing messages over the wire follow,
http://hc.apache.org/httpclient-3.x/logging.html
On Thu, Jan 15, 2015 at 10:37 PM, Sathwik B P <sa...@gmail.com> wrote:
> This happens when a message arrives early in the process.
>
> You probably have a Receive-Reply activity for which the message has
> already arrived while the process is still executing some activities prior
> to this Receive activity. This will lead to blocking of the container
> thread since it's a
> synchronous operation. AFAIK you cannot recover from this scenario.
>
> If the message arrival into the process cannot be regulated, then you
> should think making changes in your process by providing a One-way MEP
> instead of Req-Resp MEP.
>
> regards,
> sathwik
>
> On Thu, Jan 15, 2015 at 6:34 PM, Kharche, Jitendra <
> Jitendra.Kharche@geometricglobal.com> wrote:
>
>>
>> Also how/where can I check what is the message received in the following
>> case? I put ODE logs to DEBUG level but I did not see the message in ODE
>> logs.
>>
>> Regards,
>> Jitendra
>>
>> -----Original Message-----
>> From: Kharche, Jitendra [mailto:Jitendra.Kharche@geometricglobal.com]
>> Sent: Thursday, January 15, 2015 6:25 PM
>> To: user@ode.apache.org
>> Subject: A message arrived before a receive is ready for a
>> request/response pattern
>>
>> HI,
>>
>> I randomly get following log lines on the ode console.
>>
>> 17:30:47,923 WARN [BpelRuntimeContextImpl] A message arrived before a
>> receive is ready for a request/response pattern. This may be processed to
>> success. However, you should consider revising your process since a TCP
>> port and a container thread will be held for a longer time and the process
>> will not scale under heavy load.
>> 17:30:47,930 DEBUG [CorrelatorDAOImpl] removeLocalRoutes 268
>> 17:30:47,933 DEBUG [CorrelatorDAOImpl] removing {CorrelationKey
>> setId=@2[Session, values=[1421323225877]]} 0 one
>> 17:30:47,935 DEBUG [CorrelatorDAOImpl] removeLocalRoutes 268
>> 17:30:47,936 DEBUG [JacobVPU] injecting (...)
>> 17:30:47,938 FATAL [BpelRuntimeContextImpl] Engine requested response
>> while the message exchange hqejbhcnphr9x4h2860wp3 was in the state RESPONSE
>> 17:30:47,939 ERROR [PICK] The message exchange seems to be in an
>> unconsistent state, you're probably missing a reply on a request/response
>> interaction.
>> 17:30:47,942 DEBUG [EMPTY] <empty name=OEmpty#840>
>> 17:30:47,945 DEBUG [ACTIVITYGUARD] ActivityRecovery: Activity 159
>> requires recovery
>> 17:30:47,949 INFO [BpelRuntimeContextImpl] ActivityRecovery: Registering
>> activity 159, failure reason: org.apache.ode.bpel.iapi.BpelEngineException:
>> Engine requested response while the message exchange hqejbhcnphr9x4h2860wp3
>> was in the state RESPONSE on channel 270
>>
>> What could be the reason and how can I fix it?
>> This is happening in test environment where there is no load. It happens
>> even on the first process instance after the ODE restart.
>> Strange thing is this does not happen always. It happens randomly. So I
>> think this is not a problem in my process.
>>
>> Another thing is, though it says the activity is registered for recovery
>> (ActivityRecovery: Registering activity 159), it fails to recover when I
>> try from the InstanceManagement recoverActivity() API.
>>
>> Regards,
>> Jitendra
>>
>>
>
Re: A message arrived before a receive is ready for a
request/response pattern
Posted by Sathwik B P <sa...@gmail.com>.
This happens when a message arrives early in the process.
You probably have a Receive-Reply activity for which the message has
already arrived while the process is still executing some activities prior
to this Receive activity. This will lead to blocking of the container
thread since it's a
synchronous operation. AFAIK you cannot recover from this scenario.
If the message arrival into the process cannot be regulated, then you
should think making changes in your process by providing a One-way MEP
instead of Req-Resp MEP.
regards,
sathwik
On Thu, Jan 15, 2015 at 6:34 PM, Kharche, Jitendra <
Jitendra.Kharche@geometricglobal.com> wrote:
>
> Also how/where can I check what is the message received in the following
> case? I put ODE logs to DEBUG level but I did not see the message in ODE
> logs.
>
> Regards,
> Jitendra
>
> -----Original Message-----
> From: Kharche, Jitendra [mailto:Jitendra.Kharche@geometricglobal.com]
> Sent: Thursday, January 15, 2015 6:25 PM
> To: user@ode.apache.org
> Subject: A message arrived before a receive is ready for a
> request/response pattern
>
> HI,
>
> I randomly get following log lines on the ode console.
>
> 17:30:47,923 WARN [BpelRuntimeContextImpl] A message arrived before a
> receive is ready for a request/response pattern. This may be processed to
> success. However, you should consider revising your process since a TCP
> port and a container thread will be held for a longer time and the process
> will not scale under heavy load.
> 17:30:47,930 DEBUG [CorrelatorDAOImpl] removeLocalRoutes 268
> 17:30:47,933 DEBUG [CorrelatorDAOImpl] removing {CorrelationKey
> setId=@2[Session, values=[1421323225877]]} 0 one
> 17:30:47,935 DEBUG [CorrelatorDAOImpl] removeLocalRoutes 268
> 17:30:47,936 DEBUG [JacobVPU] injecting (...)
> 17:30:47,938 FATAL [BpelRuntimeContextImpl] Engine requested response
> while the message exchange hqejbhcnphr9x4h2860wp3 was in the state RESPONSE
> 17:30:47,939 ERROR [PICK] The message exchange seems to be in an
> unconsistent state, you're probably missing a reply on a request/response
> interaction.
> 17:30:47,942 DEBUG [EMPTY] <empty name=OEmpty#840>
> 17:30:47,945 DEBUG [ACTIVITYGUARD] ActivityRecovery: Activity 159 requires
> recovery
> 17:30:47,949 INFO [BpelRuntimeContextImpl] ActivityRecovery: Registering
> activity 159, failure reason: org.apache.ode.bpel.iapi.BpelEngineException:
> Engine requested response while the message exchange hqejbhcnphr9x4h2860wp3
> was in the state RESPONSE on channel 270
>
> What could be the reason and how can I fix it?
> This is happening in test environment where there is no load. It happens
> even on the first process instance after the ODE restart.
> Strange thing is this does not happen always. It happens randomly. So I
> think this is not a problem in my process.
>
> Another thing is, though it says the activity is registered for recovery
> (ActivityRecovery: Registering activity 159), it fails to recover when I
> try from the InstanceManagement recoverActivity() API.
>
> Regards,
> Jitendra
>
>
RE: A message arrived before a receive is ready for a
request/response pattern
Posted by "Kharche, Jitendra" <Ji...@geometricglobal.com>.
Also how/where can I check what is the message received in the following case? I put ODE logs to DEBUG level but I did not see the message in ODE logs.
Regards,
Jitendra
-----Original Message-----
From: Kharche, Jitendra [mailto:Jitendra.Kharche@geometricglobal.com]
Sent: Thursday, January 15, 2015 6:25 PM
To: user@ode.apache.org
Subject: A message arrived before a receive is ready for a request/response pattern
HI,
I randomly get following log lines on the ode console.
17:30:47,923 WARN [BpelRuntimeContextImpl] A message arrived before a receive is ready for a request/response pattern. This may be processed to success. However, you should consider revising your process since a TCP port and a container thread will be held for a longer time and the process will not scale under heavy load.
17:30:47,930 DEBUG [CorrelatorDAOImpl] removeLocalRoutes 268
17:30:47,933 DEBUG [CorrelatorDAOImpl] removing {CorrelationKey setId=@2[Session, values=[1421323225877]]} 0 one
17:30:47,935 DEBUG [CorrelatorDAOImpl] removeLocalRoutes 268
17:30:47,936 DEBUG [JacobVPU] injecting (...)
17:30:47,938 FATAL [BpelRuntimeContextImpl] Engine requested response while the message exchange hqejbhcnphr9x4h2860wp3 was in the state RESPONSE
17:30:47,939 ERROR [PICK] The message exchange seems to be in an unconsistent state, you're probably missing a reply on a request/response interaction.
17:30:47,942 DEBUG [EMPTY] <empty name=OEmpty#840>
17:30:47,945 DEBUG [ACTIVITYGUARD] ActivityRecovery: Activity 159 requires recovery
17:30:47,949 INFO [BpelRuntimeContextImpl] ActivityRecovery: Registering activity 159, failure reason: org.apache.ode.bpel.iapi.BpelEngineException: Engine requested response while the message exchange hqejbhcnphr9x4h2860wp3 was in the state RESPONSE on channel 270
What could be the reason and how can I fix it?
This is happening in test environment where there is no load. It happens even on the first process instance after the ODE restart.
Strange thing is this does not happen always. It happens randomly. So I think this is not a problem in my process.
Another thing is, though it says the activity is registered for recovery (ActivityRecovery: Registering activity 159), it fails to recover when I try from the InstanceManagement recoverActivity() API.
Regards,
Jitendra