Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Random 502 errors when client cancels request #2070

Closed
alkampfergit opened this issue Mar 14, 2023 · 17 comments · Fixed by #2119
Closed

Random 502 errors when client cancels request #2070

alkampfergit opened this issue Mar 14, 2023 · 17 comments · Fixed by #2119
Assignees
Labels
Type: Bug Something isn't working
Milestone

Comments

@alkampfergit
Copy link

Random 502 errors when ui cancels the request.

We have an Angular UI application that talks to an ASP.NET webservice hosted in IIS and proxyed with YARP.
The backend only works with HTTP1.1 not HTTP/2
The error happens only if YARP uses HTTP/2, so the error happens only when YARP needs to proxy HTTP/2 traffic to a HTTP1.1 backend.
The application works as usual and we have some custom ui logic that cancels some of the requests, when the requests is cancelled YARP returns 502.

To Reproduce

I had not created a reproducible working scenario but I think that it is enough to issue a request then immediately cancels. From the browser I can see that the request has content-lenght of some bytes (49 in the above example) but the request was cancelled before the first byte of the content was transmitted so YARP complained.

2023-03-14 14:52:36.832 +01:00 [INF] Proxying to http://localhost/api/v1/omnisearch/view-config HTTP/2 RequestVersionOrLower no-streaming
2023-03-14 14:52:36.836 +01:00 [INF] "Request": An error was encountered before receiving a response.
System.Net.Http.HttpRequestException: Sent 0 request content bytes, but Content-Length promised 49.
   at System.Net.Http.HttpConnection.SendRequestContentAsync(HttpRequestMessage request, HttpContentWriteStream stream, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at Yarp.ReverseProxy.Forwarder.HttpForwarder.SendAsync(HttpContext context, String destinationPrefix, HttpMessageInvoker httpClient, ForwarderRequestConfig requestConfig, HttpTransformer transformer, CancellationToken cancellationToken)

Further technical details

  • Latest YARP packages, on .NET 7 windows environment.
@alkampfergit alkampfergit added the Type: Bug Something isn't working label Mar 14, 2023
@samsp-msft
Copy link
Contributor

What are you expecting instead?

If you cancel a request, then the proxy isn't getting the information that it expects, so it returns an error.

@alkampfergit
Copy link
Author

alkampfergit commented Mar 15, 2023

Actually without the proxy, the ui cancels the request and the user has no visual indication that the query was canceled. In chrome developer toolbar I only see the request as Canceled while with the proxy the call receives a 502 error code.

Since from angular point of view the call is not canceled but the server returned an error it triggers our catch error routine that in turn shows to the user a "call failed message", resulting in a puzzled user because everything works as expeceted but he is seeing random "call errors".

If I disable HTTP/2 on proxy configuration I was not able to recreate the error, so it seems a problem when the proxy uses HTTP/2 and the backend uses HTTP1.1

@alkampfergit
Copy link
Author

Another suggestion is: As you can see the error gets logged as INF

2023-03-14 14:52:36.836 +01:00 [INF] "Request": An error was encountered before receiving a response.

I really like this kind of message to be logged at least in WARN, am I wrong?

@MihaZupan
Copy link
Member

the ui cancels the request and the user has no visual indication that the query was canceled
Since from angular point of view the call is not canceled

How is it canceled, but not considered canceled? Can you share a runnable repro js script we could use that demonstrates that?

I really like this kind of message to be logged at least in WARN, am I wrong?

You're in luck, this was just recently changed to warning in main: #2044

@alkampfergit
Copy link
Author

I'll try to reproduce the error in the next days (tomorrow I have a conference and I'll be busy). Actually it does not happens all the time and seems to be related to cancellation before the client sent all the payload.

The only thing I've noticed is that, if I disable HTTP/2 protocol on proxy the error never happens.

@Schaeri
Copy link

Schaeri commented Mar 16, 2023

Hello @MihaZupan Hello @alkampfergit

We have encountered the same problem in our environment. The problem has been found with update to Yarp 2.0.

But here with a Blazor Wasm client, SingalR and GRPC. The problem seems to occur only with Kestrel. In an IIS environment the problem seems to occur less often.

Attached you can find a sample application consisting of a WASM client which opens a SignalR connection and then makes a GRPC call. Then the SignalR connection is closed and another GRPC call is made. This is done in a loop until the error occurs.
The problem can be reproduced more quickly in Chrome than in Firefox.
ProblemDemo.zip

With Yarp, the error occurs after about 120 runs:

System.IO.IOException: The client reset the request stream.
         at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
         at System.IO.Pipelines.Pipe.ReadAsync(CancellationToken token)
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2MessageBody.ReadAsync(CancellationToken cancellationToken)
         at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
         at Grpc.AspNetCore.Server.Internal.PipeExtensions.ReadSingleMessageAsync[T](PipeReader input, HttpContextServerCallContext serverCallContext, Func`2 deserializer)
fail: Grpc.AspNetCore.Server.ServerCallHandler[6]
      Error when executing service method 'SampleCall'.
      System.IO.IOException: The client reset the request stream.
         at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
         at System.IO.Pipelines.Pipe.ReadAsync(CancellationToken token)
         at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2MessageBody.ReadAsync(CancellationToken cancellationToken)
         at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
         at Grpc.AspNetCore.Server.Internal.PipeExtensions.ReadSingleMessageAsync[T](PipeReader input, HttpContextServerCallContext serverCallContext, Func`2 deserializer)
         at Grpc.AspNetCore.Server.Internal.CallHandlers.UnaryServerCallHandler`3.HandleCallAsyncCore(HttpContext httpContext, HttpContextServerCallContext serverCallContext)
         at Grpc.AspNetCore.Server.Internal.CallHandlers.ServerCallHandlerBase`3.<HandleCallAsync>g__AwaitHandleCall|8_0(HttpContextServerCallContext serverCallContext, Method`2 method, Task handleCall)

ClientError

Without Yarp the whole thing runs stable:
NoError

What's interesting is that the client can't make any other calls to the server at all after the error. The error occurs then immediately. If you wait about 30 seconds, the system recovers and several calls are possible again.

@alkampfergit
Copy link
Author

I can add that in our situation we have two different outcome after the first error,

  1. The error occours, then it seems to happen more frequently
  2. the error is sistematic, we were not able to do any more call (each one results in the error) until we refresh the page.
    Situation 2 happens more rarely than situation 1

@karelz
Copy link
Member

karelz commented Mar 28, 2023

Triage: Thanks for the repro @Schaeri! We're a bit busy, it might take a week or two before we get to it.

@Schaeri
Copy link

Schaeri commented Mar 29, 2023

Thanks @karelz for the feedback. I ran the example with the source code from Yarp (branch release/2.0). In a release build the behavior is the same. In the debug build the application terminates because of an assertion. Maybe the info helps. Here is the stack trace with the error:

Process terminated. Assertion failed.
An actual content should have been set
   at Yarp.ReverseProxy.Forwarder.RequestUtilities.AddHeader(HttpRequestMessage request, String headerName, StringValues value) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Forwarder/RequestUtilities.cs:line 319
   at Yarp.ReverseProxy.Forwarder.HttpTransformer.TransformRequestAsync(HttpContext httpContext, HttpRequestMessage proxyRequest, String destinationPrefix) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Forwarder/HttpTransformer.cs:line 101
   at Yarp.ReverseProxy.Transforms.Builder.StructuredTransformer.<>n__0(HttpContext httpContext, HttpRequestMessage proxyRequest, String destinationPrefix)
   at Yarp.ReverseProxy.Transforms.Builder.StructuredTransformer.TransformRequestAsync(HttpContext httpContext, HttpRequestMessage proxyRequest, String destinationPrefix, CancellationToken cancellationToken) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Transforms/Builder/StructuredTransformer.cs:line 87
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Yarp.ReverseProxy.Transforms.Builder.StructuredTransformer.TransformRequestAsync(HttpContext httpContext, HttpRequestMessage proxyRequest, String destinationPrefix, CancellationToken cancellationToken)
   at Yarp.ReverseProxy.Forwarder.HttpForwarder.CreateRequestMessageAsync(HttpContext context, String destinationPrefix, HttpTransformer transformer, ForwarderRequestConfig requestConfig, Boolean isStreamingRequest, ActivityCancellationTokenSource activityToken) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Forwarder/HttpForwarder.cs:line 423
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Yarp.ReverseProxy.Forwarder.HttpForwarder.CreateRequestMessageAsync(HttpContext context, String destinationPrefix, HttpTransformer transformer, ForwarderRequestConfig requestConfig, Boolean isStreamingRequest, ActivityCancellationTokenSource activityToken)
   at Yarp.ReverseProxy.Forwarder.HttpForwarder.SendAsync(HttpContext context, String destinationPrefix, HttpMessageInvoker httpClient, ForwarderRequestConfig requestConfig, HttpTransformer transformer, CancellationToken cancellationToken) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Forwarder/HttpForwarder.cs:line 144
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Yarp.ReverseProxy.Forwarder.HttpForwarder.SendAsync(HttpContext context, String destinationPrefix, HttpMessageInvoker httpClient, ForwarderRequestConfig requestConfig, HttpTransformer transformer, CancellationToken cancellationToken)
   at Yarp.ReverseProxy.Forwarder.HttpForwarder.SendAsync(HttpContext context, String destinationPrefix, HttpMessageInvoker httpClient, ForwarderRequestConfig requestConfig, HttpTransformer transformer) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Forwarder/HttpForwarder.cs:line 92
   at Yarp.ReverseProxy.Forwarder.ForwarderMiddleware.Invoke(HttpContext context) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Forwarder/ForwarderMiddleware.cs:line 75
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Yarp.ReverseProxy.Forwarder.ForwarderMiddleware.Invoke(HttpContext context)
   at Yarp.ReverseProxy.Limits.LimitsMiddleware.Invoke(HttpContext context) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Limits/LimitsMiddleware.cs:line 49
   at Yarp.ReverseProxy.Health.PassiveHealthCheckMiddleware.Invoke(HttpContext context) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Health/PassiveHealthCheckMiddleware.cs:line 25
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Yarp.ReverseProxy.Health.PassiveHealthCheckMiddleware.Invoke(HttpContext context)
   at Yarp.ReverseProxy.LoadBalancing.LoadBalancingMiddleware.Invoke(HttpContext context) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/LoadBalancing/LoadBalancingMiddleware.cs:line 67
   at Yarp.ReverseProxy.SessionAffinity.SessionAffinityMiddleware.Invoke(HttpContext context) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/SessionAffinity/SessionAffinityMiddleware.cs:line 45
   at Yarp.ReverseProxy.Model.ProxyPipelineInitializerMiddleware.Invoke(HttpContext context) in /home/rc/Desktop/ProblemDemo/reverse-proxy/src/ReverseProxy/Model/ProxyPipelineInitializerMiddleware.cs:line 52
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.HttpsPolicy.HttpsRedirectionMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.HttpsPolicy.HstsMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.HostFiltering.HostFilteringMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2Stream`1.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

@renatosc
Copy link

renatosc commented Apr 5, 2023

I am getting similar error here ("Sent 0 request content bytes, but Content-Length promised 29."). I started getting that error after moving my code from the Program.cs to be inside a controller. So for now I will leave it outside of the controller.

@benjaminpetit
Copy link
Member

benjaminpetit commented Apr 6, 2023

@Schaeri I was not able to reproduce locally the error with your sample. But @MihaZupan can so we are all good.

@Schaeri
Copy link

Schaeri commented Apr 6, 2023

@benjaminpetit: There are two applications in the ProblemDemo. The server, which contains all GRPC and SignalR endpoints and also delivers the client. The launchSettings.json defines the following URL for the application: https://localhost:7124. The application runs behind the gateway on the URL https://localhost:6001. See lanchSettins.json from the gateway. It is important that gateway and server are started and the application is called via the gateway (https://localhost:6001). Then I have the problem after maximal 200 runs. On Linux I tested with the browser Firefox and Chrome. On Windows only with Chrome.

@benjaminpetit
Copy link
Member

Sorry for not coming back sooner.

If I do launch the demo with dotnet run --project ... I see the exception. If I run the dlls directly with dotnet xxx.dll the repro doesn't work (not sure why I tried first that way).

We should be able to do a workaround for this issue soon.

Thanks again for the repro.

@MihaZupan MihaZupan added this to the YARP 2.x milestone Apr 26, 2023
@benjaminpetit
Copy link
Member

Could you try this fix and see if it behaves like you expected? https://github.com/benjaminpetit/reverse-proxy/tree/fix/extended-connect

I still see failures, but at least the connection isn't botched.

@Schaeri
Copy link

Schaeri commented Apr 28, 2023

@benjaminpetit Thanks for the help. Unfortunately I am not able to compile the code. We are using .Net 7.0 and I get the following build error:

'Severity Code Description Project File Line Suppression State Error CS1061 'string' does not contain a definition for 'IsExtendedConnect' and no accessible extension method 'IsExtendedConnect' accepting a first argument of type 'string' could be found (are you missing a using directive or an assembly reference?) Yarp.ReverseProxy (net7.0) C:\Users\rs\Desktop\reverse-proxy\src\ReverseProxy\Forwarder\HttpForwarder.cs 518 N/A

HttpForwarder.cs

#if NET7_0_OR_GREATER
            var connectFeature = request.HttpContext.Features.Get<IHttpExtendedConnectFeature>();
            if (connectFeature?.Protocol?.IsExtendedConnect) // here is the error
            {
                hasBody = false;
            }
#endif

@benjaminpetit
Copy link
Member

Sorry I merged it a bit fast, it should be ok now

@Schaeri
Copy link

Schaeri commented Apr 28, 2023

@benjaminpetit: Thank you very much. I was able to test the changes. It seems that our problem is solved.
The sample now behaves the same with and without the proxy. I have also integrated the new proxy into our applications and there too the problems we had have disappeared. That is very nice. We would be happy if there would be a release soon 😄

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Type: Bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

7 participants