Improve logging of request drain timeout (#2480)

benchmarks/Kestrel.Performance/Mocks/MockTrace.cs

@@ -40,6 +40,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Performance
         public void ApplicationNeverCompleted(string connectionId) { }
         public void RequestBodyStart(string connectionId, string traceIdentifier) { }
         public void RequestBodyDone(string connectionId, string traceIdentifier) { }
+        public void RequestBodyNotEntirelyRead(string connectionId, string traceIdentifier) { }
+        public void RequestBodyDrainTimedOut(string connectionId, string traceIdentifier) { }
         public void RequestBodyMininumDataRateNotSatisfied(string connectionId, string traceIdentifier, double rate) { }
         public void ResponseMininumDataRateNotSatisfied(string connectionId, string traceIdentifier) { }
         public void Http2ConnectionError(string connectionId, Http2ConnectionErrorException ex) { }

src/Kestrel.Core/BadHttpRequestException.cs

@@ -13,14 +13,15 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core
 {
     public sealed class BadHttpRequestException : IOException
     {
-        private BadHttpRequestException(string message, int statusCode)
+        private BadHttpRequestException(string message, int statusCode, RequestRejectionReason reason)
-            : this(message, statusCode, null)
+            : this(message, statusCode, reason, null)
         { }
 
-        private BadHttpRequestException(string message, int statusCode, HttpMethod? requiredMethod)
+        private BadHttpRequestException(string message, int statusCode, RequestRejectionReason reason, HttpMethod? requiredMethod)
             : base(message)
         {
             StatusCode = statusCode;
+            Reason = reason;
 
             if (requiredMethod.HasValue)
             {
@@ -32,6 +33,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core
 
         internal StringValues AllowedHeader { get; }
 
+        internal RequestRejectionReason Reason { get; }
+
         [StackTraceHidden]
         internal static void Throw(RequestRejectionReason reason)
         {
@@ -49,70 +52,70 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core
             switch (reason)
             {
                 case RequestRejectionReason.InvalidRequestHeadersNoCRLF:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_InvalidRequestHeadersNoCRLF, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_InvalidRequestHeadersNoCRLF, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.InvalidRequestLine:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_InvalidRequestLine, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_InvalidRequestLine, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.MalformedRequestInvalidHeaders:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MalformedRequestInvalidHeaders, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MalformedRequestInvalidHeaders, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.MultipleContentLengths:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MultipleContentLengths, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MultipleContentLengths, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.UnexpectedEndOfRequestContent:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_UnexpectedEndOfRequestContent, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_UnexpectedEndOfRequestContent, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.BadChunkSuffix:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_BadChunkSuffix, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_BadChunkSuffix, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.BadChunkSizeData:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_BadChunkSizeData, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_BadChunkSizeData, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.ChunkedRequestIncomplete:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_ChunkedRequestIncomplete, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_ChunkedRequestIncomplete, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.InvalidCharactersInHeaderName:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_InvalidCharactersInHeaderName, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_InvalidCharactersInHeaderName, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.RequestLineTooLong:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_RequestLineTooLong, StatusCodes.Status414UriTooLong);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_RequestLineTooLong, StatusCodes.Status414UriTooLong, reason);
                     break;
                 case RequestRejectionReason.HeadersExceedMaxTotalSize:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_HeadersExceedMaxTotalSize, StatusCodes.Status431RequestHeaderFieldsTooLarge);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_HeadersExceedMaxTotalSize, StatusCodes.Status431RequestHeaderFieldsTooLarge, reason);
                     break;
                 case RequestRejectionReason.TooManyHeaders:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_TooManyHeaders, StatusCodes.Status431RequestHeaderFieldsTooLarge);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_TooManyHeaders, StatusCodes.Status431RequestHeaderFieldsTooLarge, reason);
                     break;
                 case RequestRejectionReason.RequestBodyTooLarge:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_RequestBodyTooLarge, StatusCodes.Status413PayloadTooLarge);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_RequestBodyTooLarge, StatusCodes.Status413PayloadTooLarge, reason);
                     break;
                 case RequestRejectionReason.RequestHeadersTimeout:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_RequestHeadersTimeout, StatusCodes.Status408RequestTimeout);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_RequestHeadersTimeout, StatusCodes.Status408RequestTimeout, reason);
                     break;
                 case RequestRejectionReason.RequestBodyTimeout:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_RequestBodyTimeout, StatusCodes.Status408RequestTimeout);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_RequestBodyTimeout, StatusCodes.Status408RequestTimeout, reason);
                     break;
                 case RequestRejectionReason.OptionsMethodRequired:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MethodNotAllowed, StatusCodes.Status405MethodNotAllowed, HttpMethod.Options);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MethodNotAllowed, StatusCodes.Status405MethodNotAllowed, reason, HttpMethod.Options);
                     break;
                 case RequestRejectionReason.ConnectMethodRequired:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MethodNotAllowed, StatusCodes.Status405MethodNotAllowed, HttpMethod.Connect);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MethodNotAllowed, StatusCodes.Status405MethodNotAllowed, reason, HttpMethod.Connect);
                     break;
                 case RequestRejectionReason.MissingHostHeader:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MissingHostHeader, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MissingHostHeader, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.MultipleHostHeaders:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MultipleHostHeaders, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_MultipleHostHeaders, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.InvalidHostHeader:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_InvalidHostHeader, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_InvalidHostHeader, StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.UpgradeRequestCannotHavePayload:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest_UpgradeRequestCannotHavePayload, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest_UpgradeRequestCannotHavePayload, StatusCodes.Status400BadRequest, reason);
                     break;
                 default:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest, StatusCodes.Status400BadRequest, reason);
                     break;
             }
             return ex;
@@ -137,34 +140,34 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core
             switch (reason)
             {
                 case RequestRejectionReason.InvalidRequestLine:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidRequestLine_Detail(detail), StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidRequestLine_Detail(detail), StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.InvalidRequestTarget:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidRequestTarget_Detail(detail), StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidRequestTarget_Detail(detail), StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.InvalidRequestHeader:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidRequestHeader_Detail(detail), StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidRequestHeader_Detail(detail), StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.InvalidContentLength:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidContentLength_Detail(detail), StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidContentLength_Detail(detail), StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.UnrecognizedHTTPVersion:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_UnrecognizedHTTPVersion(detail), StatusCodes.Status505HttpVersionNotsupported);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_UnrecognizedHTTPVersion(detail), StatusCodes.Status505HttpVersionNotsupported, reason);
                     break;
                 case RequestRejectionReason.FinalTransferCodingNotChunked:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_FinalTransferCodingNotChunked(detail), StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_FinalTransferCodingNotChunked(detail), StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.LengthRequired:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_LengthRequired(detail), StatusCodes.Status411LengthRequired);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_LengthRequired(detail), StatusCodes.Status411LengthRequired, reason);
                     break;
                 case RequestRejectionReason.LengthRequiredHttp10:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_LengthRequiredHttp10(detail), StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_LengthRequiredHttp10(detail), StatusCodes.Status400BadRequest, reason);
                     break;
                 case RequestRejectionReason.InvalidHostHeader:
-                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidHostHeader_Detail(detail), StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.FormatBadRequest_InvalidHostHeader_Detail(detail), StatusCodes.Status400BadRequest, reason);
                     break;
                 default:
-                    ex = new BadHttpRequestException(CoreStrings.BadRequest, StatusCodes.Status400BadRequest);
+                    ex = new BadHttpRequestException(CoreStrings.BadRequest, StatusCodes.Status400BadRequest, reason);
                     break;
             }
             return ex;

src/Kestrel.Core/Internal/Http/Http1MessageBody.cs

@@ -3,12 +3,11 @@
 
 using System;
 using System.Buffers;
-using System.Collections;
 using System.IO;
 using System.IO.Pipelines;
 using System.Threading.Tasks;
+using Microsoft.AspNetCore.Connections;
 using Microsoft.AspNetCore.Http;
-using Microsoft.AspNetCore.Connections.Abstractions;
 using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure;
 
 namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
@@ -125,9 +124,36 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
             return _pumpTask;
         }
 
-        protected override async Task OnConsumeAsync()
+        protected override Task OnConsumeAsync()
         {
-            _context.TimeoutControl.SetTimeout(Constants.RequestBodyDrainTimeout.Ticks, TimeoutAction.SendTimeoutResponse);
+            try
+            {
+                if (_context.RequestBodyPipe.Reader.TryRead(out var readResult))
+                {
+                    _context.RequestBodyPipe.Reader.AdvanceTo(readResult.Buffer.End);
+
+                    if (readResult.IsCompleted)
+                    {
+                        return Task.CompletedTask;
+                    }
+                }
+            }
+            catch (BadHttpRequestException ex)
+            {
+                // At this point, the response has already been written, so this won't result in a 4XX response;
+                // however, we still need to stop the request processing loop and log.
+                _context.SetBadRequestState(ex);
+                return Task.CompletedTask;
+            }
+
+            return OnConsumeAsyncAwaited();
+        }
+
+        private async Task OnConsumeAsyncAwaited()
+        {
+            Log.RequestBodyNotEntirelyRead(_context.ConnectionIdFeature, _context.TraceIdentifier);
+
+            _context.TimeoutControl.SetTimeout(Constants.RequestBodyDrainTimeout.Ticks, TimeoutAction.AbortConnection);
 
             try
             {
@@ -138,6 +164,14 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
                     _context.RequestBodyPipe.Reader.AdvanceTo(result.Buffer.End);
                 } while (!result.IsCompleted);
             }
+            catch (BadHttpRequestException ex)
+            {
+                _context.SetBadRequestState(ex);
+            }
+            catch (ConnectionAbortedException)
+            {
+                Log.RequestBodyDrainTimedOut(_context.ConnectionIdFeature, _context.TraceIdentifier);
+            }
             finally
             {
                 _context.TimeoutControl.CancelTimeout();

src/Kestrel.Core/Internal/Http/HttpProtocol.cs

@@ -300,8 +300,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
             (RequestBody, ResponseBody) = _streams.Start(messageBody);
         }
 
-        public void PauseStreams() => _streams.Pause();
-
         public void StopStreams() => _streams.Stop();
 
         // For testing
@@ -493,7 +491,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
         {
             // Keep-alive is default for HTTP/1.1 and HTTP/2; parsing and errors will change its value
             _keepAlive = true;
-            do
+
+            while (_keepAlive)
             {
                 BeginRequestProcessing();
 
@@ -525,7 +524,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
 
                 var httpContext = application.CreateContext(this);
 
-                BadHttpRequestException badRequestException = null;
                 try
                 {
                     KestrelEventSource.Log.RequestStart(this);
@@ -538,11 +536,17 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
                         VerifyResponseContentLength();
                     }
                 }
+                catch (BadHttpRequestException ex)
+                {
+                    // Capture BadHttpRequestException for further processing
+                    // This has to be caught here so StatusCode is set properly before disposing the HttpContext
+                    // (DisposeContext logs StatusCode).
+                    SetBadRequestState(ex);
+                    ReportApplicationError(ex);
+                }
                 catch (Exception ex)
                 {
                     ReportApplicationError(ex);
-                    // Capture BadHttpRequestException for further processing
-                    badRequestException = ex as BadHttpRequestException;
                 }
 
                 KestrelEventSource.Log.RequestStop(this);
@@ -556,9 +560,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
                     await FireOnStarting();
                 }
 
-                PauseStreams();
+                // At this point all user code that needs use to the request or response streams has completed.
+                // Using these streams in the OnCompleted callback is not allowed.
+                StopStreams();
 
-                if (badRequestException == null)
+                // 4XX responses are written by TryProduceInvalidRequestResponse during connection tear down.
+                if (_requestRejectedException == null)
                 {
                     // If _requestAbort is set, the connection has already been closed.
                     if (_requestAborted == 0)
@@ -576,21 +583,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
                         // HttpContext.Response.StatusCode is correctly set when
                         // IHttpContextFactory.Dispose(HttpContext) is called.
                         await ProduceEnd();
-
-                        // ForZeroContentLength does not complete the reader nor the writer
-                        if (!messageBody.IsEmpty)
-                        {
-                            try
-                            {
-                                // Finish reading the request body in case the app did not.
-                                await messageBody.ConsumeAsync();
-                            }
-                            catch (BadHttpRequestException ex)
-                            {
-                                // Capture BadHttpRequestException for further processing
-                                badRequestException = ex;
-                            }
-                        }
                     }
                     else if (!HasResponseStarted)
                     {
@@ -605,19 +597,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
                     await FireOnCompleted();
                 }
 
-                if (badRequestException != null)
-                {
-                    // Handle BadHttpRequestException thrown during app execution or remaining message body consumption.
-                    // This has to be caught here so StatusCode is set properly before disposing the HttpContext
-                    // (DisposeContext logs StatusCode).
-                    SetBadRequestState(badRequestException);
-                }
-
                 application.DisposeContext(httpContext, _applicationException);
 
-                // StopStreams should be called before the end of the "if (!_requestProcessingStopping)" block
+                // Even for non-keep-alive requests, try to consume the entire body to avoid RSTs.
-                // to ensure InitializeStreams has been called.
+                if (_requestAborted == 0 && _requestRejectedException == null && !messageBody.IsEmpty)
-                StopStreams();
+                {
+                    await messageBody.ConsumeAsync();
+                }
 
                 if (HasStartedConsumingRequestBody)
                 {
@@ -629,14 +615,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
                     // At this point both the request body pipe reader and writer should be completed.
                     RequestBodyPipe.Reset();
                 }
-
+            }
-                if (badRequestException != null)
-                {
-                    // Bad request reported, stop processing requests
-                    return;
-                }
-
-            } while (_keepAlive);
         }
 
         public void OnStarting(Func<object, Task> callback, object state)

src/Kestrel.Core/Internal/Http/HttpRequestStream.cs

@@ -169,11 +169,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
             }
         }
 
-        public void PauseAcceptingReads()
-        {
-            _state = HttpStreamState.Closed;
-        }
-
         public void StopAcceptingReads()
         {
             // Can't use dispose (or close) as can be disposed too early by user code

src/Kestrel.Core/Internal/Http/HttpResponseStream.cs

@@ -129,11 +129,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http
             }
         }
 
-        public void PauseAcceptingWrites()
-        {
-            _state = HttpStreamState.Closed;
-        }
-
         public void StopAcceptingWrites()
         {
             // Can't use dispose (or close) as can be disposed too early by user code

src/Kestrel.Core/Internal/Infrastructure/IKestrelTrace.cs

@@ -44,6 +44,10 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
 
         void RequestBodyDone(string connectionId, string traceIdentifier);
 
+        void RequestBodyNotEntirelyRead(string connectionId, string traceIdentifier);
+
+        void RequestBodyDrainTimedOut(string connectionId, string traceIdentifier);
+
         void RequestBodyMininumDataRateNotSatisfied(string connectionId, string traceIdentifier, double rate);
 
         void ResponseMininumDataRateNotSatisfied(string connectionId, string traceIdentifier);

src/Kestrel.Core/Internal/Infrastructure/KestrelTrace.cs

@@ -65,6 +65,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal
         private static readonly Action<ILogger, string, string, double, Exception> _requestBodyMinimumDataRateNotSatisfied =
             LoggerMessage.Define<string, string, double>(LogLevel.Information, new EventId(27, nameof(RequestBodyMininumDataRateNotSatisfied)), @"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.");
 
+        private static readonly Action<ILogger, string, string, Exception> _requestBodyNotEntirelyRead =
+            LoggerMessage.Define<string, string>(LogLevel.Information, new EventId(32, nameof(RequestBodyNotEntirelyRead)), @"Connection id ""{ConnectionId}"", Request id ""{TraceIdentifier}"": the application completed without reading the entire request body.");
+
+        private static readonly Action<ILogger, string, string, Exception> _requestBodyDrainTimedOut =
+            LoggerMessage.Define<string, string>(LogLevel.Information, new EventId(33, nameof(RequestBodyDrainTimedOut)), @"Connection id ""{ConnectionId}"", Request id ""{TraceIdentifier}"": automatic draining of the request body timed out after taking over 5 seconds.");
+
         private static readonly Action<ILogger, string, string, Exception> _responseMinimumDataRateNotSatisfied =
             LoggerMessage.Define<string, string>(LogLevel.Information, new EventId(28, nameof(ResponseMininumDataRateNotSatisfied)), @"Connection id ""{ConnectionId}"", Request id ""{TraceIdentifier}"": the connection was closed because the response was not read by the client at the specified minimum data rate.");
 
@@ -174,6 +180,16 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal
             _requestBodyMinimumDataRateNotSatisfied(_logger, connectionId, traceIdentifier, rate, null);
         }
 
+        public virtual void RequestBodyNotEntirelyRead(string connectionId, string traceIdentifier)
+        {
+            _requestBodyNotEntirelyRead(_logger, connectionId, traceIdentifier, null);
+        }
+
+        public virtual void RequestBodyDrainTimedOut(string connectionId, string traceIdentifier)
+        {
+            _requestBodyDrainTimedOut(_logger, connectionId, traceIdentifier, null);
+        }
+
         public virtual void ResponseMininumDataRateNotSatisfied(string connectionId, string traceIdentifier)
         {
             _responseMinimumDataRateNotSatisfied(_logger, connectionId, traceIdentifier, null);

src/Kestrel.Core/Internal/Infrastructure/Streams.cs

@@ -54,13 +54,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
             }
         }
 
-        public void Pause()
-        {
-            _request.PauseAcceptingReads();
-            _emptyRequest.PauseAcceptingReads();
-            _response.PauseAcceptingWrites();
-        }
-
         public void Stop()
         {
             _request.StopAcceptingReads();

test/Kestrel.Core.Tests/MessageBodyTests.cs

@@ -599,14 +599,16 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
         }
 
         [Fact]
-        public async Task ConsumeAsyncThrowsOnTimeout()
+        public async Task ConsumeAsyncCompletesAndDoesNotThrowOnTimeout()
         {
             using (var input = new TestInput())
             {
                 var mockTimeoutControl = new Mock<ITimeoutControl>();
-
                 input.Http1ConnectionContext.TimeoutControl = mockTimeoutControl.Object;
 
+                var mockLogger = new Mock<IKestrelTrace>();
+                input.Http1Connection.ServiceContext.Log = mockLogger.Object;
+
                 var body = Http1MessageBody.For(HttpVersion.Http11, new HttpRequestHeaders { HeaderContentLength = "5" }, input.Http1Connection);
 
                 // Add some input and read it to start PumpAsync
@@ -616,8 +618,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
                 // Time out on the next read
                 input.Http1Connection.SendTimeoutResponse();
 
-                var exception = await Assert.ThrowsAsync<BadHttpRequestException>(() => body.ConsumeAsync());
+                await body.ConsumeAsync();
-                Assert.Equal(StatusCodes.Status408RequestTimeout, exception.StatusCode);
+
+                mockLogger.Verify(logger => logger.ConnectionBadRequest(
+                    It.IsAny<string>(),
+                    It.Is<BadHttpRequestException>(ex => ex.Reason == RequestRejectionReason.RequestBodyTimeout)));
 
                 await body.StopAsync();
             }

test/Kestrel.FunctionalTests/RequestBodyTimeoutTests.cs

@@ -111,8 +111,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
                 }
             }
 
-            Assert.Contains(TestSink.Writes, w => w.EventId.Id == 17 && w.LogLevel == LogLevel.Information && w.Exception is BadHttpRequestException
+            Assert.Contains(TestSink.Writes, w => w.EventId.Id == 32 && w.LogLevel == LogLevel.Information);
-                && ((BadHttpRequestException)w.Exception).StatusCode == StatusCodes.Status408RequestTimeout);
+            Assert.Contains(TestSink.Writes, w => w.EventId.Id == 33 && w.LogLevel == LogLevel.Information);
         }
 
         [Fact(Skip="https://github.com/aspnet/KestrelHttpServer/issues/2464")]

test/Kestrel.FunctionalTests/ResponseTests.cs

@@ -341,7 +341,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
         [Fact]
         public async Task OnCompletedShouldNotBlockAResponse()
         {
-            var delay = Task.Delay(TestConstants.DefaultTimeout);
+            var delayTcs = new TaskCompletionSource<object>();
             var hostBuilder = TransportSelector.GetWebHostBuilder()
                 .UseKestrel()
                 .UseUrls("http://127.0.0.1:0/")
@@ -352,7 +352,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
                     {
                         context.Response.OnCompleted(async () =>
                         {
-                            await delay;
+                            await delayTcs.Task;
                         });
                         await context.Response.WriteAsync("hello, world");
                     });
@@ -366,8 +366,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests
                 {
                     var response = await client.GetAsync($"http://127.0.0.1:{host.GetPort()}/");
                     Assert.Equal(HttpStatusCode.OK, response.StatusCode);
-                    Assert.False(delay.IsCompleted);
                 }
+
+                delayTcs.SetResult(null);
             }
         }