views:

1687

answers:

6

Analysing log files I've noticed that ~1% of service calls ended with TimeoutException on the Silverlight client side. The services (wcf) are quite simple and do not perform long computations. According the log all calls to the services are always processed in less that 1 sec (even when TimeoutException is occurred on the client!), so it is not server timeout.

So what is wrong? Can it be configuration or network problem? How can I avoid it? What additional logging information can be helpful for localizing this issue?

The only one workaround I've thought up is to retry service calls after timeout.

I will appreciate any help on this issue!

Update: On startup the application performs 17 service calls and 12 of them simultaneously (may it be cause of failure?).

Update: WCF log has not contained useful information about this issue. It seems some service calls do not reach the server side.

A: 

Mmmm... can it be possible that the request / response takes more than 64 K's or too much objects serialized?

Can you try to make a simulation hiting the server with a console application (just to check if it's network, SL...)?

Good luck Braulio

Braulio
"can it be possible that the request / response takes more than 64 K's or too much objects serialized"No, I think. Service responses are quite simple and less than 64Kb."Can you try to make a simulation hiting the server with a console application (just to check if it's network, SL...)?"Thanks for advice! It is not easy in our environment but I will try.
Alexander K.
A: 

Are you still having this problem?

If so, then perhaps you should watch the network with Fiddler or Microsoft Network Monitor or something?

John Saunders
Thank you for answer! Fiddler is a great tool :)I've found a solution for this issue and will post it here soon.
Alexander K.
+3  A: 

The problem is in maximum number of concurrent connections to a single server in Internet Explorer 7/6. It is only 2! http://msdn.microsoft.com/en-us/library/cc304129(VS.85).aspx

If we have 3 (for ex.) concurrent service calls two of them will be sent to server immediately but the third will be waiting in queue. Also the send timer (corresponded to sendTimeout) is running when request is in queue. If the first two service requests will be running for a long time then the third will generate TimeoutException though it wasn't sent to the server (and we won't see any information about this request on the server side and cannot catch it with Fiddler...).

In more real situation if we have about 12 concurrent calls and default 1 min send timeout and if service calls process more than 10 seconds in average than we can easily get timeout exception with the last two calls (12 / 2 * 10 sec = 60 sec) because they will wait all others.

The solution is:

  1. Minimize number of concurrent service calls.
  2. Increase sendTimeout value in client config.
  3. Implement auto retry feature for critical services.
  4. Implement queue of requests to manage them.

In my case I've done 1-3 things and that was enough.

Here is my implementation of auto retry feature:

public static class ClientBaseExtender
{
    /// <summary>
    /// Tries to execute async service call. If <see cref="TimeoutException"/> occured retries again.
    /// </summary>
    /// <typeparam name="TChannel">ServiceClient class.</typeparam>
    /// <typeparam name="TArgs">Type of service client method return argument.</typeparam>
    /// <param name="client">ServiceClient instance.</param>
    /// <param name="tryExecute">Delegate that execute starting of service call.</param>
    /// <param name="onCompletedSubcribe">Delegate that subcribes an event handler to the OnCompleted event of the service client method.</param>
    /// <param name="onCompleted">Delegate that executes when service call is succeeded.</param>
    /// <param name="onError">Delegate that executes when service call fails.</param>
    /// <param name="maxAttempts">Maximum attempts to execute service call before error if <see cref="TimeoutException"/> occured (by default 5).</param>
    public static void ExecuteAsyncRepeatedly<TChannel, TArgs>(this ClientBase<TChannel> client, Action tryExecute,
                                                               Action<EventHandler<TArgs>> onCompletedSubcribe, EventHandler<TArgs> onCompleted,
                                                               EventHandler<TArgs> onError, int maxAttempts)
        where TChannel : class
        where TArgs : AsyncCompletedEventArgs
    {
        int attempts = 0;
        var serviceName = client.GetType().Name;

        onCompletedSubcribe((s, e) =>
                                {
                                    if (e.Error == null) // Everything is OK
                                    {
                                        if (onCompleted != null)
                                            onCompleted(s, e);

                                        ((ICommunicationObject)client).Close();
                                        Debug.WriteLine("[{1}] Service '{0}' closed.", serviceName, DateTime.Now);
                                    }
                                    else if (e.Error is TimeoutException)
                                    {
                                        attempts++;

                                        if (attempts >= maxAttempts) // Final timeout after n attempts
                                        {
                                            Debug.WriteLine("[{2}], Final Timeout occured in '{0}' service after {1} attempts.", serviceName, attempts, DateTime.Now);

                                            if (onError != null)
                                                onError(s, e);
                                            client.Abort();

                                            Debug.WriteLine("[{1}] Service '{0}' aborted.", serviceName, DateTime.Now);
                                            return;
                                        }

                                        // Local timeout
                                        Debug.WriteLine("[{2}] Timeout occured in '{0}' service (attempt #{1}).", serviceName, attempts, DateTime.Now);

                                        Debug.WriteLine("[{2}] Attempt #{0} to execute call to '{1}' service.", attempts + 1, serviceName, DateTime.Now);
                                        tryExecute(); // Try again.
                                    }
                                    else
                                    {
                                        if (onError != null)
                                            onError(s, e);
                                        client.Abort();
                                        Debug.WriteLine("[{1}] Service '{0}' aborted.", serviceName, DateTime.Now);
                                    }
                                });

        Debug.WriteLine("[{2}] Attempt #{0} to execute call to '{1}' service.", attempts + 1, serviceName, DateTime.Now);
        tryExecute(); // First attempt to execute
    }
}

And here is a usage:

var client = new MyServiceClient();
client.ExecuteAsyncRepeatedly(() => client.MyOperationAsync(...),
    (EventHandler<MyOperationCompletedEventArgs> handler) => client.MyOperationCompleted += handler,
    (s, e) => // OnCompleted
        {
            Do(e.Result);
        },
    (s, e) => // OnError
        {
            HandleError(e.Error);
        }
);

Hope this will be helpful.

Alexander K.
A: 

Hi Alexander,

Could you post your solution to the issue?

Thanks!

It marked as accepted answer in this thread.
Alexander K.
A: 

Alexander,

Have you had any issues with your auto retry that you've come across? This catching or service call timeouts could really help me out with some issues but I wanted to see if you ran into any problems from its implementation. Thanks, really useful!

Jeff Zickgraf
No, it has been working perfectly in production environment for more than year.
Alexander K.
A: 

Hi! I have a confusion here.. How have you used ClientBaseExtender ? Does your proxy derive from ClientBaseExtender? But the proxy class is already derived from System.ServiceModel.ClientBase. So how do you plug-in ClientBaseExtender with MyServiceClient??

Ami
No, ClientBaseExtender provides the extension method (http://msdn.microsoft.com/en-us/library/bb383977.aspx) for ClientBase. So you can use this method in any inheritors of ClientBase.
Alexander K.