Kestrelhttpserver: BadHttpRequestException: Request Timed Out randomly in Web API

[nforysinski]

Hosting a 2.0.0 web API on Azure in a web service with only one instance. The following exception occurred randomly today and was accompanied by CPU spikes. We do not yet know if the requests completely failed or were handling and these exceptions are transient. Since this is a web API, all requests are coming from a web context and the endpoints in question are anonymous POST requests with a [FromForm] request body. This is intermittent - it went away with no action taken on our part. The issue simply stopped occurring. The endpoint in question does not have any async/await decoration and is one of the highest requested endpoints as it is being hit automatically from a third-party vendor. Typical requests are roughly 8,000 per hour steadily during the day.

The accompanying message is "Request Timed Out"

Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException:
   at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.PipeCompletion.ThrowFailed (Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.Pipe.GetResult (Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.Pipe.Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.IReadableBufferAwaiter.GetResult (Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.MessageBody+<ReadAsync>d__22.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.FrameRequestStream+<ReadAsyncInternal>d__21.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.IO.StreamReader+<ReadBufferAsync>d__97.MoveNext (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.IO.StreamReader+<ReadAsyncInternal>d__64.MoveNext (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.WebUtilities.FormReader+<BufferAsync>d__41.MoveNext (Microsoft.AspNetCore.WebUtilities, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.WebUtilities.FormReader+<ReadNextPairAsyncImpl>d__34.MoveNext (Microsoft.AspNetCore.WebUtilities, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.WebUtilities.FormReader+<ReadFormAsync>d__43.MoveNext (Microsoft.AspNetCore.WebUtilities, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Http.Features.FormFeature+<InnerReadFormAsync>d__18.MoveNext (Microsoft.AspNetCore.Http, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Mvc.ModelBinding.FormValueProviderFactory+<AddValueProviderAsync>d__1.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Mvc.ModelBinding.CompositeValueProvider+<CreateAsync>d__3.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Mvc.ModelBinding.CompositeValueProvider+<CreateAsync>d__2.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerBinderDelegateProvider+<>c__DisplayClass0_0+<<CreateBinderDelegate>g__Bind0>d.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeInnerFilterAsync>d__14.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeNextExceptionFilterAsync>d__23.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeNextResourceFilter>d__22.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeFilterPipelineAsync>d__17.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeAsync>d__15.MoveNext (Microsoft.AspNetCore.Mvc.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Builder.RouterMiddleware+<Invoke>d__4.MoveNext (Microsoft.AspNetCore.Routing, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.ResponseCompression.ResponseCompressionMiddleware+<Invoke>d__3.MoveNext (Microsoft.AspNetCore.ResponseCompression, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6.MoveNext (Microsoft.AspNetCore.Authentication, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Cors.Infrastructure.CorsMiddleware+<Invoke>d__7.MoveNext (Microsoft.AspNetCore.Cors, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Server.IISIntegration.IISMiddleware+<Invoke>d__11.MoveNext (Microsoft.AspNetCore.Server.IISIntegration, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Hosting.Internal.RequestServicesContainerMiddleware+<Invoke>d__3.MoveNext (Microsoft.AspNetCore.Hosting, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Frame`1+<ProcessRequestsAsync>d__2.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.Frame`1+<ProcessRequestsAsync>d__2.MoveNext (Microsoft.AspNetCore.Server.Kestrel.Core, Version=2.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)

[Tratcher]

Is there a message for that exception?

[nforysinski]

@Tratcher Sorry! Added the exception message that we are getting. The message is "Request Timed Out"

[halter73]

This is likely another form of #2151.

[nforysinski]

Any chance of getting a patch on this one? If not, any options to mitigate it?

I am curious if you know if the requests are actually getting handled or if they are getting dropped. Pretty serious in production scenarios if the requests aren't getting fully handled.

[halter73]

@nforysinski Sorry for the delay. Can you try our public nightly feed for the upcoming ASP.NET patch? It includes a fix for #2151 which might be related.

These packages are not yet final or supported, so use them at your own risk.

[mayconbeserra]

Hi @halter73 I'm getting the same issue in our Stage Environment, which I need to fix ASAP. How can I fix that? is there any hotfix?

I'm using .NET Core (microsoft/aspnetcore:2.0.5)

[Tratcher]

@mayconbeserra did you try updating to the packages on https://dotnet.myget.org/gallery/aspnet-2018-feb-patch-public ?

[chrisowhite]

@Tratcher I've been getting this same error while calling the ReadFormAsync extension. I upgraded to the version on the February 2018 patch feed and I'm still seeing it with about the same frequency.

Microsoft.AspNetCore.Server.Kestrel.Core.BadHttpRequestException: Request timed out.
   at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.PipeCompletion.ThrowFailed()
   at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.Pipe.GetResult(ReadResult& result)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.Pipe.Microsoft.AspNetCore.Server.Kestrel.Internal.System.IO.Pipelines.IReadableBufferAwaiter.GetResult()
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.MessageBody.<ReadAsync>d__22.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.FrameRequestStream.<ReadAsyncInternal>d__21.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at System.IO.StreamReader.<ReadBufferAsync>d__65.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at System.IO.StreamReader.<ReadAsyncInternal>d__63.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.WebUtilities.FormReader.<BufferAsync>d__41.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.WebUtilities.FormReader.<ReadNextPairAsyncImpl>d__34.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.WebUtilities.FormReader.<ReadFormAsync>d__43.MoveNext()

[Tratcher]

@halter73 who is going to take a look at more of these timeoutes.

[halter73]

@chrisowhite Is it possible the request body isn't actually being uploaded at the default minimum rate of 240 bytes/second? If so, you can reconfigure the minimum request body data rate. This doc shows how in the "Minimum request body data rate" subsection.

[chrisowhite]

@halter73 I'd say it's highly unlikely as I'm seeing it on back channel communication to our identity server, but I won't go as far as it's impossible. I can try changing it and see what happens. This is in our dev environment, which sees about 8000 hourly requests to our idsrv, and I'll see it maybe 8 times a day. Our production environment is in the 200k hourly request range, but we haven't deployed our latest version there yet. I'll try updating and see what happens over the next couple of days.

[halter73]

@chrisowhite Do those requests happen to be coming from linux-based dotnet applications using HttpClient?

[chrisowhite]

All traffic to idsrv is coming from Windows-based dotnet applications using HttpClient. We have a mix of Core and full framework applications that depend on it. We've been using IdentityServer4 on net core 1.1 since May of last year. We're currently testing 2.0 and this is the first we're seeing this error.

[chrisowhite]

@halter73 We're using Serilog. Is there any targeted trace logging we can turn on to help troubleshoot?

[halter73]

You could try collecting "info"-level and higher logs from "Microsoft.AspNetCore.Server.Kestrel". You should be able to see logs like this: https://github.com/aspnet/KestrelHttpServer/blob/49cd0ef97fed1c64514b729c20598b6128567a95/src/Kestrel.Core/Internal/Infrastructure/KestrelTrace.cs#L68-L69.

Another thing you could try is writing middleware to buffer the entire request body into a MemoryStream an replace the context.Request.Body stream. When reading from the original request body stream fails, you can dump the contents of the MemoryStream into your log. That could help us determine how much of the request was received, whether it was corrupted, etc...

[chrisowhite]

I'll try both of the above. We've put our idsrv upgrade on hold due to this but we're doing just fine with our current version. I'm here to help in any way I can to figure this out.

[chrisowhite]

@halter73 I've been logging for a few days now with first attempting to read the body into a memory stream to log the content. All of the log messages indicate the exception is thrown before any of the content is read (empty MemoryStream reads through a StreamReader as empty string).

[chrisowhite]

Did a little more digging and found these:

Connection id "{ConnectionId}", Request id "{TraceIdentifier}": the request timed out because it was not sent by the client at a minimum of {Rate} bytes/second.

With rate being the default 240 bytes/second.

[halter73]

Not getting a response body would explain the connection timeout. Are you sure there isn't a problem with clients disconnecting mid-request?

[halter73]

Maybe you could measure the rate yourself by timing your reads as you're filling the memory stream.

[chrisowhite]

It's possible a client could disconnect mid-request if a deployment happens, as this is in our dev environment.

[chrisowhite]

Any suggestions on an easy way I can prove out the disconnect theory?

[halter73]

You could collect other trace-level-and-above logs with a matching connection id. If the client sent a FIN, you should see a log to that effect.

The problem is, if this is the result of client issue, the client wasn't sending a FIN. If the client was sending a FIN, you'd get an exception thrown from Request.Body.ReadAsync informing you that the body was truncated.

Instead it seems like the client just isn't sending data. That's why I recommended timing the reads yourself. This way you can test independently whether the Request.Body.ReadAsync call is taking over 5 seconds without receiving any data. If a request timeout happens within 5 seconds after you start reading the request body with the default configuration, that's a bug.

[chrisowhite]

Based on what you're saying I'm wondering if it's a client app being killed for a deployment. If that's the case then it's nothing to worry about. I have a feeling things are working the way they're supposed to but I'd like to prove it.

[chrisowhite]

It's been a few weeks, but wanted to update. Based on the log data we're seeing it looks like the new checks put in place in 2.x are working and it's likely an intermittent issue on our end. Given how rare this occurs we've decided to move forward and investigate as necessary.

[chrisowhite]

Thank you everyone for your assistance.

[zaozaoniao]

how is going on about the issue? I 'm still get the exception randomly in my production .
about 5 times per day..

The offical will pay attention to the issue ,right ?

[Huffers]

@Julian89757 have you checked it's not just the client occasionally sending at a rate under the KestrelServerLimits.MinRequestBodyDataRate?
I just tried writing a console app sending a long request at 1 byte/second, and found I get the same error and stack trace as the original post above - which seems like expected behaviour.

Also, issue #2194 looks like a duplicate of this.

Perhaps the real solution is to improve the Exception's message to state that the MinRequestBodyDataRate has been exceeded - so people don't search for the Exception & message, find these GitHub issues, and spend too long trying to figure out whether they've ran into a bug in Kestrel or not?

[halter73]

@Huffers Agreed about the exception message. In 2.1.0, we've improved some exception messages including this one. Now instead of "Request timed out", it reads "Reading the request body timed out due to data arriving too slowly. See MinRequestBodyDataRate." See #2356

[Huffers]

@halter73 Thanks, that's perfect :)

[aspnet-hello]

We periodically close 'discussion' issues that have not been updated in a long period of time.

We apologize if this causes any inconvenience. We ask that if you are still encountering an issue, please log a new issue with updated information and we will investigate.