Facing Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content (Without high CPU usage/Thread starvation/network starvation for small requests)

[shreyagr]

We have been intermittently seeing issues with our Windows Docker hosted service on a Service Fabric cluster where for a fraction of the requests we start seeing this exception. Our payloads are very small (around 3 Kb at max) and the service fabric cluster sits behind an API-Management layer which doesn't show any issues. We also don't see high CPU usage/Thread starvation/Network starvation. The machines are hardly receiving 5 RPS.

I want to understand 2 things -

1. What could be the possible reasons for this happening in our scenario?
2. What is the best way to debug this issue ?

I have read other threads on this and they didn't help a lot.

Here is the callstack from the exception out of the middleware -

Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Unexpected end of request content.\r\n at
Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException.Throw(RequestRejectionReason reason)\r\n at
Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Http1MessageBody.PumpAsync()\r\n at
System.IO.Pipelines.PipeCompletion.ThrowLatchedException()\r\n at
System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)\r\n at
System.IO.Pipelines.Pipe.GetReadAsyncResult()\r\n at
Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.MessageBody.ReadAsync(Memory"1 buffer, CancellationToken cancellationToken)\r\n at
Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.ReadAsyncInternal(Memory"1 buffer, CancellationToken cancellationToken)\r\n at
Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream.ReadAsync(Byte[] buffer, Int32 offset, Int32 count, CancellationToken cancellationToken)\r\n at
Microsoft.AspNetCore.WebUtilities.StreamHelperExtensions.DrainAsync(Stream stream, ArrayPool"1 bytePool, Nullable"1 limit, CancellationToken cancellationToken)\r\n at
Microsoft.AspNetCore.Mvc.Formatters.JsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)\r\n at
Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder.BindModelAsync(ModelBindingContext bindingContext)\r\n at
Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder.BindModelAsync(ActionContext actionContext, IModelBinder modelBinder, IValueProvider valueProvider, ParameterDescriptor parameter, ModelMetadata metadata, Object value)\r\n at
Microsoft.AspNetCore.Mvc.Internal.ControllerBinderDelegateProvider.<>c__DisplayClass0_0.<g__Bind|0>d.MoveNext()\r\n
--- End of stack trace from previous location where exception was thrown ---\r\n at
Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeInnerFilterAsync()\r\n at
Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter()\r\n at
Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context)\r\n at
Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)\r\n at
Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync()\r\n at
Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync()\r\n at
Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)\r\n at
Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware.Invoke(HttpContext context)\r\n at
Microsoft.Commerce.UniversalStore.Authorization.AuthorizationRuntime.WebAPI.AuthorizationRuntimeMiddleware.Invoke(HttpContext context)\r\n at
Microsoft.AspNetCore.Builder.Extensions.UsePathBaseMiddleware.Invoke(HttpContext context)\r\n at
RaaS.KnowledgeGateway.Service.API.Middlewares.RequestLoggerMiddleware.Invoke(HttpContext context) in D:\Source\Repos\2-MKG.RaaS.Service.Knowledge\Knowledge\RaaS.KnowledgeGateway.Service.Container\Middlewares\RequestLoggerMiddleware.cs:line 73\r\n at
RaaS.KnowledgeGateway.Service.API.Middlewares.RequestLoggerMiddleware.Invoke(HttpContext context) in D:\Source\Repos\2-MKG.RaaS.Service.Knowledge\Knowledge\RaaS.KnowledgeGateway.Service.Container\Middlewares\RequestLoggerMiddleware.cs:line 100\r\n at
RaaS.KnowledgeGateway.Service.API.Middlewares.ErrorHandlerMiddleware.Invoke(HttpContext context) in D:\Source\Repos\2-MKG.RaaS.Service.Knowledge\Knowledge\RaaS.KnowledgeGateway.Service.Container\Middlewares\ErrorHandlerMiddleware.cs:line 41

[Tratcher]

That's likely what you'd see if the client terminated the request body early. E.g. They disconnected before sending the number of bytes specified in the content-length or before the chunked terminator. Can you log the headers to see if the request was content-length or chunked?

If this were locally I'd say to capture a Wireshark trace to verify the disconnect at the TCP level. Not sure how you can trace that in service fabric.

[shreyagr]

That's likely what you'd see if the client terminated the request body early. E.g. They disconnected before sending the number of bytes specified in the content-length or before the chunked terminator. Can you log the headers to see if the request was content-length or chunked?

The requests are content-length. The client does not actually disconnect till 5 seconds, so that does not seem plausible. I'll try wireshark on the VMs but this happens on container instances, so not sure.

[Nagalakshhmi]

We are facing the same issue and failed in trials to find out a solution. Some one is saying that this is an expected error and some one is saying that this is a kestrel issue and it is resolved.

But still we are facing it. Could you please suggest to resolve it in the code part?

Thanks in advance!!

[Nagalakshhmi]

@shreyagr, Is this issue resolved at your end?.

[analogrelay]

Is anyone able to provide a runnable sample and/or wireshark trace? We don't have much to go on here unfortunately.

[analogrelay]

Closing as we don't really have any data to go on here. If anyone is able to provide some more detailed information here, feel free to comment and we can reopen our investigation!