title: Timeout Exception - Queuing of Requests? Not enough threads?
body: <p><strong>Background:</strong></p>
  
  <p>I have a service which aggregates data from multiple other services.  To make things happen in a timely manner I use async throughout the code, and then gather the various requests into a list of tasks.</p>
  
  <p>Here is some excerpts from the code:</p>
  
  <pre><code>private async Task&lt;List&lt;Foo&gt;&gt; Baz(..., int timeout)
  {
      var tasks = new List&lt;Task&lt;IEnumerable&lt;Foo&gt;&gt;&gt;();
      Tasks.Add(GetFoo1(..., timeout));
      Tasks.Add(GetFoo2(..., timeout));
      // Up to 6, depending on other parameters.  Some tasks return multiple objects.
  
      return await Task.WhenAll(tasks).ContinueWith((antecedent) =&gt; { return antecedent.Result.AsEnumerable().SelectMany(f =&gt; f).ToList(); }).ConfigureAwait(false);
  }    
  private async Task&lt;IEnumerable&lt;Foo&gt;&gt; GetFoo1(..., int timeout)
  {
  Stopwatch sw = new Stopwatch();
  sw.Start();
  
      var value = await SomeAsyncronousService.GetAsync(..., timeout).ConfigureAwait(false);
  
  sw.Stop();
  // Record timing...
      return new[] { new Foo(..., value) };
  }
  private async Task&lt;IEnumerable&lt;Foo&gt;&gt; GetFoo2(..., int timeout)
  {
  return await Task.Run(() =&gt; {
      Stopwatch sw = new Stopwatch();
      sw.Start();
      var r = new[] { new Foo(..., SomeSyncronousService.Get(..., timeout)) };
      sw.Start();
      sw.Stop();
      // Record timing...
      return r;
  }).ConfigureAwait(false);
  }  
  
  // In class SomeAsyncronousService
  public async Task&lt;string&gt; GetAsync(..., int timeout)
  {
  ...
      try
      {
          using (var httpClient = HttpClientFactory.Create())
          {
              // I have tried it with both timeout and CTS.  The behavior is the same.
              //httpClient.Timeout = TimeSpan.FromMilliseconds(timeout);
              var cts = new CancellationTokenSource();
              cts.CancelAfter(timeout);
  
              var content = ...;
              var responseMessage = await httpClient.PostAsync(Endpoint, content, cts.Token).ConfigureAwait(false);
              if (responseMessage.IsSuccessStatusCode)
              {
                  var contentData = await responseMessage.Content.ReadAsStringAsync().ConfigureAwait(false);
                  ...
                  return ...
              }
              ...             
          }
      }
      catch (OperationCanceledException ex)
      {
          // Log statement ...
      }
      catch (Exception ex)
      {
          // Log statement ...
      }
      return ...;
  }
  </code></pre>
  
  <p><strong>The Symptoms:</strong></p>
  
  <p>This code works great on my local machine, and it works fine on our test servers most of the time.  However, occasionally we get a bunch of mass recorded timeouts - recorded by the "Record timing" comments above and the Log statements on OperationCanceledExceptions.  I do not have any way of telling if the services I call actually timed out.</p>
  
  <p>Now, when I say a series of timeouts I mean that most or all of the tasks (and the HttpClients that all but one use, the other uses a WCF service) all timeout at about the same time.</p>
  
  <p>Now, I know what you are thinking, I am passing in the same timeout.  Thats right, but I pass in 250 ms and the run time that is being reported by the various stop watches are around 800 ms or higher.</p>
  
  <p>Now, I do see the OperationCanceledExceptions in the log, but the time stamp of the exception is the same as the time stamp of when the stopwatch ended (or within 2-3 ms) and my service is failing because clients are expecting it to respond in 500 ms or less, not 800 ms.</p>
  
  <p>Now, normally the various services respond in less than 100 ms, with a wide variance among the results.  When we a problem occurs, and most / all return in 800 ms or more, they vary  only by ~10 ms.  The dependencies I call are all on different domains.  It seems highly unlikely that all of them are really taking that long to respond, all at the same time.</p>
  
  <p>I suppose there could be a network issue, affecting all requests at the same time, but the other services in our network do not experience the same behavior - it is limited to the new service I am writing.</p>
  
  <p>Even if that was the case, I would expect the cancellation exceptions to occur after 250 ms, then for the task to end and the stopwatch to record 250 (plus 5-20ms or so for exception handling).</p>
  
  <p>So I do not think that it is a network issue.  Now I am sure that at least part of the problem is related to me not cancelling / timing out correctly, but it seem to me that all of the out going requests from the service are being affected at the same time independent of HttpClient.</p>
  
  <p>The reason I say that is because the WCF service also shows 800+ ms (according to the stopwatch) when the rest of the requests timeout.  The WCF service is not asynchronous.  The timeout is set like this:</p>
  
  <pre><code>var binding = new BasicHttpBinding()
  {
      Security = new BasicHttpSecurity()
      {
          Mode = BasicHttpSecurityMode.TransportCredentialOnly,
          Transport = new HttpTransportSecurity()
          {
              ClientCredentialType = HttpClientCredentialType.Ntlm
          }
  
      },
      ReceiveTimeout = TimeSpan.FromMilliseconds(timeout)
  };
  </code></pre>
  
  <p><strong>The Problem:</strong></p>
  
  <p>So, in short I think that something is causing all outgoing requests to any domain to pause or queue which is causing the observed behavior.</p>
  
  <p>I have spent days trying to figure out what is going on, but have had no luck.  Any ideas?</p>
  
  <p><strong>EDIT</strong></p>
  
  <p>I think what is happening is that the requests are being put put on hold because there isn't a thread available, and then a few hundred milliseconds later a thread is available and the task starts.  Timing the  method call shows that it is taking 800 ms, but the timeout on the HttpClient doesn't start until a thread is available to run the async call.</p>
  
  <p>It would also explain why I see that the method takes 800+ ms, but sometimes it still completes without showing a timeout exception.  Other times it does throw a timeout exception and does not complete.</p>
  
  <p>I have tried setting the ServicePointManager.DefaultConnectionLimit to 200 in Application_Start, but that did not solve the issue.</p>
  
  <p>The service isn't taking that much traffic compared to our other services, and none of the others appear to have the same problem.</p>
  
  <p>Any ideas?</p>
  
  <p><strong>Edit 2</strong></p>
  
  <p>I logged into the box and monitored netstat while doing (minor) load tests.</p>
  
  <p>Using HttpClient, with 1-2 requests per second the ports would show ESTABLISHED, then move to TIME_WAIT for about 4 minutes.  With 3+ requests per second I would end up with about a constant 100 x requests per second ESTABLISHED ports (so 300 for a 3 per second load test), and then I would start seeing them go to CLOSE_WAIT instead of TIME_WAIT - indicating an error condition on close.  At the same time I would see the spike in the number of exceptions and time to execute the requests. (TcpTimedWaitDelay does not apply to CLOSE_WAIT).</p>
  
  <p>So I rewrote the whole thing to use HttpWebRequests in serial, instead of HttpClient in parallel.  Then I ran the same tests.</p>
  
  <p>Now the ESTABLISHED ports equal 0-2 x requests per second, and the ports then move on to TIME_CLOSE as expected.  The performance and throughput improved, but didn't clear up completely.</p>
  
  <p>Then I set TcpTimedWaitDelay to 30 (default 240).  The performance has increased dramatically.  I have a primitive load test that hits it with 40 requests per second without any issues.  I will get a more thorough test setup but I think the problem has been solved.</p>
  
  <p>I don't know what is going on, but it appears that the HttpClient was not closing the ephemoral ports correctly underneath.  Many of the developers and architects at my company looked at it and couldn't not see anything wrong with the code.  I tried having a single HttpClient in a using statement per request, as well as having a single HttpClient per api I call on the back end.  I have tried using HttpClient in parallel and serial.  I have tried it with async/await and without.  No matter what I tried the behavior was the same.</p>
  
  <p>I would like to be able to use HttpClient, but I can't spend anymore time on this issue as I have it working with HttpWebRequest.  My next step is to make the HttpWebRequests occur in Parallel.</p>
  
  <p>Thank you for your input.</p>