How can I diagnose the cause of a WCF Service Timeout?

Question

I am creating a C# windows service which communicates with a C# program using a NetNamedPipeBinding. The service works as follows.

1. User calls "Run" command on the service.
2. Service fires off a thread, which runs database queries.
3. User calls "GetStatus" on the service (about once per second).

Unfortunately, GetStatus frequently times out. These timeouts occur partway through running the service. These timeouts continue even after the thread in step 2 has finished running. 5 to 10 minutes later, the calls to GetStatus stop timing out.

How can I diagnose the cause of these timeouts?

---

Things I've tried:

1. Adding ServiceBehavior(UseSynchronizationContext = false) to DataSenderService.
2. Adding ServiceBehavior(ConcurrencyMode = ConcurrencyMode.Multiple) to DataSenderService.
3. Attaching the debugger to the service (during timeouts, the GetStatus call is never entered).
4. Verifying that the ServiceHost.State is set to CommunicationState.Opened during the timeouts.

---

Code snippets and exception data:

public partial class DataSenderService : ServiceBase
{
    private ServiceHost _host;
    protected override void OnStart(string[] args)
    {
        _host = new ServiceHost(typeof(DataSender), new Uri("net.pipe://localhost"));
        NetNamedPipeBinding pipeBinding = new NetNamedPipeBinding();
        pipeBinding.Security.Mode=NetNamedPipeSecurityMode.None;
        _host.AddServiceEndpoint(typeof(IDataSender), pipeBinding, "MyPipeXA");
        _host.Open();
    }
    //More stuff...
}

-

public class DataSender : IDataSender
{
    private static WorkerObject MyWorkerObject { get; set; }
    public string GetStatus()
    {
        WorkerObject req = MyWorkerObject;
        return req == null ? "NULL" : req.TaskState;
    }
    public void Run()
    {
        MyWorkerObject = new WorkerObject();
        //Start function uses delegate.BeginInvoke to 
        //execute a function which makes database queries.
        MyWorkerObject.Start();
    }
    //More Stuff...
}

-

//Client
void Main()
{
    var pipeBinding = new NetNamedPipeBinding();
    pipeBinding.MaxReceivedMessageSize = 5000000;
    pipeBinding.ReaderQuotas.MaxArrayLength = 5000000;
    pipeBinding.Security.Mode = NetNamedPipeSecurityMode.None;
    var pipeFactory = new ChannelFactory<IDataSender>(pipeBinding,new EndpointAddress("net.pipe://localhost/MyPipeXA"));
    IDataSender pipeProxy = pipeFactory.CreateChannel();
    pipeProxy.Run();        

    //We call this about once per second.
    //Eventually it starts triggering timeouts
    Console.WriteLine(pipeProxy.GetStatus());
}

-

TimeoutException:
    Message: The open operation did not complete within the allotted timeout of 00:01:00. The time allotted to this operation may have been a portion of a longer timeout.
    InnerException: TimeoutException
        Message: The read from the pipe did not complete within the allotted timeout of 00:01:00. The time allotted to this operation may have been a portion of a longer timeout.
        StackTrace:
            at System.ServiceModel.Channels.PipeConnection.WaitForSyncRead(TimeSpan timeout, Boolean traceExceptionsAsErrors)
            at System.ServiceModel.Channels.PipeConnection.Read(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout)
            at System.ServiceModel.Channels.DelegatingConnection.Read(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout)
            at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.SendPreamble(IConnection connection, ArraySegment`1 preamble, TimeoutHelper& timeoutHelper)
            at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.DuplexConnectionPoolHelper.AcceptPooledConnection(IConnection connection, TimeoutHelper& timeoutHelper)
            at System.ServiceModel.Channels.ConnectionPoolHelper.EstablishConnection(TimeSpan timeout)
            at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.OnOpen(TimeSpan timeout)
    StackTrace:
        Server stack trace: 
           at System.ServiceModel.Channels.ClientFramingDuplexSessionChannel.OnOpen(TimeSpan timeout)
           at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout)
           at System.ServiceModel.Channels.ServiceChannel.OnOpen(TimeSpan timeout)
           at System.ServiceModel.Channels.CommunicationObject.Open(TimeSpan timeout)
           at System.ServiceModel.Channels.ServiceChannel.CallOpenOnce.System.ServiceModel.Channels.ServiceChannel.ICallOnce.Call(ServiceChannel channel, TimeSpan timeout)
           at System.ServiceModel.Channels.ServiceChannel.CallOnceManager.CallOnce(TimeSpan timeout, CallOnceManager cascade)
           at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
           at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
           at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)
        Exception rethrown at [0]: 
           at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
           at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)     

Answer 1

You may want to consider enabling WCF Tracing and Logging, so you can:

review the WCF service startup configuration

evaluate the error trace activities

The following link provides a comprehensive overview:
http://msdn.microsoft.com/en-us/library/ms733025(v=vs.110).aspx