c#asp.net dotnet-httpclient polly retry-logic

Handling TaskCanceledException when HttpClient times out

I'm trying to use Microsoft.Extensions.Http.Polly policy handler for retries when TaskCanceledException or http transient errors, but it's not working properly.

I wrote the minimal API below just for testing:

Program.cs

using Polly;
using Polly.Extensions.Http;
using Polly.Retry;

WebApplicationBuilder builder = WebApplication.CreateBuilder(args);

AsyncRetryPolicy<HttpResponseMessage>? policy = HttpPolicyExtensions.HandleTransientHttpError()
    .Or<TaskCanceledException>()
    .WaitAndRetryAsync(5, _ => TimeSpan.FromSeconds(5));

builder.Services.AddHttpClient("test", client =>
    {
        client.BaseAddress = new Uri("http://localhost:5000");
        client.Timeout = TimeSpan.FromSeconds(2);
    })
    .AddPolicyHandler(policy);

WebApplication app = builder.Build();

app.MapPost("/status/{code}",
    async (string code, IHttpClientFactory httpClientFactory, CancellationToken cancellationToken) =>
    {
        HttpClient client = httpClientFactory.CreateClient("test");
        HttpResponseMessage response = await client.GetAsync($"/status/{code}", cancellationToken);

        response.EnsureSuccessStatusCode();

        return response.Content.ReadAsStringAsync(cancellationToken);
    });

app.MapPost("/timeout/{timeout:int}",
    async (int timeout, IHttpClientFactory httpClientFactory, CancellationToken cancellationToken) =>
    {
        HttpClient client = httpClientFactory.CreateClient("test");
        HttpResponseMessage response = await client.GetAsync($"/timeout/{timeout}", cancellationToken);

        response.EnsureSuccessStatusCode();

        return response.Content.ReadAsStringAsync(cancellationToken);
    });

#region Simulated API

app.MapGet("/status/{code:int}", (int code) => Results.StatusCode(code));

app.MapGet("/timeout/{timeout:int}", async (int timeout) =>
{
    await Task.Delay(TimeSpan.FromSeconds(timeout));
    return Results.Ok();
});

#endregion

app.Run();

After calling POST http://localhost:5000/timeout/10 it raises this exception without any further attempts:

Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
An unhandled exception has occurred while executing the request.
System.Threading.Tasks.TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 2 seconds elapsing.
---> System.TimeoutException: A task was canceled.
---> System.Threading.Tasks.TaskCanceledException: A task was canceled.
 at Polly.Retry.AsyncRetryEngine.ImplementationAsync[TResult](Func`3 action, Context context, CancellationToken cancellationToken, ExceptionPredicates shouldRetryExceptionPredicates, ResultPredicates`1 shouldRetryResultPredicates, Func`5 onRetryAsync, Int32 permittedRetryCount, IEnumerable`1 sleepDurationsEnumerable, Func`4 sleepDurationProvider, Boolean continueOnCapturedContext)
 at Polly.AsyncPolicy`1.ExecuteAsync(Func`3 action, Context context, CancellationToken cancellationToken, Boolean continueOnCapturedContext)       
 at Microsoft.Extensions.Http.PolicyHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
 at Microsoft.Extensions.Http.Logging.LoggingScopeHttpMessageHandler.<>c__DisplayClass5_0.<<SendCoreAsync>g__Core|0>d.MoveNext()
--- End of stack trace from previous location ---
 at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
 --- End of inner exception stack trace ---
 --- End of inner exception stack trace ---
 at System.Net.Http.HttpClient.HandleFailure(Exception e, Boolean telemetryStarted, HttpResponseMessage response, CancellationTokenSource cts, CancellationToken cancellationToken, CancellationTokenSource pendingRequestsCts)
 at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
 at Program.<>c.<<<Main>$>b__0_3>d.MoveNext() in Z:\Repositories\POCs\PollyRetryTest\PollyRetryTest\Program.cs:line 35
--- End of stack trace from previous location ---
 at Microsoft.AspNetCore.Http.RequestDelegateFactory.<ExecuteTaskOfT>g__ExecuteAwaited|129_0[T](Task`1 task, HttpContext httpContext, JsonTypeInfo`1 jsonTypeInfo)
 at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddlewareImpl.Invoke(HttpContext context)

What am I doing wrong? Do I have to override the primary handler?

Solution

TL;DR: The HttpClient's Timeout works as a per-logical-request timeout (which covers all retry attempts) rather than as a per-transport-request (which covers a single attempt).

What we have:

You have a long running operation (10 seconds)
You have a retry policy with at most 5 retry attempts and 5 seconds delays between each attempt
You have a 2 seconds per-logical-request timeout on the HttpClient
- So, it is not a per-transport-request timeout

What happens:

You issue a request against a long running operation
HttpClient's timeout kicks in
The retry policy kicks in
- if you add a logging for the onRetry/onRetryAsync you can see it is fires only once
Then it goes to sleep for 5 seconds
HttpClient's GetAsync call throws the TCE since the per-logical-request timeout kicked in

The Solution

Use timeout policy to define a per-transport-request timeout

IAsyncPolicy<HttpResponseMessage> timeout = Policy.TimeoutAsync<HttpResponseMessage>(TimeSpan.FromSeconds(2));

IAsyncPolicy<HttpResponseMessage> retry = HttpPolicyExtensions.HandleTransientHttpError()
    .Or<TaskCanceledException>()
    .Or<TimeoutRejectedException>()
    .WaitAndRetryAsync(5, _ => TimeSpan.FromSeconds(5), 
        onRetry:(_, __) => Console.WriteLine("RETRIED"));

builder.Services.AddHttpClient("test", client =>
    {
        client.BaseAddress = new Uri("http://localhost:5000");
        client.Timeout = TimeSpan.FromSeconds(20);
    })
    .AddPolicyHandler(Policy.WrapAsync(retry, timeout));

The timeout will be used as per-transport-request timeout (2 seconds)
The retry is timeout-policy aware (Or<TimeoutRejectedException>())
- I've added some logging to see how many times the retry kicks in
I've increased the per-logical-request timeout on HttpClient from 2 seconds to 20 seconds
I've combined the timeout and retry policies in order to collaborate

You should see something similar in your logs:

RETRIED
...
RETRIED
...
RETRIED
...
TaskCancelledException thrown

Let's see the sequence of actions:

[00-02s]: Initial request throws TimeoutRejectedException
@2s: Prints RETRIED
[02-07s]: Polly is sleeping
[07-09s]: 1st retry attempt throws TimeoutRejectedException
@9s: Prints RETRIED
[09-14s]: Polly is sleeping
[14-16s]: 2nd retry attempt throws TimeoutRejectedException
@16s: Prints RETRIED
[16-21s]: Polly is sleeping
@20s: HttpClient throws TaskCancelledException

Note

Please note that you can implement both the per-logical-request and the per-transport-request timeouts with Polly

IAsyncPolicy<HttpResponseMessage> attemptSequenceTimeout = Policy
    .TimeoutAsync<HttpResponseMessage>(TimeSpan.FromSeconds(20));

IAsyncPolicy<HttpResponseMessage> attemptTimeout = Policy
    .TimeoutAsync<HttpResponseMessage>(TimeSpan.FromSeconds(2));

IAsyncPolicy<HttpResponseMessage> retry = HttpPolicyExtensions
    .HandleTransientHttpError()
    .Or<TimeoutRejectedException>()
    .WaitAndRetryAsync(5, _ => TimeSpan.FromSeconds(5), 
        onRetry:(_, __) => Console.WriteLine("RETRIED"));

var combinedPolicy =  Policy.WrapAsync(
    attemptSequenceTimeout, 
    retry, 
    attemptTimeout);

builder.Services.AddHttpClient("test", client =>
    {
        client.BaseAddress = new Uri("http://localhost:5000");
    })
    .AddPolicyHandler(combinedPolicy);