Unknown causes for canceled responses

[greg-signi]

Using Yarp.ReverseProxy version 2.3.0

We are having the issue on a specific request, that when we ask for a longer chunk of data, we get
Copying the response body was canceled after almost a minute of the response already being delivered.
We are only seeing this on this specific request.

The api response is fairly small 1.6MB nothing major, I managed to test locally much more, so I kinda want to disregard the response size in this equation, but its the only variable that changes..

The api responds in ~5 seconds

My proxy response times out after ~60 seconds always

You can see that we get Received HTTP/"2.0" response 200. inside the Yarp.ReverseProxy.Forwarder.HttpForwarder

After this 60 seconds hang up I can see that the HttpContext.RequestAborted.IsCancellationRequested is true, but that must be just a symptom and not the cause right ?

Can you help me debug this issue ?

[MihaZupan]

Are you sure you're on 2.3.0? Copying the response body was canceled. is a debug-level event as of 2.3.0.

After this 60 seconds hang up I can see that the HttpContext.RequestAborted.IsCancellationRequested is true, but that must be just a symptom and not the cause right ?

YARP has two ways to impose timeouts:

• Timeout/TimeoutPolicy that you normally set on the route.
• ActivityTimeout that can last forever as long as there's recent activity (e.g. bytes getting transfered)

The first one will signal request timeouts by signaling HttpContext.RequestAborted.
If you're not using that, then HttpContext.RequestAborted should mean that the client disconnected.

You can see that we get Received HTTP/"2.0" response 200.

This log message with the status code is logged as soon as we get the start of the response that includes the status code.
The response body is copied after this.

You can see System.Net.Http.Http2Connection.Http2Stream.WaitForDataAsync in the stack trace, so at the moment that cancellation was triggered we were waiting for more data from the backend server.

Are you sure that the backend server is actually generating the full response in time?

[greg-signi]

Are you sure you're on 2.3.0? Copying the response body was canceled. is a debug-level event as of 2.3.0.

Yeah, this log is Warning level and it comes from our code when we notice an error in IForwardedErrorFeature.

using var cts = new CancellationTokenSource(TimeSpan.FromMinutes(2));

await _httpForwarder.SendAsync(HttpContext, $"https://{apiDomain}/{destinationApiUrl}", httpClient, ForwarderRequestConfig.Empty, transformer, cts.Token);

var errorFeature = HttpContext.Features.Get<IForwarderErrorFeature>();
if (errorFeature != null)
{
      var error = errorFeature.Error;
      var exception = errorFeature.Exception;

      _logger.LogReverseProxyFailedToForward(destinationApiUrl, error, exception);
}

Are you sure that the backend server is actually generating the full response in time?

According to the logs, yes, you can see "Request finished" and right after the log from istio (other proxy) about the request.

[MihaZupan]

If this is consistent for a particular kind of request, I'd try getting a network capture for just that one request. Even if encrypted you should still be able to see how much data was flowing around and when.

So your setup is Client <----> YARP <-- HTTP/2 --> Istio <-- HTTP/1.1 --> Backend service?

[greg-signi]

Client <----> YARP <-- HTTP/2 --> Istio <-- HTTP/1.1 --> Backend service

Yep

If this is consistent for a particular kind of request, I'd try getting a network capture for just that one request. Even if encrypted you should still be able to see how much data was flowing around and when.

Hmm okay, will need to see how I can do this

[greg-signi]

The problem seems to be related to Accepting gzip.

• When the response is large enough it breaks.

• The same response if we don't Accept gzip it doesn't break.

• When the response is small enough it doesn't break.

[MihaZupan]

Assuming you're using YARP's default HttpClient configuration, YARP doesn't care whether or which kind of compression is used.
If this is making a difference it points at an issue behind YARP.

[greg-signi]

A bit but nothing special.. Where do you think I should look for ?

For example take my Http transformer

public override HttpTransformer CreateTransformer(string localPath, AccessTokenResult accessToken)
    {
        return TransformBuilder.Create(context =>
        {
            // apply default YARP logic for forwarding headers
            context.CopyRequestHeaders = true;

            // use YARP default logic for x-forwarded headers
            context.UseDefaultForwarders = true;

            // always remove cookie header since this contains the session
            context.RequestTransforms.Add(new RequestHeaderRemoveTransform("Cookie"));

            // transform path to remove prefix
            context.RequestTransforms.Add(new PathStringTransform(PathStringTransform.PathTransformMode.RemovePrefix, localPath));

            // add the access token
            context.RequestTransforms.Add(new AccessTokenRequestTransform(
                ProofService,
                LoggerFactory.CreateLogger<AccessTokenRequestTransform>(),
                accessToken));

            // add the reverse proxy request transform
            context.RequestTransforms.Add(new MultipartFormDataRequestTransform());
        });
    }

or my MessageInvokerFactory

public class DefaultHttpMessageInvokerFactory : IHttpMessageInvokerFactory
{
    /// <summary>
    /// Dictionary to cache invoker instances
    /// </summary>
    protected readonly ConcurrentDictionary<string, HttpMessageInvoker> Clients = new();

    /// <inheritdoc />
    public virtual HttpMessageInvoker CreateClient(string localPath)
    {
        return Clients.GetOrAdd(localPath, (key) =>
        {
            var handler = CreateHandler(key);
            return new HttpMessageInvoker(handler);
        });
    }
    
    /// <summary>
    /// Creates the HTTP message handler
    /// </summary>
    /// <param name="localPath"></param>
    /// <returns></returns>
    protected virtual HttpMessageHandler CreateHandler(string localPath)
    {
        return new SocketsHttpHandler
        {
            UseProxy = false,
            AllowAutoRedirect = false,
            AutomaticDecompression = DecompressionMethods.None,
            UseCookies = false,
        };
    }
}

[greg-signi]

Currently band aid fix was to:

context.RequestTransforms.Add(new RequestHeaderValueTransform("Accept-Encoding", "identity", false));

Thanks for your help👍