dotnet / aspnetcore

ASP.NET Core is a cross-platform .NET framework for building modern cloud-based web applications on Windows, Mac, or Linux.
https://asp.net
MIT License
35.44k stars 10.02k forks source link

Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content. #23949

Open Tino92 opened 4 years ago

Tino92 commented 4 years ago

We are facing intermittently BadHttpRequestException: Unexpected end of request content.

Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException:
   at Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException.Throw (Microsoft.AspNetCore.Server.Kestrel.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody+<ReadAsyncInternal>d__9.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream+<ReadAsyncInternal>d__30.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream+<ReadAsync>d__36.MoveNext (Microsoft.AspNetCore.WebUtilities, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.WebUtilities.StreamHelperExtensions+<DrainAsync>d__3.MoveNext (Microsoft.AspNetCore.WebUtilities, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Mvc.Formatters.NewtonsoftJsonInputFormatter+<ReadRequestBodyAsync>d__13.MoveNext (Microsoft.AspNetCore.Mvc.NewtonsoftJson, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder+<BindModelAsync>d__7.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder+<BindModelAsync>d__7.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider+<>c__DisplayClass0_0+<<CreateBinderDelegate>g__Bind|0>d.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker+<<InvokeInnerFilterAsync>g__Awaited|13_0>d.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker+<<InvokeNextResourceFilter>g__Awaited|24_0>d.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeFilterPipelineAsync (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker+<<InvokeAsync>g__Logged|17_1>d.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware+<<Invoke>g__AwaitRequestTask|6_0>d.MoveNext (Microsoft.AspNetCore.Routing, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware+<Invoke>d__5.MoveNext (Microsoft.AspNetCore.Authorization.Policy, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6.MoveNext (Microsoft.AspNetCore.Authentication, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol+<ProcessRequests>d__214`1.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=3.1.5.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)

We are running on .NET Core 3.1.5, this exception seemed to only appear when we moved over to .NET Core 3.0

There have been similiar issues opened in the past, https://github.com/dotnet/aspnetcore/issues/19476#issuecomment-629457165 and https://github.com/dotnet/aspnetcore/issues/6575.

This exception seems to be thrown when a client aborts mid-request. My question is, should this be logged as a warning instead of an exception? It creates a lot of noise in our logs.

Tratcher commented 4 years ago

The exception needs to be thrown from the request body APIs so you don't think the request finished gracefully, but the caller should catch it. In this case that's MVC, and I think they're adding something in 5.0.

mkArtakMSFT commented 4 years ago

Thanks for contacting us. We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We will evaluate the request when we will planning the work for the next milestone. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

ghost commented 4 years ago

We've moved this issue to the Backlog milestone. This means that it is not going to be worked on for the coming release. We will reassess the backlog following the current release and consider this item at that time. To learn more about our issue management process and to have better expectation regarding different types of issues you can read our Triage Process.

Tino92 commented 4 years ago

Do you recommend just filtering out the exceptions?

Tratcher commented 4 years ago

Yes

sunliusi commented 3 years ago

The issue is still here in 5.0, version 2.2 is normal.

sunliusi commented 3 years ago

Can this error be ignored globally?

mynkow commented 3 years ago

Can this error be ignored globally?

pccai commented 3 years ago

The issue is still here in 5.0.7

xsoheilalizadeh commented 3 years ago

We are facing the same issue on .NET 6 Preview 7:

fail: Microsoft.AspNetCore.Server.Kestrel[13]
Connection id "0HMBJDQ4IBONH", Request id "0HMBJDQ4IBONH:00000002": An unhandled exception was thrown by the application.
Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.
at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken) in Microsoft.AspNetCore.Server.Kestrel.Core.dll:token 0x60009ee+0x1a2
at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 destination, CancellationToken cancellationToken) in Microsoft.AspNetCore.Server.Kestrel.Core.dll:token 0x6000e12+0x77
at System.Text.Json.JsonSerializer.ReadFromStreamAsync(Stream utf8Json, ReadBufferState bufferState, CancellationToken cancellationToken) in System.Text.Json.dll:token 0x60003a8+0x95
at System.Text.Json.JsonSerializer.ReadAllAsync[TValue](Stream utf8Json, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken) in System.Text.Json.dll:token 0x60003a6+0xfa
at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000b0e+0x103
at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000b0e+0x26a
at Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder.BindModelAsync(ModelBindingContext bindingContext) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x60007fc+0x1e8
at Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder.BindModelAsync(ActionContext actionContext, IModelBinder modelBinder, IValueProvider valueProvider, ParameterDescriptor parameter, ModelMetadata metadata, Object value, Object container) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x600066e+0x220
at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider.<>c__DisplayClass0_0.<<CreateBinderDelegate>g__Bind|0>d.MoveNext() in Microsoft.AspNetCore.Mvc.Core.dll:token 0x60010f6+0x16d
--- End of stack trace from previous location ---
at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x60009c2+0x65
at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a81+0x65
at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a7d+0x77
at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a7d+0xfb
at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger) in Microsoft.AspNetCore.Routing.dll:token 0x60000ab+0x5e
at Microsoft.AspNetCore.Authorization.Policy.AuthorizationMiddlewareResultHandler.HandleAsync(RequestDelegate next, HttpContext context, AuthorizationPolicy policy, PolicyAuthorizationResult authorizeResult) in Microsoft.AspNetCore.Authorization.Policy.dll:token 0x600001b+0x338
at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Authorization.Policy.dll:token 0x6000013+0x448
at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Authentication.dll:token 0x6000049+0x401
at Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware.<Invoke>g__AwaitMatcher|8_0(EndpointRoutingMiddleware middleware, HttpContext httpContext, Task`1 matcherTask) in Microsoft.AspNetCore.Routing.dll:token 0x60000b9+0x130
at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application) in Microsoft.AspNetCore.Server.Kestrel.Core.dll:token 0x6000d6b+0x54c
senj commented 3 years ago

How can I filter this exception in logs, without ignoring other error messages from kestrel ?

WeihanLi commented 3 years ago

How can I filter this exception in logs, without ignoring other error messages from kestrel ?

I add a custom exception handler to ignore the BadHttpRequestException

supermihi commented 3 years ago

@WeihanLi could you share a code snippet for filtering that exception?

deleteLater commented 3 years ago

use mvc-exception-filter or a global exception middleware, then check and ignore

if (ex is Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException && 
    ex.Message == "Unexpected end of request content.")
{
    // "Unexpected end of request content."
    // Microsoft.AspNetCore.Server.Kestrel.Core.CoreStrings.BadRequest_UnexpectedEndOfRequestContent
    // ignore this
}
WeihanLi commented 3 years ago

@supermihi , sorry for missing this message, you can do what as @deleteLater proposed. For our project, we use a custom exception handler middleware to ignore the BadRequestException

public class CustomExceptionHandlerMiddleware
{
    private readonly ILogger<CustomExceptionHandlerMiddleware> _logger;
    private readonly RequestDelegate _next;

    public CustomExceptionHandlerMiddleware(ILogger<CustomExceptionHandlerMiddleware> logger, RequestDelegate next)
    {
        _logger = logger;
        _next = next;
    }

    public async Task Invoke(HttpContext context)
    {
        try
        {
            await _next(context);
        }
        catch (BadHttpRequestException ex)
        {
            _logger.LogWarning(ex, "BadHttpRequestException");
        }
        catch (Exception exception)
        {
            _logger.LogError(exception, $"Exception when invoke {context.Request.Method}:{context.Request.GetDisplayUrl()}");
        }
    }
}
supermihi commented 3 years ago

Thanks a lot, @WeihanLi and @deleteLater!

VahidN commented 2 years ago

I had this issue with the hot reload feature of .NET 6. Whenever a record was written to an SQLite database located at wwwroot, all of the HTTP requests of a Blazor WASM's app would be cancelled/aborted and it caused the full app reload in the browser and BadHttpRequestException on the server. I had to turn off the hot reload and disable watching the wwwroot to make it work again in production environment:

    "profiles": {
      "Name.Server": {
        "hotReloadEnabled": false,

and also

  <ItemGroup>
     <Watch Remove="wwwroot\**\*" />
  </ItemGroup>
ghost commented 2 years ago

Thanks for contacting us. We're moving this issue to the .NET 7 Planning milestone for future evaluation / consideration. Because it's not immediately obvious that this is a bug in our framework, we would like to keep this around to collect more feedback, which can later help us determine the impact of it. We will re-evaluate this issue, during our next planning meeting(s). If we later determine, that the issue has no community involvement, or it's very rare and low-impact issue, we will close it - so that the team can focus on more important and high impact issues. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

petavalentin commented 2 years ago

We were also seeing this issue intermittently in .NET5 and .NET6 (didn't try in previous versions). Tweaking the thread pool seems to have "fixed" it: ThreadPool.SetMaxThreads(32_767, 2_000); ThreadPool.SetMinThreads(1_000, 1_000);

sergiuciudin commented 2 years ago

For us is happening in high load for all services that are using following code:

var reader = new StreamReader(Request.Body, Encoding.UTF8); string payload = await reader.ReadToEndAsync();

Note: timeout is long enough, so connection is not closed.

petavalentin commented 2 years ago

For us is happening in high load for all services that are using following code:

var reader = new StreamReader(Request.Body, Encoding.UTF8); string payload = await reader.ReadToEndAsync();

Note: timeout is long enough, so connection is not closed.

Seems similar with our code. For us the timeout was not reached too. If I were you, I would try tweaking the ThreadPool as mentioned in the previous comment. Even if it was not obvious from the exception message, we were actually having a thread starvation issue.

deleteLater commented 2 years ago

@sergiuciudin @petavalentin I don't think service high load is the problem, this error often occurred when client terminated the request body early, just like what @Tratcher said here https://github.com/dotnet/aspnetcore/issues/6575#issuecomment-453691427. And the problem can be reproduced easily, just upload a file to your server and terminate before it finished.

RobvH commented 2 years ago

@sergiuciudin @petavalentin I don't think service high load is the problem, this error often occurred when client terminated the request body early, just like what @Tratcher said here #6575 (comment). And the problem can be reproduced easily, just upload a file to your server and terminate before it finished.

I think part of the problem is that it could happen in either case; and the thread starvation case is definitely not as obvious as it really ought to be at this time (we're running .net and asp net core 6).

We have similar middleware that read our request and response bodies (firehosing them to a log in s3) and we get this exception under load, as well as BadHttpRequestException: Reading the request body timed out due to data arriving too slowly. See MinRequestBodyDataRate. at a far lower frequency but in the same error clusters that correlate with load.

mnns commented 2 years ago

Same here. Only happens under heavy load. We are using .NET 6. Don't really know how to solve it and this is a serious production problem.

I'm using Bombardier for high load testing. I noticed the output starts printing BadHttpRequestException when connection count is more than 25+. So around 50 concurrent connections I'm constantly getting this exception, which later actually stops the server from responding, even when I abort the Bombardier test. The log output keeps throwing the error minutes after I stop the test. The only solution then is to restart.

Feels like thread starvation but I'm not sure how to approach it.

All my code is fully async, even when this is happening, the CPU and Memory are very low. The function I'm testing is performing some Cosmos DB queries (Read/write) and so on.

davidfowl commented 2 years ago

@RobvH

I think part of the problem is that it could happen in either case; and the thread starvation case is definitely not as obvious as it really ought to be at this time (we're running .net and asp net core 6).

Do you have counters for your service?

mnns commented 2 years ago

I ended up doing some tuning to speed up a specific function which helped but then when high load stressed the system it happened again. Check this post out: https://developpaper.com/about-bad-httprequestexception-of-frombody-model-binding-reading-exception-of-request-request-caused-by-active-cancellation-of-client-under-net-core/

I'm trying to tune my SetMinThreads to maybe handle more concurrent connections.

davidfowl commented 2 years ago

You only need to tune the minimum threads if you have LOTS of blocking.

Vandersteen commented 2 years ago

I've hit the same case, however it is not specifically 'high' load but the 'slow' networks that mostly caused this.

We have mobile apps connecting to our services, these devices do not always have the fastest networks. When uploading things like images / videos / ... these requests can take a long time to arrive.

Example: On iOS we use NSUrlSessions background which (to my best understanding) optimises for battery & network usage. So chucks of bytes arrive 'slowly', sometimes with 10+ seconds delay between chunks. (multiple concurrent uploads on a 3G/edge networks are not the fastest)

Do note that for us, around 80-90% of the requests complete in less than 10sec, with data arriving at an 'acceptable' rate for kestrel. It is to accommodate those requests under poor network conditions to still complete that we had to add:

.UseKestrel(o =>
{
    o.Limits.MinRequestBodyDataRate = null;
})

Now, we also use Azure Blob Storage for storing these. Basically we do something like this:

var writeStream = blob.OpenWrite();
requestStream.CopyToAsync(writeStream);

Now at this stage we had a lot of 'BadRequestExceptions' until we raised the 'ThreadPool MinThread'.

To my best understanding, we have 'at least' 2 async operations per request here that (might) take a long time to complete. So this might be the cause for 'threadpool starvation' in our case.

As we run on kubernetes, and these applications share nodes, we are currently unsure if/how this would affect other applications running on the same nodes. And if we should maybe just scale up the number of 'pods' these application run under to accommodate for those slow request, while leaving threadpool defaults as they are

mnns commented 2 years ago

You only need to tune the minimum threads if you have LOTS of blocking.

Well I did check each and every line of code in this specific method - it seems there's no blocking calls. Also used Ben.BlockingDetector to make sure I didn't miss anything. Raising the min threads minimized the amount of errors but I still get them at times (heavy load). In our case it is also an API for a mobile app.

ghost commented 2 years ago

Thanks for contacting us. We're moving this issue to the .NET 8 Planning milestone for future evaluation / consideration. Because it's not immediately obvious that this is a bug in our framework, we would like to keep this around to collect more feedback, which can later help us determine the impact of it. We will re-evaluate this issue, during our next planning meeting(s). If we later determine, that the issue has no community involvement, or it's very rare and low-impact issue, we will close it - so that the team can focus on more important and high impact issues. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

BirhaneS commented 1 year ago

Any update on this. We started seeing this immediately after upgrading to .NET 6 from .NET 3.1.

image

mohSalah66 commented 1 year ago

I'm seeing this exception a lot, an idea how to fix it?

Thanks ---------------------------------------Info output------------------------------------------------------------------------------- ` .NET SDK (reflecting any global.json): Version: 6.0.403 Commit: 2bc18bf292

Runtime Environment: OS Name: Windows OS Version: 10.0.22621 OS Platform: Windows RID: win10-x64 Base Path: C:\Program Files\dotnet\sdk\6.0.403\

global.json file: Not found

Host: Version: 6.0.11 Architecture: x64 Commit: 943474ca16

.NET SDKs installed: 5.0.214 [C:\Program Files\dotnet\sdk] 6.0.101 [C:\Program Files\dotnet\sdk] 6.0.403 [C:\Program Files\dotnet\sdk]

.NET runtimes installed: Microsoft.AspNetCore.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 6.0.1 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 6.0.11 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.NETCore.App 3.1.31 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 6.0.1 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 6.0.11 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.WindowsDesktop.App 3.1.31 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 6.0.1 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 6.0.11 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Download .NET: https://aka.ms/dotnet-download

Learn about .NET Runtimes and SDKs: https://aka.ms/dotnet/runtimes-sdk-info `

-------------------------------------------------------------Stacktrace---------------------------------------------------------------------

` Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.

at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken) at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder'11.StateMachineBox'1.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory'1 destination, CancellationToken cancellationToken) at System.Text.Json.JsonSerializer.ReadFromStreamAsync(Stream utf8Json, ReadBufferState bufferState, CancellationToken cancellationToken) at System.Text.Json.JsonSerializer.ReadAllAsync[TValue](Stream utf8Json, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken) at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding) at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding) at Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder.BindModelAsync(ModelBindingContext bindingContext) at Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder.BindModelAsync(ActionContext actionContext, IModelBinder modelBinder, IValueProvider valueProvider, ParameterDescriptor parameter, ModelMetadata metadata, Object value, Object container) at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider.<>cDisplayClass0_0.<gBind|0>d.MoveNext() --- End of stack trace from previous location --- at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.gAwaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.gAwaited|25_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeFilterPipelineAsync() --- End of stack trace from previous location --- at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.gAwaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope) at Microsoft.AspNetCore.Routing.EndpointMiddleware.gAwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger) at Swashbuckle.AspNetCore.SwaggerUI.SwaggerUIMiddleware.Invoke(HttpContext httpContext) at Swashbuckle.AspNetCore.Swagger.SwaggerMiddleware.Invoke(HttpContext httpContext, ISwaggerProvider swaggerProvider) at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context) at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context) at Microsoft.AspNetCore.ResponseCaching.ResponseCachingMiddleware.Invoke(HttpContext httpContext) at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task) --- End of inner exception stack trace --- at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.HandleException(HttpContext context, ExceptionDispatchInfo edi) at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication1 application) `

raffaele-cappelli commented 1 year ago

I am seeing the same exception randomly on .NET 7.

2022-12-06 14:35:45.3704|0|ERROR|Microsoft.AspNetCore.Server.Kestrel|Connection id "0HMMNGGNU7TQJ", Request id "0HMMNGGNU7TQJ:00000012": An unhandled exception was thrown by the application. Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 destination, CancellationToken cancellationToken)
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
   at System.Text.Json.Serialization.ReadBufferState.ReadFromStreamAsync(Stream utf8Json, CancellationToken cancellationToken, Boolean fillBuffer)
   at System.Text.Json.JsonSerializer.ReadFromStreamAsync[TValue](Stream utf8Json, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)
   at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)
   at Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder.BindModelAsync(ModelBindingContext bindingContext)
   at Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder.BindModelAsync(ActionContext actionContext, IModelBinder modelBinder, IValueProvider valueProvider, ParameterDescriptor parameter, ModelMetadata metadata, Object value, Object container)
   at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider.<>c__DisplayClass0_0.<<CreateBinderDelegate>g__Bind|0>d.MoveNext()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
BirhaneS commented 1 year ago

I'm seeing this exception a lot, an idea how to fix it?

Thanks ---------------------------------------Info output------------------------------------------------------------------------------- ` .NET SDK (reflecting any global.json): Version: 6.0.403 Commit: 2bc18bf292

Runtime Environment: OS Name: Windows OS Version: 10.0.22621 OS Platform: Windows RID: win10-x64 Base Path: C:\Program Files\dotnet\sdk\6.0.403\

global.json file: Not found

Host: Version: 6.0.11 Architecture: x64 Commit: 943474ca16

.NET SDKs installed: 5.0.214 [C:\Program Files\dotnet\sdk] 6.0.101 [C:\Program Files\dotnet\sdk] 6.0.403 [C:\Program Files\dotnet\sdk]

.NET runtimes installed: Microsoft.AspNetCore.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 6.0.1 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 6.0.11 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.NETCore.App 3.1.31 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 6.0.1 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 6.0.11 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.WindowsDesktop.App 3.1.31 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 6.0.1 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 6.0.11 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Download .NET: https://aka.ms/dotnet-download

Learn about .NET Runtimes and SDKs:

https://aka.ms/dotnet/runtimes-sdk-info ` -------------------------------------------------------------Stacktrace---------------------------------------------------------------------

` Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.

at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken) at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder'11.StateMachineBox'1.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory'1 destination, CancellationToken cancellationToken) at System.Text.Json.JsonSerializer.ReadFromStreamAsync(Stream utf8Json, ReadBufferState bufferState, CancellationToken cancellationToken) at System.Text.Json.JsonSerializer.ReadAllAsync[TValue](Stream utf8Json, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken) at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding) at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding) at Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder.BindModelAsync(ModelBindingContext bindingContext) at Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder.BindModelAsync(ActionContext actionContext, IModelBinder modelBinder, IValueProvider valueProvider, ParameterDescriptor parameter, ModelMetadata metadata, Object value, Object container) at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider.<>cDisplayClass0_0.<gBind|0>d.MoveNext() --- End of stack trace from previous location --- at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.gAwaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.gAwaited|25_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeFilterPipelineAsync() --- End of stack trace from previous location --- at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.gAwaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope) at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope) at Microsoft.AspNetCore.Routing.EndpointMiddleware.gAwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger) at Swashbuckle.AspNetCore.SwaggerUI.SwaggerUIMiddleware.Invoke(HttpContext httpContext) at Swashbuckle.AspNetCore.Swagger.SwaggerMiddleware.Invoke(HttpContext httpContext, ISwaggerProvider swaggerProvider) at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context) at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context) at Microsoft.AspNetCore.ResponseCaching.ResponseCachingMiddleware.Invoke(HttpContext httpContext) at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task) --- End of inner exception stack trace --- at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.HandleException(HttpContext context, ExceptionDispatchInfo edi) at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication1 application) `

We have been looking into this issue a bit more, and found out that what is contributing to the exception was a couple of blocking calls in our api. So here is what we did

In summary, I don't think ignoring the exception as recommended may be the right thing to do here since, even though not direct, the exception tells us we have some blocking issue that needs to be looked at.

raffaele-cappelli commented 1 year ago

We have been looking into this issue a bit more, and found out that what is contributing to the exception was a couple of blocking calls in our api. So here is what we did

  • Setup Ben.BlockingDetector in our api
  • Confirmed the exception was specifically coming from Kestrel.Core.Internal.Http.HttpRequestStream.ReadyAsyncInternal
  • Identified the blocking calls after running a few performance tests, we use locust but what ever you have should be fine.
  • Fixed the blocking calls and run a few more perf. tests.
  • Confirmed the exception do not occur anymore.

In summary, I don't think ignoring the exception as recommended may be the right thing to do here since, even though not direct, the exception tells us we have some blocking issue that needs to be looked at.

In my case I am quite sure no bloking calls are involved and I was able to reproduce the exception in a development environment with only one client connected making a small number of API calls. Unfortunately it is still happening randomly, I have not found a way to sistematically reproduce it.

raffaele-cappelli commented 1 year ago

💡 In some experiments I am doing, I have just noted that each time this exception is thrown, ((Microsoft.AspNetCore.Http.DefaultHttpContext)context).HttpContext).RequestAborted is in cancelled state (IsCancellationRequested is true). It seems (at least in my case) that sometimes when the client closes the connection, somewhere in the asp.net core pipeline, this BadHttpRequestException is thrown instead of OperationCanceledException.

raffaele-cappelli commented 1 year ago

💡💡 Now that I've been able to narrow the search space, I've verified that the problem (at least in my case) is due to a client calling an API (with HttpPost) and canceling it almost immediately (closing the connection). My guess is that in some cases, the framework, instead of correctly throwing an OperationCanceledException, tries to read the body, fails (perhaps because the body was not transmitted yet or because the connection was closed) and incorrectly throws BadHttpRequestException.

Tratcher commented 1 year ago

This is by design. BadHttpRequestException is an IOException. The request is 'bad' because it's being closed by the client before we receive the entire request body. Model binding can't complete.

The proposed fix in this issue is that BodyModelBinder should catch IOExceptions and terminate processing.

EgoPingvina commented 1 year ago

It's still relevant! ASP.Net 7 image

macias commented 1 year ago

It would be good to at least throw more meaningful exception/message -- we could all see the same final exception, but the reason for it being thrown could be different (I see this being single user on a local machine, so I very doubt it is a load issue in my case).

michasacuer commented 1 year ago

Have the same issue with dotnet-isolated Azure Function on Linux in B1 plan .NET 7. Its really annoying because my function receives houndreds of POST requests each seconds and i have a lot of those exceptions:

Microsoft.Azure.WebJobs.Host.FunctionInvocationException:
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+<ExecuteWithLoggingAsync>d__26.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.37.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: D:\a\_work\1\s\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:352)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+<TryExecuteAsync>d__18.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.37.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: D:\a\_work\1\s\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:108)
Inner exception System.InvalidOperationException handled at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw:
   at Microsoft.Azure.WebJobs.Host.Executors.DelayedException.Throw (Microsoft.Azure.WebJobs.Host, Version=3.0.37.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: D:\a\_work\1\s\src\Microsoft.Azure.WebJobs.Host\Executors\DelayedException.cs:27)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+ParameterHelper+<PrepareParametersAsync>d__36.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.37.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: D:\a\_work\1\s\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:922)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+<ExecuteWithWatchersAsync>d__32.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.37.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: D:\a\_work\1\s\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:492)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+<ExecuteWithLoggingAsync>d__26.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.37.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: D:\a\_work\1\s\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:306)
Inner exception Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException handled at Microsoft.Azure.WebJobs.Host.Executors.DelayedException.Throw:
   at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelBadHttpRequestException.Throw (Microsoft.AspNetCore.Server.Kestrel.Core, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody+<ReadAsyncInternal>d__9.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.ThrowForFailedGetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Threading.Tasks.Sources.ManualResetValueTaskSourceCore`1.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1+StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream+<ReadAsyncInternal>d__29.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream+<ReadAsync>d__40.MoveNext (Microsoft.AspNetCore.WebUtilities, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.IO.StreamReader+<ReadBufferAsync>d__71.MoveNext (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.IO.StreamReader+<ReadToEndAsyncInternal>d__65.MoveNext (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Extensions.Http.HttpRequestExtensions+<ReadAsStringAsync>d__4.MoveNext (Microsoft.Azure.WebJobs.Extensions.Http, Version=3.2.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\azure-webjobs-sdk-extensions\src\WebJobs.Extensions.Http\Extensions\HttpRequestExtensions.cs:39)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Extensions.Http.HttpTriggerAttributeBindingProvider+HttpTriggerBinding+<BindAsync>d__10.MoveNext (Microsoft.Azure.WebJobs.Extensions.Http, Version=3.2.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\azure-webjobs-sdk-extensions\src\WebJobs.Extensions.Http\HttpTriggerAttributeBindingProvider.cs:162)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Triggers.TriggeredFunctionBinding`1+<BindCoreAsync>d__8.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.37.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: D:\a\_work\1\s\src\Microsoft.Azure.WebJobs.Host\Triggers\TriggeredFunctionBinding.cs:57)

Can i just omit that exceptions @Tratcher ?

fengbozs commented 1 year ago

I've hit the same case,Through network packet capture analysis, the client connection is normal

itamarribsilva commented 9 months ago

Does anyone know if it's still happening in .NET 8?

vparmarhha commented 9 months ago

I am getting below error.

Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 destination, CancellationToken cancellationToken)
   at System.Text.Json.JsonSerializer.ReadFromStreamAsync(Stream utf8Json, ReadBufferState bufferState, CancellationToken cancellationToken)
   at System.Text.Json.JsonSerializer.ReadAllAsync[TValue](Stream utf8Json, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)
   at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)
   at Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder.BindModelAsync(ModelBindingContext bindingContext)
   at Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder.BindModelAsync(ActionContext actionContext, IModelBinder modelBinder, IValueProvider valueProvider, ParameterDescriptor parameter, ModelMetadata metadata, Object value, Object container)
   at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider.<>c__DisplayClass0_0.<<CreateBinderDelegate>g__Bind|0>d.MoveNext()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Serilog.AspNetCore.RequestLoggingMiddleware.Invoke(HttpContext httpContext)
[14:01:13 ERR] Something went wrong: Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1ContentLengthMessageBody.ReadAsyncInternal(CancellationToken cancellationToken)
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory`1 destination, CancellationToken cancellationToken)
   at System.Text.Json.JsonSerializer.ReadFromStreamAsync(Stream utf8Json, ReadBufferState bufferState, CancellationToken cancellationToken)
   at System.Text.Json.JsonSerializer.ReadAllAsync[TValue](Stream utf8Json, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)
   at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)
   at Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder.BindModelAsync(ModelBindingContext bindingContext)
   at Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder.BindModelAsync(ActionContext actionContext, IModelBinder modelBinder, IValueProvider valueProvider, ParameterDescriptor parameter, ModelMetadata metadata, Object value, Object container)
   at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider.<>c__DisplayClass0_0.<<CreateBinderDelegate>g__Bind|0>d.MoveNext()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Serilog.AspNetCore.RequestLoggingMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context): Unexpected end of request content.

How can I fix it?

caiorodrigues-cyncly commented 9 months ago

I'm facing the same error. Any update about that? The first register is around 4 years ago... I think that is a lot of time without a specific answer

itamarribsilva commented 8 months ago

I Almost eliminated the issue changing the API Startup Limits. { */serverOptions.Limits.MinRequestBodyDataRate = null*/ serverOptions.Limits.MinRequestBodyDataRate = new MinDataRate(bytesPerSecond: 1024, gracePeriod: TimeSpan.FromSeconds(10)); }) I guess it can be caused by bad internet connections sending data very slowly.

aaronmu commented 8 months ago

Does anyone know if it's still happening in .NET 8?

I can confirm that it is still happening in .NET 8.

davhdavh commented 8 months ago

https://github.com/dotnet/aspnetcore/blob/d83064b467e26bb30c4e4180eac1d0fad873bca9/src/Servers/Kestrel/Core/src/Internal/Http/HttpProtocol.cs#L698 is the problem. It both logs it in the call to SetBadRequestState to Debug level, but then again in the line after ReportApplicationError at level error. Fix is just to remove call to ReportApplicationError. This is also consistent with the same code https://github.com/dotnet/aspnetcore/blob/d83064b467e26bb30c4e4180eac1d0fad873bca9/src/Servers/Kestrel/Core/src/Internal/Http/HttpProtocol.cs#L582

amcasey commented 8 months ago

https://github.com/dotnet/aspnetcore/blob/d83064b467e26bb30c4e4180eac1d0fad873bca9/src/Servers/Kestrel/Core/src/Internal/Http/HttpProtocol.cs#L698

is the problem. It both logs it in the call to SetBadRequestState to Debug level, but then again in the line after ReportApplicationError at level error. Fix is just to remove call to ReportApplicationError. This is also consistent with the same code https://github.com/dotnet/aspnetcore/blob/d83064b467e26bb30c4e4180eac1d0fad873bca9/src/Servers/Kestrel/Core/src/Internal/Http/HttpProtocol.cs#L582

The consistency argument seems misleading in that ProcessRequestsAsync calls ProcessRequests and can take for granted that it has already reported application errors, if necessary. Presumably, that's why ProcessRequestsAsync never directly calls ReportApplicationError.

taylaninan commented 5 months ago

I can confirm that I have the same issue for a simple API developed in .NET 8.0.5. The simple API works with Postman fine when I click the "send button" manually. If I want to stress the API with automated load generators, I'm starting to get the same error.

It has been 4 long years from the first report of the issue. Any ideas?