15

In my ASP.NET MVC4 application I have a controller action in which I go out to several external websites and collect information which I show on my page in an aggregated way. Obviously, I want to do this in parallel, so I have written my code similar to this:

var client1 = new HttpClient().GetAsync("http://google.com");
var client2 = new HttpClient().GetAsync("http://stackoverflow.com");
var client3 = new HttpClient().GetAsync("http://twitter.com");

var result1 = client1.Result;
var result2 = client2.Result;
var result3 = client3.Result;

How can I find out how long each request took to finish, so that I can display that information on my page?

Daniel Lang
  • 6,819
  • 4
  • 28
  • 54

2 Answers2

20

I would probably try something like the following:

private async void _HttpServerDemo()
{
    var info1 = _GetHttpWithTimingInfo("http://google.com");
    var info2 = _GetHttpWithTimingInfo("http://stackoverflow.com");
    var info3 = _GetHttpWithTimingInfo("http://twitter.com");

    await Task.WhenAll(info1, info2, info3);
    Console.WriteLine("Request1 took {0}", info1.Result);
    Console.WriteLine("Request2 took {0}", info2.Result);
    Console.WriteLine("Request3 took {0}", info3.Result);
}

private async Task<Tuple<HttpResponseMessage, TimeSpan>> _GetHttpWithTimingInfo(string url)
{
    var stopWatch = Stopwatch.StartNew();
    using (var client = new HttpClient())
    {
        var result = await client.GetAsync(url);
        return new Tuple<HttpResponseMessage, TimeSpan>(result, stopWatch.Elapsed);
    }
}
ollifant
  • 8,576
  • 10
  • 35
  • 45
  • 1
    Why are your method names starting with `_`? I haven't seen such naming convention in C#, even for `private` methods. – svick Jan 06 '13 at 13:20
  • @swick: I am working heavily in framework development and this is a nice way to quickly see if something is private or public. Yet this is not always needed, for further info see http://stackoverflow.com/questions/383850/private-method-naming-convention – ollifant Jan 06 '13 at 15:12
  • 2
    Well, the consensus in answers to that question seem to be *not* to use underscore for private methods. – svick Jan 06 '13 at 15:17
  • 2
    This might lead to wrong results. If there are no thread ready (or the context is in use elsewhere) the await will not continue for a while - leading to the returned timespan being higher than the response time. – Ykok Apr 26 '17 at 15:25
  • 2
    I used to use this method. It fails dramatically if you start 20+ parallel requests. A single thread may wait up to a second (!!!) before given a chance to stop a timer. To be fair, I still do not know a better way... – Dmytro Bogatov Jun 16 '17 at 13:23
  • I read somewhere that `HttpClient` should not be used with `using` despite implementing `IDisposable`. `HttpClient` is threadsafe by design, so it should be reused in a concurrent context. _HttpClient is intended to be instantiated once and reused throughout the life of an application_ https://learn.microsoft.com/en-us/aspnet/web-api/overview/advanced/calling-a-web-api-from-a-net-client – Jeppe Sep 19 '21 at 13:04
  • How can this work? If you await each GetAsync(), what actually happens is that each request is awaited before returning. So the task would not run in parallel. And the returned Task is really a not-started task that does not run. Actually tried the code. It's not working. – Luc Nov 02 '21 at 22:23
2

There is now one option in .NET Core which might give you better results, at least in my case the elapsed time is lower around 10-40% than using the method suggested by @ollifant. I would stay with his suggestion but moved the Stopwatch to the handler.

You can use DelegatingHandler, example .NET Core Docs.

You can still use Stopwatch as suggested above but rather in the handler itself. I add elapsed time to the Header which I retreive then in e.g your _GetHttpWithTimingInfo and process further. Most likely you could DI some services and save the duration to the database from the handler itself, depends on your project..

Maybe, this solution might also resolve problem mentioned by @Dmytro Bogatov.

Also, this method is used directly in .NET Core HTTP logging check SendAsync. Note they are using internal ValueStopwatch instead Stopwatch.

These logs are showing using Stopwatch in the Handler vs directly in the method:

08-11-2020 18:05:52.024 [INF] Handler: 992, _GetHttpWithTimingInfo 995
08-11-2020 18:05:52.153 [INF] Handler: 663, _GetHttpWithTimingInfo 1249
08-11-2020 18:05:52.208 [INF] Handler: 999, _GetHttpWithTimingInfo 1220
08-11-2020 18:05:52.219 [INF] Handler: 1002, _GetHttpWithTimingInfo 1241
08-11-2020 18:05:52.219 [INF] Handler: 989, _GetHttpWithTimingInfo 1217
08-11-2020 18:05:52.255 [INF] Handler: 609, _GetHttpWithTimingInfo 1302
08-11-2020 18:05:52.260 [INF] Handler: 959, _GetHttpWithTimingInfo 1267
08-11-2020 18:05:52.287 [INF] Handler: 1063, _GetHttpWithTimingInfo 1303
08-11-2020 18:05:52.292 [INF] Handler: 515, _GetHttpWithTimingInfo 1381
08-11-2020 18:05:52.296 [INF] Handler: 992, _GetHttpWithTimingInfo 1286
08-11-2020 18:05:52.321 [INF] Handler: 953, _GetHttpWithTimingInfo 1323
08-11-2020 18:05:52.324 [INF] Handler: 973, _GetHttpWithTimingInfo 1304
08-11-2020 18:05:52.326 [INF] Handler: 985, _GetHttpWithTimingInfo 1302
Vaclav Elias
  • 4,101
  • 2
  • 24
  • 28