Kestrel returns 400 status code when request size is greater than MaxRequestBodySize

[olizarevichroman]

Is there an existing issue for this?

• I have searched the existing issues

Describe the bug

When uploading a file larger than a default limit (30000000 bytes) Kestrel returns 400 status code, instead of 413.

Seems like similar issue have been already proposed #47525

Expected Behavior

I expect 413 status code in this case.

Http1ContentLengthMessageBody.OnReadStarting throws new BadHttpRequestException(CoreStrings.FormatBadRequest_RequestBodyTooLarge(detail), StatusCodes.Status413PayloadTooLarge, reason); when body size is greater setting 413 status code.

Then HttpProtocol.ProcessRequestsAsync catches this exception calling HttpProtocol.SetBadRequestState. And at this moment HttpProtocol.HasResponseStarted == true what prevents setting status code from exception.

For me it's seems a bit confusing

Steps To Reproduce

Try to upload a file larger than 30MB

Exceptions (if any)

No response

.NET Version

.NET 7, .NET 8 Preview 6

Anything else?

Tested with ASP.NET Core 7, ASP.NET Core Runtime 8.0.0-preview.6

[Tratcher]

Can you enable the debug logs to get more details? The 400 is likely coming from MVC or similar.

And yes, we should fix this wherever it's being blocked.

[olizarevichroman]

Can you enable the debug logs to get more details? The 400 is likely coming from MVC or similar.

And yes, we should fix this wherever it's being blocked.

Sure, hope it will help. Let me know if it's not enough or maybe I did it wrong.

logs-20230713.txt

[Tratcher]

2023-07-13T11:29:35.9322760+02:00 0HMS3GEM34QIQ:00000001 [DBG] Executed controller factory for controller "Gaming.FileStorage.WebApi.V2.UserFileController" ("Gaming.FileStorage.WebApi") (65418032)
2023-07-13T11:29:35.9453310+02:00 0HMS3GEM34QIQ:00000001 [DBG] Connection id ""0HMS3GEM34QIQ"", Request id ""0HMS3GEM34QIQ:00000001"": started reading request body. (55b8f554)
2023-07-13T11:29:35.9455550+02:00 0HMS3GEM34QIQ:00000001 [DBG] Connection id ""0HMS3GEM34QIQ"", Request id ""0HMS3GEM34QIQ:00000001"": done reading request body. (6feb3b06)
2023-07-13T11:29:35.9561270+02:00 0HMS3GEM34QIQ:00000001 [DBG] Done attempting to bind parameter '"fileId"' of type '"Gaming.FileStorage.Contracts.FileId"'. (90fee3af)
2023-07-13T11:29:35.9561450+02:00 0HMS3GEM34QIQ:00000001 [DBG] Done attempting to bind parameter '"fileId"' of type '"Gaming.FileStorage.Contracts.FileId"'. (90fee3af)
2023-07-13T11:29:35.9561570+02:00 0HMS3GEM34QIQ:00000001 [DBG] Attempting to validate the bound parameter '"fileId"' of type '"Gaming.FileStorage.Contracts.FileId"' ... (ce60666b)
2023-07-13T11:29:35.9561940+02:00 0HMS3GEM34QIQ:00000001 [DBG] Done attempting to validate the bound parameter '"fileId"' of type '"Gaming.FileStorage.Contracts.FileId"'. (5d5b0261)
2023-07-13T11:29:35.9562070+02:00 0HMS3GEM34QIQ:00000001 [DBG] Attempting to bind parameter '"file"' of type '"Microsoft.AspNetCore.Http.IFormFile"' ... (0448c17b)
2023-07-13T11:29:35.9575020+02:00 0HMS3GEM34QIQ:00000001 [DBG] Attempting to bind parameter '"file"' of type '"Microsoft.AspNetCore.Http.IFormFile"' using the name '""' in request data ... (1d38b825)
2023-07-13T11:29:35.9581050+02:00 0HMS3GEM34QIQ:00000001 [DBG] No files found in the request to bind the model to. (e9c88c0d)
2023-07-13T11:29:35.9581580+02:00 0HMS3GEM34QIQ:00000001 [DBG] Done attempting to bind parameter '"file"' of type '"Microsoft.AspNetCore.Http.IFormFile"'. (90fee3af)
2023-07-13T11:29:35.9581840+02:00 0HMS3GEM34QIQ:00000001 [DBG] Done attempting to bind parameter '"file"' of type '"Microsoft.AspNetCore.Http.IFormFile"'. (90fee3af)
2023-07-13T11:29:35.9582040+02:00 0HMS3GEM34QIQ:00000001 [DBG] Attempting to validate the bound parameter '"file"' of type '"Microsoft.AspNetCore.Http.IFormFile"' ... (ce60666b)
2023-07-13T11:29:35.9616380+02:00 0HMS3GEM34QIQ:00000001 [DBG] Done attempting to validate the bound parameter '"file"' of type '"Microsoft.AspNetCore.Http.IFormFile"'. (5d5b0261)
2023-07-13T11:29:35.9617780+02:00 0HMS3GEM34QIQ:00000001 [VRB] "Action Filter": Before executing "OnActionExecuting" on filter "Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter". (b4eff790)
2023-07-13T11:29:35.9619750+02:00 0HMS3GEM34QIQ:00000001 [VRB] "Action Filter": After executing "OnActionExecuting" on filter "Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter". (3551d07a)
2023-07-13T11:29:35.9620240+02:00 0HMS3GEM34QIQ:00000001 [VRB] "Action Filter": Before executing "OnActionExecuting" on filter "Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter". (b4eff790)
2023-07-13T11:29:35.9621330+02:00 0HMS3GEM34QIQ:00000001 [DBG] The request has model state errors, returning an error response. (4d2db500)

There's no size exception reported here, it's a binding failure, due to an empty file name?

2023-07-13T11:29:35.9562070+02:00 0HMS3GEM34QIQ:00000001 [DBG] Attempting to bind parameter '"file"' of type '"Microsoft.AspNetCore.Http.IFormFile"' ... (0448c17b)
2023-07-13T11:29:35.9575020+02:00 0HMS3GEM34QIQ:00000001 [DBG] Attempting to bind parameter '"file"' of type '"Microsoft.AspNetCore.Http.IFormFile"' using the name '""' in request data ... (1d38b825)
...
The request has model state errors, returning an error response. (4d2db500)

[olizarevichroman]

@Tratcher I almost sure it's not related. Here is what server returns:

{ "errors": { "": [ "Failed to read the request form. Request body too large. The max request body size is 30000000 bytes." ] }, "type": "https://tools.ietf.org/html/rfc9110#section-15.5.1", "title": "One or more validation errors occurred.", "status": 400, "traceId": "00-5babaa18f55ab68c2d9f5302f87994cb-1316c5577cf6467d-01" }

I've maken another log and here you can see a message "Request body too large".

[olizarevichroman]

@Tratcher did you have a chance to take a look?

[Tratcher]

Yes, that does look like MVC catching the exception and returning a generic 400. We've talked about that before, there might be another issue about it.