Problem with asynchronous HttpClient methods

Recently, I wrote a client application which should send some log messages to a server. Since it was only for statistics, the log didn’t have the highest requirements on reliability. Additionally, it shouldn’t block my application. Therefore I decided to send the message asynchronously, and in case of an error only to write something to the local log file. I came up with

static void LogMessage(string message)
{
  Uri baseAddress = new Uri("http://localhost/");
  string requestUri = "uri";

  using (HttpClient client = new HttpClient { BaseAddress = baseAddress })
  {
    client.PostAsJsonAsync(requestUri, message, cancellationToken).ContinueWith(task =>
      {
        if (task.IsFaulted)
          Console.WriteLine(“Failed: “ + task.Exception);
        else if (task.IsCanceled)
          Console.WriteLine ("Canceled");
        else
        {
          HttpResponseMessage response = task.Result;
          if (response.IsSuccessStatusCode)
            Console.WriteLine("Succeeded");
          else
            response.Content.ReadAsStringAsync().ContinueWith(task2 => Console.WriteLine(“Failed with status " + response.StatusCode));
        }
      });
  }
}

This code should send the message asynchronously (PostAsJsonAsync). And afterwards it should check, if the sending was successfully or not (ContinueWith). My expectation was to see an error, since there is nothing is listening on the specified address. But I didn’t see anything. Moreover, it even didn’t send any requests. Even for my requirements, this was not enough.

After some research, I added trace switches to my config file:

<system.diagnostics>
  <switches>
    <add name="System.Net" value="Verbose"/>
    <add name="System.Net.Http" value="Verbose"/>
    <add name="System.Net.HttpListener" value="Verbose"/>
    <add name="System.Net.Sockets" value="Verbose"/>
    <add name="System.Net.Cache" value="Verbose"/>
  </switches>
</system.diagnostics>

With it, one of the last lines of my debug output was

System.Net Error: 0 : [0864] Exception in HttpWebRequest#54246671:: - The request was aborted: The request was canceled..

This led me to the evil: it was the disposing of HttpClient too early. At the end of the using block the client will be disposed. But at this time, the message has not been sent. This happens, since I do something asynchronous inside the using block without waiting for its end.

The solution to this problem is to reverse the order of using and asynchronous: if I start the using in an asynchronous way, everything is fine:

static void LogMessage(string message)
{
  Uri baseAddress = new Uri("http://localhost/");
  string requestUri = "uri";

  new TaskFactory().StartNew(() =>
    {
      using (HttpClient client = new HttpClient { BaseAddress = baseAddress })
      {
        Console.WriteLine("Sending message");
        HttpResponseMessage response = client.PostAsJsonAsync(requestUri, message).Result;

        Console.WriteLine("Evaluating response");
        if (response.IsSuccessStatusCode)
          Console.WriteLine("Succeeded");
        else
          Console.WriteLine("Failed with status " + response.StatusCode);
      }
    });
}

Here I start a new task, which does inside the using / Dispose stuff. And the task is finished only after the Dispose.

This took me to the next stage: what about the async / await pattern from .net 4.5? The implementation is quite similar to the one above - the main difference is that the method now has to return a Task.

static async Task LogMessage (string message)
{
  Uri baseAddress = new Uri("http://localhost/");
  string requestUri = "uri";

  using (HttpClient client = new HttpClient { BaseAddress = baseAddress })
  {
    Console.WriteLine("Sending message");
    HttpResponseMessage response = await client.PostAsJsonAsync(requestUri, message);

    Console.WriteLine("Evaluating response");
    if (response.IsSuccessStatusCode)
      Console.WriteLine("Succeeded");
    else
      Console.WriteLine("Failed with status " + response.StatusCode);
  }
}

Also this implementation starts a new thread for the response message handling. But it does it only if really needed. And it does it as late as possible.

A little more sophisticated logging shows some details (the 2nd column is the thread number). The implementation with an explicit Task calls LogMessage on the main thread 9. Afterwards in continues immediately on the same thread. Approx. 20 ms later the new thread 12 starts with the HTTP handling:

21:28:42.524    9       CallMethod      Calling LogMessageWithTask
21:28:42.526    9       CallMethod      Continuing after LogMessageWithTask
21:28:42.545    12      LogMessageWithTask      Sending message
21:28:45.682    12      LogMessageWithTask      Evaluating response
21:28:45.682    12      LogMessageWithTask      Failed with status NotFound

With async / await it is a little bit different: also the request will be sent on the main thread. The response handling will be done later also in a second thread:

21:28:51.638    9       CallMethod      Calling LogMessageAsyncAwait
21:28:51.666    9       LogMessageAsyncAwait    Sending message
21:28:51.701    9       CallMethod      Continuing after LogMessageAsyncAwait
21:28:52.144    16      LogMessageAsyncAwait    Evaluating response
21:28:52.144    16      LogMessageAsyncAwait    Failed with status NotFound

However, the coding is more precise. And the request will be sent without the delay for creating the new Task.

---

You can find the source code at GitHub: https://github.com/Ritzlgrmft/HttpClientDispose.