Article
· Jun 23, 2016 7m read

Web Service Business Operation Client – Response Timeout Behavior

When calling out to web services there are several settings of the Business Operation that play together in controlling what will happen when a response is not returned in the desired time.(Note this is relevant also for example for a non-SOAP simple HTTP call)

 

The 3 main settings involved are:

  • Response Timeout

Specifies the timeout for getting a response from the remote web server.

  • Retry Interval

Number of seconds to wait between attempts to connect with a destination outside Ensemble.

  • Failure Timeout

Total number of seconds to keep trying to connect with a destination outside Ensemble. After this number of seconds has elapsed, the business operation discards the message data and returns an error code. 

 

Put together in words these play together as follows –

We will wait for a response from the Web Server for 'Response Timeout' seconds. If no response has been received by that time, we will call the Web Server again after 'Retry Interval' seconds have elapsed. We will continue attempting this 'Failure Timeout' seconds have gone by since the first attempt started.

 

To illustrate let's take the following example –

 

Assume the following settings:

 

In words –

Response Timeout - Waiting for 7 seconds for response

Retry Interval - Retrying every 10 sec.

Failure Timeout – "Give up" retrying after 30 seconds

 

So assuming the Response comes back after exactly 8 sec. then the following scenario will take place –

  1. At 00:00 we will make the first call
  2. At 00:07 since no response is returned we will acknowledge internally that a "Response Timeout" error has occurred [and log an "Error event" in the Event Log], and will attempt again according to the retry policy and settings – the "Failure Timeout" has not arrived yet, so a "Need to Retry flag" is raised.
  3. [At 00:08 the Web Server will return a response but this response will not be received by us since we've already errored with a timeout]
  4. At 00:10 the Retry Interval has arrived and since the "Need to retry flag" is raised we will call the Web Server again.
  5. At 00:17 we will again have arrived at our "Response Timeout" with no response (note as mentioned before the response sent back at 00:08/step #3 is "ignored/discarded"), so again we will internally denote this as an error (though this time will not add another Event log Error entry, only the first attempt will create this, not every retry failure), and since we have not reached the "Failure Timeout" yet, have "Need to Retry flag" up yet again.
  6. [At 00:18 the Web Server will return a response which again will not be received by us]
  7. At 00:20 another retry interval elapses and we will call again for our 3rd attempt.
  8. At 00:27, no response, again "Response Timeout" error and need to Retry (not reached "Failure Timeout" yet).
  9. [At 00:28 a non-received response is sent by server]
  10. At 00:30 another Retry Interval comes along and we make our 4th (and last) attempt.
  11. At 00:37 a "Response Timeout" occurs again – this time the "Failure Timeout" has passed so we do not raise the "Need to Retry flag" but rather give up – we log an Error event in the Event Log noting the Failure timeout has elapsed, and also return an error from the Business Operation to the calling item.

 

The following is some "evidence" from a sample call per the scenario above.

 

First the server side [From the SOAP log] – you can see it received 4 calls/requests, 10 seconds apart, each time returning a response after 8 seconds from the request –


05/31/2016 14:18:45 *********************
Input to Web service with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
<SOAP-ENV:Envelope xmlns:SOAP-ENV='http://schemas.xmlsoap.org/soap/envelope/'
...
</SOAP-ENV:Envelope>

 

05/31/2016 14:18:53 *********************
Output from Web service with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>

 

05/31/2016 14:18:55 *********************
Input to Web service with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>

 

05/31/2016 14:19:03 *********************
Output from Web service with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>

 

05/31/2016 14:19:05 *********************
Input to Web service with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>

 

05/31/2016 14:19:13 *********************
Output from Web service with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>

 

05/31/2016 14:19:15 *********************
Input to Web service with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>

 

05/31/2016 14:19:23 *********************
Output from Web service with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>

 

And now from the Ensemble BO/client side, you can see 4 attempts, 10 seconds apart, each time logging a response timeout error 7 seconds after.

 

Client side

 

05/31/2016 14:18:45 *********************
Output from Web client with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>
 
05/31/2016 14:18:52 *********************
Input to Web client with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
ERROR #5922: Timed out waiting for response
string**** SOAP client return error. method=GetResponse, action=http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
     ERROR #5922: Timed out waiting for response
 
05/31/2016 14:18:55 *********************
Output from Web client with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>
 
05/31/2016 14:19:02 *********************
Input to Web client with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
ERROR #5922: Timed out waiting for response
string**** SOAP client return error. method=GetResponse, action=http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
     ERROR #5922: Timed out waiting for response
 
05/31/2016 14:19:05 *********************
Output from Web client with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>
 
05/31/2016 14:19:12 *********************
Input to Web client with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
ERROR #5922: Timed out waiting for response
string**** SOAP client return error. method=GetResponse, action=http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
     ERROR #5922: Timed out waiting for response
 
05/31/2016 14:19:15 *********************
Output from Web client with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
<?xml version="1.0" encoding="UTF-8" ?>
...
</SOAP-ENV:Envelope>
 
05/31/2016 14:19:22 *********************
Input to Web client with SOAP action = http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
ERROR #5922: Timed out waiting for response
string**** SOAP client return error. method=GetResponse, action=http://tempuri.org/Test.WSTimeouts.WebService.GetResponse
     ERROR #5922: Timed out waiting for response

 

Here is the Ensemble Visual Trace:

And here the Event log entries –

 

Sample Event Log with Trace Events on [You might need to zoom-in to read the text in the image better] –

Here you can observe some of the "inner workings" of the above described scenario –

At Log ID #684 the initial call is made – at 17:09:16.

Then 7 seconds later (09:23) we get the response timeout error (#685). The operation then logs the error (#687) and decides to wait for another 3 seconds until the retry interval; 10sec retry interval minus 7sec response timeout (#688-#690).

After the 3 second wait elapses (at 09:26; #691) the 2nd attempt is made (#692), with the same result and the same subsequent behavior, until the 4th try (#704). After the 4th try fails (09:53; #705) another attempt is not made since the failure timeout (30sec) has exceeded.

Discussion (4)5
Log in or sign up to continue

Hello Tani,

Thanks for sharing this useful information.

I have the feeling that Intersystems could somehow improve the tool in terms of validating and not allowing timeouts overlapping each other, if you understand what I'm saying.

It is a very common mistake people make when configuring these timeouts and sometimes they end up not enjoying the real benefits they can offer.

I am now very confused while trying to put in context what you described in your article (related to webservices) along with the TCP connection world, because it has got, additionally to the timeouts you've mentioned:

Stay Connected
Connect Timeout
Reconnect Retry
Read Timeout

For example, the reconnect retry sounds very close to the purpose of the Retry Interval, so I am not too confident on how to set these guys up.

Are you able to give me a helping hand?

Thanks

Hello,

Thank you very mych for your very detail explanation of the Business Operation settings and how they work.

I would like to aks if you could help me with a question regarding these settings.

I have in my Busioness Operation settings the following values:

* Response timeout: 30 seconds

* Retry interval: 5 seconds

*Failure Timeout: 15

When I get a timeout error I also get a FailureTimeout error.

I have configured the BusinessOperation to send me emails when an error occurs. This implies that I received two emails of alerts but in reality only one error has been received.
Is there a way to avoid FailureTimeout error? I am not retrying because FailureTimeout setting value is 15 and ResponseTimeout setting value is 30, so I think I should not get that error
 

I hope you could help me.

Thank you very much.

Hello Carlos,

These settings are a tad confusing because if not set up properly, can cause overlapping and, in my opinion, this is something the management portal should be able to validate and raise the error on the UI side.

In your case, the failure timeout is throwing this due to the fact that its value is lower than the Response Timeout and it shouldn't. 

Practically speaking: the operation will give up retrying after 15s. If the Response timeout is 30s, 15s has gone already (Failure Timeout triggers before the response comes), so logically you need a value here at least greater (double the Response timeout may be ideal).

This is the reason why you probably get the message saying that the Failure timeout exceeded. Furthermore, this should be combined along with the Retry interval, otherwise it will overlap its functioning.