HttpClient ignoring timeout policy when downloading files

[dgoldm]

Summary:

When configuring a timeout for HttpClient with AddPolicyHandler, then using the HttpClient to download a file, the policy is ignored.

Expected behavior:

1. With a large download that normally takes n>100 seconds and setting a long timeout x>n seconds, the download should succeed.
2. With a smaller download that normally takes n<100 seconds, and setting a short timeout x<n seconds, the request should fail, throwing a Timeout or TaskCanceled exception after x seconds.

Actual behavior:

1. The client throws a TaskCanceled exception after approx, 100 seconds (which is the default HttpClient timeout).
2. The download succeeds.

Code to reproduce the problem:

Program.cs

using Microsoft.Extensions.DependencyInjection;
using Polly;
using System;
using System.Diagnostics;
using System.Net.Http;
using System.Threading.Tasks;

namespace TimeoutTest
{
    class Program
    {
        static IHttpClientFactory factory;
        static int i = 0;

        static async Task Main(string[] args)
        {
            var services = new ServiceCollection();

            //setting timeout via policy
            services.AddHttpClient("p200")
                .AddPolicyHandler(Policy.TimeoutAsync<HttpResponseMessage>(TimeSpan.FromMilliseconds(200)));
            services.AddHttpClient("p2000")
                .AddPolicyHandler(Policy.TimeoutAsync<HttpResponseMessage>(TimeSpan.FromMilliseconds(2000)));
            services.AddHttpClient("p200_000")
                .AddPolicyHandler(Policy.TimeoutAsync<HttpResponseMessage>(TimeSpan.FromMilliseconds(200_000)));

            //setting timeout via config
            services.AddHttpClient("c200",
                config => config.Timeout = TimeSpan.FromMilliseconds(200));
            services.AddHttpClient("c2000",
                config => config.Timeout = TimeSpan.FromMilliseconds(2000));
            services.AddHttpClient("c200_000",
                config => config.Timeout = TimeSpan.FromMilliseconds(200_000));

            var serviceProvider = services.BuildServiceProvider();

            factory = serviceProvider.GetService<IHttpClientFactory>();

            Console.WriteLine("Using policy-based timeout:");
            await TestDownload("http://download.inspire.net.nz/data/200MB.zip", "p200_000");
            await TestDownload("http://download.inspire.net.nz/data/20MB.zip", "p2000");
            await TestDownload("http://download.inspire.net.nz/data/20MB.zip", "p200");

            Console.WriteLine("\nUsing config-based timeout:");
            await TestDownload("http://download.inspire.net.nz/data/200MB.zip", "c200_000");
            await TestDownload("http://download.inspire.net.nz/data/20MB.zip", "c2000");

            Console.WriteLine("\nUsing policy-based timeout for a long running request with a small response:");
            await TestDownload("http://httpbin.org/delay/5", "p2000");

        }
        static async Task TestDownload(string url, string clientName)
        {
            var watch = new Stopwatch();
            watch.Start();
            try
            {
                Console.WriteLine($"#{++i} Url: {url}, Timeout: {clientName.Substring(1)}ms");
                await factory.CreateClient(clientName).GetAsync(url).Result.Content.ReadAsByteArrayAsync();
                watch.Stop();
                Console.WriteLine($" Result: Success, Elapsed: {watch.ElapsedMilliseconds}ms");
            }
            catch (AggregateException ex) when (ex.InnerException is Polly.Timeout.TimeoutRejectedException)
            {
                Console.WriteLine($" Result: TimeoutRejected, Elapsed: {watch.ElapsedMilliseconds}ms");
            }
            catch (AggregateException ex) when (ex.InnerException is TaskCanceledException)
            {
                Console.WriteLine($" Result: TaskCanceled, Elapsed: {watch.ElapsedMilliseconds}ms");
            }
            catch (Exception ex)
            {
                Console.WriteLine(ex.ToString());
                throw;
            }
        }
    }
}

TimeoutTest.csproj

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>netcoreapp3.1</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Polly" Version="7.2.1" />
    <PackageReference Include="Microsoft.Extensions.Http" Version="3.1.5" />
    <PackageReference Include="Microsoft.Extensions.Http.Polly" Version="3.1.5" />
  </ItemGroup>

</Project>

Output:

Using policy-based timeout:
#1 Url: http://download.inspire.net.nz/data/512MB.zip, Timeout: 300_000ms
 Result: TaskCanceled, Elapsed: 100379ms
#2 Url: http://download.inspire.net.nz/data/20MB.zip, Timeout: 3000ms
 Result: Success, Elapsed: 11079ms

Using config-based timeout:
#3 Url: http://download.inspire.net.nz/data/512MB.zip, Timeout: 300_000ms
 Result: Success, Elapsed: 193739ms
#4 Url: http://download.inspire.net.nz/data/20MB.zip, Timeout: 3000ms
 Result: TaskCanceled, Elapsed: 3044ms

Using policy-based timeout for a long running request with a small response:
#5 Url: http://httpbin.org/delay/5, Timeout: 3000ms
 Result: TimeoutRejected, Elapsed: 3016ms

Using policy-based timeout with a very short timeout:
#6 Url: http://download.inspire.net.nz/data/20MB.zip, Timeout: 300ms
 Result: TimeoutRejected, Elapsed: 327ms

Remarks:
Attempts 1 & 2 demonstrate the unexpected behavior described above.
3 & 4 demonstrate how similar requests, using a config-based timeout, behave as expected.
5 & 6 are sanity checks that demonstrate cases where policy-based timeouts do behave as expected

Of course the actual download times may vary according to your internet speed, so you may have to download different sized files, and/or specify different timeout values in order to reproduce the problem.

[github-actions]

This issue is stale because it has been open for 60 days with no activity. It will be automatically closed in 14 days if no further updates are made.

[github-actions]

This issue was closed because it has been inactive for 14 days since being marked as stale.