diff --git a/benchmarks/Kestrel.Performance/Http1ConnectionBenchmark.cs b/benchmarks/Kestrel.Performance/Http1ConnectionBenchmark.cs index 638eb70cb3..78defbe0b0 100644 --- a/benchmarks/Kestrel.Performance/Http1ConnectionBenchmark.cs +++ b/benchmarks/Kestrel.Performance/Http1ConnectionBenchmark.cs @@ -9,7 +9,7 @@ using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Server.Kestrel.Core; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http; -using Microsoft.AspNetCore.Server.Kestrel.Performance.Mocks; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; using Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions.Internal; namespace Microsoft.AspNetCore.Server.Kestrel.Performance @@ -42,7 +42,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Performance ServiceContext = serviceContext, ConnectionFeatures = new FeatureCollection(), MemoryPool = memoryPool, - TimeoutControl = new MockTimeoutControl(), + TimeoutControl = new TimeoutControl(timeoutHandler: null), Transport = pair.Transport }); diff --git a/benchmarks/Kestrel.Performance/Http1ConnectionParsingOverheadBenchmark.cs b/benchmarks/Kestrel.Performance/Http1ConnectionParsingOverheadBenchmark.cs index 31e8d54aa3..c9da214414 100644 --- a/benchmarks/Kestrel.Performance/Http1ConnectionParsingOverheadBenchmark.cs +++ b/benchmarks/Kestrel.Performance/Http1ConnectionParsingOverheadBenchmark.cs @@ -8,7 +8,7 @@ using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Server.Kestrel.Core; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http; -using Microsoft.AspNetCore.Server.Kestrel.Performance.Mocks; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; using Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions.Internal; namespace Microsoft.AspNetCore.Server.Kestrel.Performance @@ -38,7 +38,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Performance ServiceContext = serviceContext, ConnectionFeatures = new FeatureCollection(), MemoryPool = memoryPool, - TimeoutControl = new MockTimeoutControl(), + TimeoutControl = new TimeoutControl(timeoutHandler: null), Transport = pair.Transport }); diff --git a/benchmarks/Kestrel.Performance/Mocks/MockTimeoutControl.cs b/benchmarks/Kestrel.Performance/Mocks/MockTimeoutControl.cs deleted file mode 100644 index 70565511ff..0000000000 --- a/benchmarks/Kestrel.Performance/Mocks/MockTimeoutControl.cs +++ /dev/null @@ -1,51 +0,0 @@ -// Copyright (c) .NET Foundation. All rights reserved. -// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. - -using Microsoft.AspNetCore.Server.Kestrel.Core; -using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; - -namespace Microsoft.AspNetCore.Server.Kestrel.Performance.Mocks -{ - public class MockTimeoutControl : ITimeoutControl - { - public void CancelTimeout() - { - } - - public void ResetTimeout(long ticks, TimeoutReason timeoutReason) - { - } - - public void SetTimeout(long ticks, TimeoutReason timeoutReason) - { - } - - public void StartTimingReads(MinDataRate minRate) - { - } - - public void StopTimingReads() - { - } - - public void PauseTimingReads() - { - } - - public void ResumeTimingReads() - { - } - - public void BytesRead(long count) - { - } - - public void StartTimingWrite(MinDataRate rate, long size) - { - } - - public void StopTimingWrite() - { - } - } -} diff --git a/benchmarks/Kestrel.Performance/RequestParsingBenchmark.cs b/benchmarks/Kestrel.Performance/RequestParsingBenchmark.cs index b5664bb9f6..efb11e5c9f 100644 --- a/benchmarks/Kestrel.Performance/RequestParsingBenchmark.cs +++ b/benchmarks/Kestrel.Performance/RequestParsingBenchmark.cs @@ -8,7 +8,7 @@ using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Server.Kestrel.Core; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http; -using Microsoft.AspNetCore.Server.Kestrel.Performance.Mocks; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; using Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions.Internal; namespace Microsoft.AspNetCore.Server.Kestrel.Performance @@ -42,7 +42,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Performance ConnectionFeatures = new FeatureCollection(), MemoryPool = _memoryPool, Transport = pair.Transport, - TimeoutControl = new MockTimeoutControl() + TimeoutControl = new TimeoutControl(timeoutHandler: null) }); http1Connection.Reset(); diff --git a/benchmarks/Kestrel.Performance/ResponseHeadersWritingBenchmark.cs b/benchmarks/Kestrel.Performance/ResponseHeadersWritingBenchmark.cs index be53f22bf9..94c5d863c5 100644 --- a/benchmarks/Kestrel.Performance/ResponseHeadersWritingBenchmark.cs +++ b/benchmarks/Kestrel.Performance/ResponseHeadersWritingBenchmark.cs @@ -12,7 +12,7 @@ using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Server.Kestrel.Core; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http; -using Microsoft.AspNetCore.Server.Kestrel.Performance.Mocks; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; using Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions.Internal; using Microsoft.AspNetCore.Testing; @@ -132,7 +132,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Performance ServiceContext = serviceContext, ConnectionFeatures = new FeatureCollection(), MemoryPool = _memoryPool, - TimeoutControl = new MockTimeoutControl(), + TimeoutControl = new TimeoutControl(timeoutHandler: null), Transport = _pair.Transport }); diff --git a/src/Kestrel.Core/Internal/Http/Http1Connection.cs b/src/Kestrel.Core/Internal/Http/Http1Connection.cs index 486af7fb00..68554aff49 100644 --- a/src/Kestrel.Core/Internal/Http/Http1Connection.cs +++ b/src/Kestrel.Core/Internal/Http/Http1Connection.cs @@ -122,6 +122,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http Input.CancelPendingRead(); } + public void HandleRequestHeadersTimeout() + => SendTimeoutResponse(); + public void ParseRequest(ReadOnlySequence buffer, out SequencePosition consumed, out SequencePosition examined) { consumed = buffer.Start; diff --git a/src/Kestrel.Core/Internal/Http2/Http2Connection.cs b/src/Kestrel.Core/Internal/Http2/Http2Connection.cs index e3968fc14d..d744728714 100644 --- a/src/Kestrel.Core/Internal/Http2/Http2Connection.cs +++ b/src/Kestrel.Core/Internal/Http2/Http2Connection.cs @@ -4,6 +4,7 @@ using System; using System.Buffers; using System.Collections.Concurrent; +using System.Diagnostics; using System.IO; using System.IO.Pipelines; using System.Security.Authentication; @@ -105,7 +106,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 public PipeReader Input => _context.Transport.Input; public IKestrelTrace Log => _context.ServiceContext.Log; public IFeatureCollection ConnectionFeatures => _context.ConnectionFeatures; - public KestrelServerOptions ServerOptions => _context.ServiceContext.ServerOptions; + public ITimeoutControl TimeoutControl => _context.TimeoutControl; + public KestrelServerLimits Limits => _context.ServiceContext.ServerOptions.Limits; internal Http2PeerSettings ServerSettings => _serverSettings; @@ -139,6 +141,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 public void StopProcessingNextRequest() => StopProcessingNextRequest(true); + public void HandleRequestHeadersTimeout() + { + Log.ConnectionBadRequest(ConnectionId, BadHttpRequestException.GetException(RequestRejectionReason.RequestHeadersTimeout)); + Abort(new ConnectionAbortedException(CoreStrings.BadRequest_RequestHeadersTimeout)); + } + public void StopProcessingNextRequest(bool sendGracefulGoAway = false) { lock (_stateLock) @@ -174,6 +182,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 try { ValidateTlsRequirements(); + TimeoutControl.SetTimeout(Limits.KeepAliveTimeout.Ticks, TimeoutReason.KeepAlive); if (!await TryReadPrefaceAsync()) { @@ -298,7 +307,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 await _streamsCompleted.Task; - _context.TimeoutControl.StartDrainTimeout(ServerOptions.Limits.MinResponseDataRate, ServerOptions.Limits.MaxResponseBufferSize); + TimeoutControl.StartDrainTimeout(Limits.MinResponseDataRate, Limits.MaxResponseBufferSize); _frameWriter.Complete(); } @@ -551,30 +560,46 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 } else { - // Start a new stream - _currentHeadersStream = new Http2Stream(new Http2StreamContext + // Cancel keep-alive timeout and start header timeout if necessary. The keep-alive timeout can be + // started on another thread so the lock is necessary. + lock (_stateLock) { - ConnectionId = ConnectionId, - StreamId = _incomingFrame.StreamId, - ServiceContext = _context.ServiceContext, - ConnectionFeatures = _context.ConnectionFeatures, - MemoryPool = _context.MemoryPool, - LocalEndPoint = _context.LocalEndPoint, - RemoteEndPoint = _context.RemoteEndPoint, - StreamLifetimeHandler = this, - ClientPeerSettings = _clientSettings, - ServerPeerSettings = _serverSettings, - FrameWriter = _frameWriter, - ConnectionInputFlowControl = _inputFlowControl, - ConnectionOutputFlowControl = _outputFlowControl, - TimeoutControl = _context.TimeoutControl, - }); + if (TimeoutControl.TimerReason != TimeoutReason.None) + { + Debug.Assert(TimeoutControl.TimerReason == TimeoutReason.KeepAlive, "Non keep-alive timeout set at start of stream."); + TimeoutControl.CancelTimeout(); + } - _currentHeadersStream.Reset(); - _headerFlags = _incomingFrame.HeadersFlags; + if (!_incomingFrame.HeadersEndHeaders) + { + TimeoutControl.SetTimeout(Limits.RequestHeadersTimeout.Ticks, TimeoutReason.RequestHeaders); + } - var headersPayload = payload.Slice(0, _incomingFrame.HeadersPayloadLength); // Minus padding - return DecodeHeadersAsync(application, _incomingFrame.HeadersEndHeaders, headersPayload); + // Start a new stream + _currentHeadersStream = new Http2Stream(new Http2StreamContext + { + ConnectionId = ConnectionId, + StreamId = _incomingFrame.StreamId, + ServiceContext = _context.ServiceContext, + ConnectionFeatures = _context.ConnectionFeatures, + MemoryPool = _context.MemoryPool, + LocalEndPoint = _context.LocalEndPoint, + RemoteEndPoint = _context.RemoteEndPoint, + StreamLifetimeHandler = this, + ClientPeerSettings = _clientSettings, + ServerPeerSettings = _serverSettings, + FrameWriter = _frameWriter, + ConnectionInputFlowControl = _inputFlowControl, + ConnectionOutputFlowControl = _outputFlowControl, + TimeoutControl = TimeoutControl, + }); + + _currentHeadersStream.Reset(); + _headerFlags = _incomingFrame.HeadersFlags; + + var headersPayload = payload.Slice(0, _incomingFrame.HeadersPayloadLength); // Minus padding + return DecodeHeadersAsync(application, _incomingFrame.HeadersEndHeaders, headersPayload); + } } } @@ -835,7 +860,17 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 } else { - return DecodeHeadersAsync(application, _incomingFrame.ContinuationEndHeaders, payload); + lock (_stateLock) + { + Debug.Assert(TimeoutControl.TimerReason == TimeoutReason.RequestHeaders, "Received continuation frame without request header timeout being set."); + + if (_incomingFrame.HeadersEndHeaders) + { + TimeoutControl.CancelTimeout(); + } + + return DecodeHeadersAsync(application, _incomingFrame.ContinuationEndHeaders, payload); + } } } @@ -849,24 +884,22 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 return Task.CompletedTask; } + // This is always called with the _stateLock acquired. private Task DecodeHeadersAsync(IHttpApplication application, bool endHeaders, ReadOnlySequence payload) { try { - lock (_stateLock) + _highestOpenedStreamId = _currentHeadersStream.StreamId; + _hpackDecoder.Decode(payload, endHeaders, handler: this); + + if (endHeaders) { - _highestOpenedStreamId = _currentHeadersStream.StreamId; - _hpackDecoder.Decode(payload, endHeaders, handler: this); - - if (endHeaders) + if (_state != Http2ConnectionState.Closed) { - if (_state != Http2ConnectionState.Closed) - { - StartStream(application); - } - - ResetRequestHeaderParsingState(); + StartStream(application); } + + ResetRequestHeaderParsingState(); } } catch (Http2StreamErrorException) @@ -979,7 +1012,16 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 Input.CancelPendingRead(); } - if (_state != Http2ConnectionState.Open) + if (_state == Http2ConnectionState.Open) + { + // If we're awaiting headers, either a new stream will be started, or there will be a connection + // error possibly due to a request header timeout, so no need to start a keep-alive timeout. + if (TimeoutControl.TimerReason != TimeoutReason.RequestHeaders) + { + TimeoutControl.SetTimeout(Limits.KeepAliveTimeout.Ticks, TimeoutReason.KeepAlive); + } + } + else { // Complete the task waiting on all streams to finish _streamsCompleted.TrySetResult(null); @@ -1164,6 +1206,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2 } else if (state == Http2ConnectionState.Closed) { + // This cancels keep-alive and request header timeouts, but not the response drain timeout. + TimeoutControl.CancelTimeout(); Log.Http2ConnectionClosed(_context.ConnectionId, _highestOpenedStreamId); } } diff --git a/src/Kestrel.Core/Internal/HttpConnection.cs b/src/Kestrel.Core/Internal/HttpConnection.cs index f88c03fbe7..8c866f57a5 100644 --- a/src/Kestrel.Core/Internal/HttpConnection.cs +++ b/src/Kestrel.Core/Internal/HttpConnection.cs @@ -47,10 +47,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal _timeoutControl = new TimeoutControl(this); } - // For testing - internal HttpProtocol Http1Connection => _http1Connection; - internal IDebugger Debugger { get; set; } = DebuggerWrapper.Singleton; - public string ConnectionId => _context.ConnectionId; public IPEndPoint LocalEndPoint => _context.LocalEndPoint; public IPEndPoint RemoteEndPoint => _context.RemoteEndPoint; @@ -196,9 +192,10 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal } // For testing only - internal void Initialize(IDuplexPipe transport) + internal void Initialize(IRequestProcessor requestProcessor) { - _requestProcessor = _http1Connection = new Http1Connection(CreateDerivedContext(transport)); + _requestProcessor = requestProcessor; + _http1Connection = requestProcessor as Http1Connection; _protocolSelectionState = ProtocolSelectionState.Selected; } @@ -379,17 +376,17 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal switch (reason) { case TimeoutReason.KeepAlive: - _http1Connection.StopProcessingNextRequest(); + _requestProcessor.StopProcessingNextRequest(); break; case TimeoutReason.RequestHeaders: - _http1Connection.SendTimeoutResponse(); + _requestProcessor.HandleRequestHeadersTimeout(); break; case TimeoutReason.ReadDataRate: Log.RequestBodyMinimumDataRateNotSatisfied(_context.ConnectionId, _http1Connection.TraceIdentifier, _http1Connection.MinRequestBodyDataRate.BytesPerSecond); _http1Connection.SendTimeoutResponse(); break; case TimeoutReason.WriteDataRate: - Log.ResponseMinimumDataRateNotSatisfied(_http1Connection.ConnectionIdFeature, _http1Connection.TraceIdentifier); + Log.ResponseMinimumDataRateNotSatisfied(_context.ConnectionId, _http1Connection?.TraceIdentifier); Abort(new ConnectionAbortedException(CoreStrings.ConnectionTimedBecauseResponseMininumDataRateNotSatisfied)); break; case TimeoutReason.RequestBodyDrain: diff --git a/src/Kestrel.Core/Internal/IRequestProcessor.cs b/src/Kestrel.Core/Internal/IRequestProcessor.cs index b83a56d7ae..23dbea150e 100644 --- a/src/Kestrel.Core/Internal/IRequestProcessor.cs +++ b/src/Kestrel.Core/Internal/IRequestProcessor.cs @@ -11,6 +11,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal { Task ProcessRequestsAsync(IHttpApplication application); void StopProcessingNextRequest(); + void HandleRequestHeadersTimeout(); void OnInputOrOutputCompleted(); void Abort(ConnectionAbortedException ex); } diff --git a/src/Kestrel.Core/Internal/Infrastructure/ITimeoutControl.cs b/src/Kestrel.Core/Internal/Infrastructure/ITimeoutControl.cs index 69f0362ce8..c1d169992b 100644 --- a/src/Kestrel.Core/Internal/Infrastructure/ITimeoutControl.cs +++ b/src/Kestrel.Core/Internal/Infrastructure/ITimeoutControl.cs @@ -5,6 +5,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure { public interface ITimeoutControl { + TimeoutReason TimerReason { get; } + void SetTimeout(long ticks, TimeoutReason timeoutReason); void ResetTimeout(long ticks, TimeoutReason timeoutReason); void CancelTimeout(); diff --git a/src/Kestrel.Core/Internal/Infrastructure/TimeoutControl.cs b/src/Kestrel.Core/Internal/Infrastructure/TimeoutControl.cs index 6aa349827c..eec50242ba 100644 --- a/src/Kestrel.Core/Internal/Infrastructure/TimeoutControl.cs +++ b/src/Kestrel.Core/Internal/Infrastructure/TimeoutControl.cs @@ -14,7 +14,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure private long _lastTimestamp; private long _timeoutTimestamp = long.MaxValue; - private TimeoutReason _timeoutReason; private readonly object _readTimingLock = new object(); private MinDataRate _minReadRate; @@ -32,6 +31,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure _timeoutHandler = timeoutHandler; } + public TimeoutReason TimerReason { get; private set; } + internal IDebugger Debugger { get; set; } = DebuggerWrapper.Singleton; public void Initialize(DateTimeOffset now) @@ -56,9 +57,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure { if (timestamp > Interlocked.Read(ref _timeoutTimestamp)) { + var timeoutReason = TimerReason; + CancelTimeout(); - _timeoutHandler.OnTimeout(_timeoutReason); + _timeoutHandler.OnTimeout(timeoutReason); } } } @@ -117,7 +120,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure public void SetTimeout(long ticks, TimeoutReason timeoutReason) { - Debug.Assert(_timeoutTimestamp == long.MaxValue, "Concurrent timeouts are not supported"); + Debug.Assert(_timeoutTimestamp == long.MaxValue, "Concurrent timeouts are not supported."); AssignTimeout(ticks, timeoutReason); } @@ -130,11 +133,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure public void CancelTimeout() { Interlocked.Exchange(ref _timeoutTimestamp, long.MaxValue); + + TimerReason = TimeoutReason.None; } private void AssignTimeout(long ticks, TimeoutReason timeoutReason) { - _timeoutReason = timeoutReason; + TimerReason = timeoutReason; // Add Heartbeat.Interval since this can be called right before the next heartbeat. Interlocked.Exchange(ref _timeoutTimestamp, _lastTimestamp + ticks + Heartbeat.Interval.Ticks); diff --git a/src/Kestrel.Core/Internal/Infrastructure/ITimeoutReason.cs b/src/Kestrel.Core/Internal/Infrastructure/TimeoutReason.cs similarity index 96% rename from src/Kestrel.Core/Internal/Infrastructure/ITimeoutReason.cs rename to src/Kestrel.Core/Internal/Infrastructure/TimeoutReason.cs index b6900b4501..c7b1a5da5c 100644 --- a/src/Kestrel.Core/Internal/Infrastructure/ITimeoutReason.cs +++ b/src/Kestrel.Core/Internal/Infrastructure/TimeoutReason.cs @@ -5,6 +5,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure { public enum TimeoutReason { + None, KeepAlive, RequestHeaders, ReadDataRate, diff --git a/src/Kestrel.Transport.Libuv/Internal/ILibuvTrace.cs b/src/Kestrel.Transport.Libuv/Internal/ILibuvTrace.cs index 4906efadf0..51394bc4c7 100644 --- a/src/Kestrel.Transport.Libuv/Internal/ILibuvTrace.cs +++ b/src/Kestrel.Transport.Libuv/Internal/ILibuvTrace.cs @@ -12,7 +12,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal void ConnectionReadFin(string connectionId); - void ConnectionWriteFin(string connectionId); + void ConnectionWriteFin(string connectionId, string reason); void ConnectionWrite(string connectionId, int count); @@ -25,7 +25,5 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal void ConnectionPause(string connectionId); void ConnectionResume(string connectionId); - - void ConnectionAborted(string connectionId, string message); } } diff --git a/src/Kestrel.Transport.Libuv/Internal/LibuvConnection.cs b/src/Kestrel.Transport.Libuv/Internal/LibuvConnection.cs index 4d01959cda..428860737f 100644 --- a/src/Kestrel.Transport.Libuv/Internal/LibuvConnection.cs +++ b/src/Kestrel.Transport.Libuv/Internal/LibuvConnection.cs @@ -95,8 +95,10 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal } finally { + inputError = inputError ?? _abortReason ?? new ConnectionAbortedException("The libuv transport's send loop completed gracefully."); + // Now, complete the input so that no more reads can happen - Input.Complete(inputError ?? _abortReason ?? new ConnectionAbortedException("The libuv transport's send loop completed gracefully.")); + Input.Complete(inputError); Output.Complete(outputError); // Make sure it isn't possible for a paused read to resume reading after calling uv_close @@ -104,7 +106,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal Input.CancelPendingFlush(); // Send a FIN - Log.ConnectionWriteFin(ConnectionId); + Log.ConnectionWriteFin(ConnectionId, inputError.Message); // We're done with the socket now _socket.Dispose(); @@ -119,8 +121,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal public override void Abort(ConnectionAbortedException abortReason) { - Log.ConnectionAborted(ConnectionId, abortReason?.Message); - _abortReason = abortReason; // Cancel WriteOutputAsync loop after setting _abortReason. diff --git a/src/Kestrel.Transport.Libuv/Internal/LibuvTrace.cs b/src/Kestrel.Transport.Libuv/Internal/LibuvTrace.cs index fa70bd3853..cef5b8e119 100644 --- a/src/Kestrel.Transport.Libuv/Internal/LibuvTrace.cs +++ b/src/Kestrel.Transport.Libuv/Internal/LibuvTrace.cs @@ -19,8 +19,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal private static readonly Action _connectionReadFin = LoggerMessage.Define(LogLevel.Debug, new EventId(6, nameof(ConnectionReadFin)), @"Connection id ""{ConnectionId}"" received FIN."); - private static readonly Action _connectionWriteFin = - LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(ConnectionWriteFin)), @"Connection id ""{ConnectionId}"" sending FIN."); + private static readonly Action _connectionWriteFin = + LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(ConnectionWriteFin)), @"Connection id ""{ConnectionId}"" sending FIN because: ""{Reason}"""); // ConnectionWrite: Reserved: 11 @@ -32,9 +32,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal private static readonly Action _connectionReset = LoggerMessage.Define(LogLevel.Debug, new EventId(19, nameof(ConnectionReset)), @"Connection id ""{ConnectionId}"" reset."); - private static readonly Action _connectionAborted = - LoggerMessage.Define(LogLevel.Debug, new EventId(20, nameof(ConnectionAborted)), @"Connection id ""{ConnectionId}"" closing because: ""{Message}"""); - private readonly ILogger _logger; public LibuvTrace(ILogger logger) @@ -53,9 +50,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal _connectionReadFin(_logger, connectionId, null); } - public void ConnectionWriteFin(string connectionId) + public void ConnectionWriteFin(string connectionId, string reason) { - _connectionWriteFin(_logger, connectionId, null); + _connectionWriteFin(_logger, connectionId, reason, null); } public void ConnectionWrite(string connectionId, int count) @@ -90,11 +87,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal _connectionResume(_logger, connectionId, null); } - public void ConnectionAborted(string connectionId, string message) - { - _connectionAborted(_logger, connectionId, message, null); - } - public IDisposable BeginScope(TState state) => _logger.BeginScope(state); public bool IsEnabled(LogLevel logLevel) => _logger.IsEnabled(logLevel); diff --git a/src/Kestrel.Transport.Sockets/Internal/ISocketsTrace.cs b/src/Kestrel.Transport.Sockets/Internal/ISocketsTrace.cs index 585bfcc816..afb7190142 100644 --- a/src/Kestrel.Transport.Sockets/Internal/ISocketsTrace.cs +++ b/src/Kestrel.Transport.Sockets/Internal/ISocketsTrace.cs @@ -10,7 +10,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal { void ConnectionReadFin(string connectionId); - void ConnectionWriteFin(string connectionId); + void ConnectionWriteFin(string connectionId, string reason); void ConnectionError(string connectionId, Exception ex); @@ -19,7 +19,5 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal void ConnectionPause(string connectionId); void ConnectionResume(string connectionId); - - void ConnectionAborted(string connectionId, string message); } } diff --git a/src/Kestrel.Transport.Sockets/Internal/SocketConnection.cs b/src/Kestrel.Transport.Sockets/Internal/SocketConnection.cs index f78cd69584..8f5a3ca0a6 100644 --- a/src/Kestrel.Transport.Sockets/Internal/SocketConnection.cs +++ b/src/Kestrel.Transport.Sockets/Internal/SocketConnection.cs @@ -92,8 +92,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal public override void Abort(ConnectionAbortedException abortReason) { - _trace.ConnectionAborted(ConnectionId, abortReason?.Message); - // Try to gracefully close the socket to match libuv behavior. Shutdown(abortReason); @@ -290,7 +288,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal // to half close the connection which is currently unsupported. _shutdownReason = shutdownReason ?? new ConnectionAbortedException("The Socket transport's send loop completed gracefully."); - _trace.ConnectionWriteFin(ConnectionId); + _trace.ConnectionWriteFin(ConnectionId, _shutdownReason.Message); try { diff --git a/src/Kestrel.Transport.Sockets/Internal/SocketsTrace.cs b/src/Kestrel.Transport.Sockets/Internal/SocketsTrace.cs index 53d902312b..7d29e82666 100644 --- a/src/Kestrel.Transport.Sockets/Internal/SocketsTrace.cs +++ b/src/Kestrel.Transport.Sockets/Internal/SocketsTrace.cs @@ -19,8 +19,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal private static readonly Action _connectionReadFin = LoggerMessage.Define(LogLevel.Debug, new EventId(6, nameof(ConnectionReadFin)), @"Connection id ""{ConnectionId}"" received FIN."); - private static readonly Action _connectionWriteFin = - LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(ConnectionWriteFin)), @"Connection id ""{ConnectionId}"" sending FIN."); + private static readonly Action _connectionWriteFin = + LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(ConnectionWriteFin)), @"Connection id ""{ConnectionId}"" sending FIN because: ""{Reason}"""); // ConnectionWrite: Reserved: 11 @@ -32,9 +32,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal private static readonly Action _connectionReset = LoggerMessage.Define(LogLevel.Debug, new EventId(19, nameof(ConnectionReset)), @"Connection id ""{ConnectionId}"" reset."); - private static readonly Action _connectionAborted = - LoggerMessage.Define(LogLevel.Debug, new EventId(20, nameof(ConnectionAborted)), @"Connection id ""{ConnectionId}"" closing because: ""{Message}"""); - private readonly ILogger _logger; public SocketsTrace(ILogger logger) @@ -53,9 +50,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal _connectionReadFin(_logger, connectionId, null); } - public void ConnectionWriteFin(string connectionId) + public void ConnectionWriteFin(string connectionId, string reason) { - _connectionWriteFin(_logger, connectionId, null); + _connectionWriteFin(_logger, connectionId, reason, null); } public void ConnectionWrite(string connectionId, int count) @@ -90,11 +87,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal _connectionResume(_logger, connectionId, null); } - public void ConnectionAborted(string connectionId, string message) - { - _connectionAborted(_logger, connectionId, message, null); - } - public IDisposable BeginScope(TState state) => _logger.BeginScope(state); public bool IsEnabled(LogLevel logLevel) => _logger.IsEnabled(logLevel); diff --git a/test/Kestrel.Core.Tests/HttpConnectionTests.cs b/test/Kestrel.Core.Tests/HttpConnectionTests.cs index 565b7eeae4..476be4ffda 100644 --- a/test/Kestrel.Core.Tests/HttpConnectionTests.cs +++ b/test/Kestrel.Core.Tests/HttpConnectionTests.cs @@ -5,6 +5,7 @@ using System.IO.Pipelines; using System.Threading.Tasks; using Microsoft.AspNetCore.Connections; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; using Microsoft.AspNetCore.Testing; using Moq; @@ -29,10 +30,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests var httpConnection = new HttpConnection(httpConnectionContext); var aborted = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var http1Connection = new Http1Connection(httpConnectionContext); - httpConnection.Initialize(httpConnectionContext.Transport); - httpConnection.Http1Connection.Reset(); - httpConnection.Http1Connection.RequestAborted.Register(() => + httpConnection.Initialize(http1Connection); + http1Connection.Reset(); + http1Connection.RequestAborted.Register(() => { aborted.SetResult(null); }); diff --git a/test/Kestrel.InMemory.FunctionalTests/Http2/Http2ConnectionTests.cs b/test/Kestrel.InMemory.FunctionalTests/Http2/Http2ConnectionTests.cs index bbe3471951..1654641733 100644 --- a/test/Kestrel.InMemory.FunctionalTests/Http2/Http2ConnectionTests.cs +++ b/test/Kestrel.InMemory.FunctionalTests/Http2/Http2ConnectionTests.cs @@ -13,11 +13,9 @@ using Microsoft.AspNetCore.Connections; using Microsoft.AspNetCore.Server.Kestrel.Core.Features; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.HPack; -using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; using Microsoft.AspNetCore.Testing; using Microsoft.Extensions.Logging; using Microsoft.Net.Http.Headers; -using Moq; using Xunit; namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests @@ -2971,34 +2969,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests expectedErrorMessage: CoreStrings.FormatHttp2ErrorHeadersInterleaved(Http2FrameType.GOAWAY, streamId: 0, headersStreamId: 1)); } - [Fact] - public async Task GOAWAY_Received_ConnectionClosedWhenResponseNotDrainedAtMinimumDataRate() - { - var mockSystemClock = new MockSystemClock(); - var limits = _connectionContext.ServiceContext.ServerOptions.Limits; - var timeoutControl = _connectionContext.TimeoutControl; - - _timeoutControl.Initialize(mockSystemClock.UtcNow); - - await InitializeConnectionAsync(_noopApplication); - - await SendGoAwayAsync(); - - await WaitForConnectionStopAsync(expectedLastStreamId: 0, ignoreNonGoAwayFrames: false); - - mockSystemClock.UtcNow += - Heartbeat.Interval + - TimeSpan.FromSeconds(limits.MaxResponseBufferSize.Value * 2 / limits.MinResponseDataRate.BytesPerSecond); - _timeoutControl.Tick(mockSystemClock.UtcNow); - - _mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny()), Times.Never); - - mockSystemClock.UtcNow += TimeSpan.FromTicks(1); - _timeoutControl.Tick(mockSystemClock.UtcNow); - - _mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once); - } - [Fact] public async Task WINDOW_UPDATE_Received_StreamIdEven_ConnectionError() { diff --git a/test/Kestrel.InMemory.FunctionalTests/Http2/Http2TestBase.cs b/test/Kestrel.InMemory.FunctionalTests/Http2/Http2TestBase.cs index 49e82eb566..c1d1339c26 100644 --- a/test/Kestrel.InMemory.FunctionalTests/Http2/Http2TestBase.cs +++ b/test/Kestrel.InMemory.FunctionalTests/Http2/Http2TestBase.cs @@ -56,8 +56,10 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests protected readonly HPackDecoder _hpackDecoder; private readonly byte[] _headerEncodingBuffer = new byte[Http2PeerSettings.MinAllowedMaxFrameSize]; - protected readonly Mock _mockTimeoutHandler = new Mock(); protected readonly TimeoutControl _timeoutControl; + protected readonly Mock _mockConnectionContext = new Mock(); + protected readonly Mock _mockTimeoutHandler = new Mock(); + protected readonly Mock _mockTimeoutControl; protected readonly ConcurrentDictionary> _runningStreams = new ConcurrentDictionary>(); protected readonly Dictionary _receivedHeaders = new Dictionary(StringComparer.OrdinalIgnoreCase); @@ -105,7 +107,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests _pair = DuplexPipe.CreateConnectionPair(inputPipeOptions, outputPipeOptions); _hpackDecoder = new HPackDecoder((int)_clientSettings.HeaderTableSize, MaxRequestHeaderFieldSize); + _timeoutControl = new TimeoutControl(_mockTimeoutHandler.Object); + _mockTimeoutControl = new Mock(_timeoutControl) { CallBase = true }; _noopApplication = context => Task.CompletedTask; @@ -289,15 +293,20 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests _connectionContext = new HttpConnectionContext { - ConnectionContext = Mock.Of(), + ConnectionContext = _mockConnectionContext.Object, ConnectionFeatures = new FeatureCollection(), ServiceContext = new TestServiceContext(LoggerFactory, mockKestrelTrace.Object), MemoryPool = _memoryPool, Transport = _pair.Transport, - TimeoutControl = _timeoutControl + TimeoutControl = _mockTimeoutControl.Object }; _connection = new Http2Connection(_connectionContext); + + var httpConnection = new HttpConnection(_connectionContext); + httpConnection.Initialize(_connection); + _mockTimeoutHandler.Setup(h => h.OnTimeout(It.IsAny())) + .Callback(r => httpConnection.OnTimeout(r)); } public override void Dispose() @@ -1065,5 +1074,69 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests public ReadOnlySequence PayloadSequence => new ReadOnlySequence(Payload); } + + public class MockTimeoutControlBase : ITimeoutControl + { + private readonly ITimeoutControl _realTimeoutControl; + + public MockTimeoutControlBase(ITimeoutControl realTimeoutControl) + { + _realTimeoutControl = realTimeoutControl; + } + + public virtual TimeoutReason TimerReason => _realTimeoutControl.TimerReason; + + public virtual void SetTimeout(long ticks, TimeoutReason timeoutReason) + { + _realTimeoutControl.SetTimeout(ticks, timeoutReason); + } + + public virtual void ResetTimeout(long ticks, TimeoutReason timeoutReason) + { + _realTimeoutControl.ResetTimeout(ticks, timeoutReason); + } + + public virtual void CancelTimeout() + { + _realTimeoutControl.CancelTimeout(); + } + + + public virtual void StartTimingReads(MinDataRate minRate) + { + _realTimeoutControl.StartTimingReads(minRate); + } + + public virtual void PauseTimingReads() + { + _realTimeoutControl.PauseTimingReads(); + } + + public virtual void ResumeTimingReads() + { + _realTimeoutControl.ResumeTimingReads(); + } + + public virtual void StopTimingReads() + { + _realTimeoutControl.StopTimingReads(); + } + + public virtual void BytesRead(long count) + { + _realTimeoutControl.BytesRead(count); + } + + + public virtual void StartTimingWrite(MinDataRate minRate, long size) + { + _realTimeoutControl.StartTimingWrite(minRate, size); + } + + public virtual void StopTimingWrite() + { + _realTimeoutControl.StopTimingWrite(); + } + } } } diff --git a/test/Kestrel.InMemory.FunctionalTests/Http2/Http2TimeoutTests.cs b/test/Kestrel.InMemory.FunctionalTests/Http2/Http2TimeoutTests.cs new file mode 100644 index 0000000000..1fc51cfb12 --- /dev/null +++ b/test/Kestrel.InMemory.FunctionalTests/Http2/Http2TimeoutTests.cs @@ -0,0 +1,170 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Threading.Tasks; +using Microsoft.AspNetCore.Connections; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; +using Microsoft.AspNetCore.Testing; +using Moq; +using Xunit; + +namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests +{ + public class Http2TimeoutTests : Http2TestBase + { + [Fact] + public async Task HEADERS_NotReceivedInitially_WithinKeepAliveTimeout_ClosesConnection() + { + var mockSystemClock = new MockSystemClock(); + var limits = _connectionContext.ServiceContext.ServerOptions.Limits; + + _timeoutControl.Initialize(mockSystemClock.UtcNow); + + await InitializeConnectionAsync(_noopApplication); + + mockSystemClock.UtcNow += limits.KeepAliveTimeout + Heartbeat.Interval; + _timeoutControl.Tick(mockSystemClock.UtcNow); + + _mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny()), Times.Never); + + mockSystemClock.UtcNow += TimeSpan.FromTicks(1); + _timeoutControl.Tick(mockSystemClock.UtcNow); + + _mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.KeepAlive), Times.Once); + + await WaitForConnectionStopAsync(expectedLastStreamId: 0, ignoreNonGoAwayFrames: false); + } + + [Fact] + public async Task HEADERS_NotReceivedAfterFirstRequest_WithinKeepAliveTimeout_ClosesConnection() + { + var mockSystemClock = new MockSystemClock(); + var limits = _connectionContext.ServiceContext.ServerOptions.Limits; + + _timeoutControl.Initialize(mockSystemClock.UtcNow); + + await InitializeConnectionAsync(_noopApplication); + + mockSystemClock.UtcNow += limits.KeepAliveTimeout + Heartbeat.Interval; + _timeoutControl.Tick(mockSystemClock.UtcNow); + + // keep-alive timeout set but not fired. + _mockTimeoutControl.Verify(c => c.SetTimeout(It.IsAny(), TimeoutReason.KeepAlive), Times.Once); + _mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny()), Times.Never); + + // The KeepAlive timeout is set when the stream completes processing on a background thread, so we need to hook the + // keep-alive set afterwards to make a reliable test. + var setTimeoutTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + _mockTimeoutControl.Setup(c => c.SetTimeout(It.IsAny(), TimeoutReason.KeepAlive)).Callback((t, r) => + { + _timeoutControl.SetTimeout(t, r); + setTimeoutTcs.SetResult(null); + }); + + // Send continuation frame to verify intermediate request header timeout doesn't interfere with keep-alive timeout. + await SendHeadersAsync(1, Http2HeadersFrameFlags.NONE, _browserRequestHeaders); + await SendEmptyContinuationFrameAsync(1, Http2ContinuationFrameFlags.END_HEADERS); + await SendDataAsync(1, new Memory(), endStream: true); + + _mockTimeoutControl.Verify(c => c.SetTimeout(It.IsAny(), TimeoutReason.RequestHeaders), Times.Once); + + await ExpectAsync(Http2FrameType.HEADERS, + withLength: 55, + withFlags: (byte)Http2HeadersFrameFlags.END_HEADERS, + withStreamId: 1); + await ExpectAsync(Http2FrameType.DATA, + withLength: 0, + withFlags: (byte)Http2DataFrameFlags.END_STREAM, + withStreamId: 1); + + await setTimeoutTcs.Task.DefaultTimeout(); + + mockSystemClock.UtcNow += limits.KeepAliveTimeout + Heartbeat.Interval; + _timeoutControl.Tick(mockSystemClock.UtcNow); + + _mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny()), Times.Never); + + mockSystemClock.UtcNow += TimeSpan.FromTicks(1); + _timeoutControl.Tick(mockSystemClock.UtcNow); + + _mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.KeepAlive), Times.Once); + + await WaitForConnectionStopAsync(expectedLastStreamId: 1, ignoreNonGoAwayFrames: false); + } + + [Fact] + public async Task HEADERS_ReceivedWithoutAllCONTINUATIONs_WithinRequestHeadersTimeout_AbortsConnection() + { + var mockSystemClock = new MockSystemClock(); + var limits = _connectionContext.ServiceContext.ServerOptions.Limits; + + _mockConnectionContext.Setup(c => c.Abort(It.IsAny())).Callback(ex => + { + // Emulate transport abort so the _connectionTask completes. + _pair.Application.Output.Complete(ex); + }); + + _timeoutControl.Initialize(mockSystemClock.UtcNow); + + await InitializeConnectionAsync(_noopApplication); + + await SendHeadersAsync(1, Http2HeadersFrameFlags.NONE, _browserRequestHeaders); + + await SendEmptyContinuationFrameAsync(1, Http2ContinuationFrameFlags.NONE); + + mockSystemClock.UtcNow += limits.RequestHeadersTimeout + Heartbeat.Interval; + _timeoutControl.Tick(mockSystemClock.UtcNow); + + _mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny()), Times.Never); + + await SendEmptyContinuationFrameAsync(1, Http2ContinuationFrameFlags.NONE); + + mockSystemClock.UtcNow += TimeSpan.FromTicks(1); + _timeoutControl.Tick(mockSystemClock.UtcNow); + + _mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.RequestHeaders), Times.Once); + + await WaitForConnectionErrorAsync( + ignoreNonGoAwayFrames: false, + expectedLastStreamId: 1, + Http2ErrorCode.INTERNAL_ERROR, + CoreStrings.BadRequest_RequestHeadersTimeout); + + _mockConnectionContext.Verify(c =>c.Abort(It.Is(e => + e.Message == CoreStrings.BadRequest_RequestHeadersTimeout)), Times.Once); + } + + [Fact] + public async Task ResponseDrain_SlowerThanMinimumDataRate_AbortsConnection() + { + var mockSystemClock = new MockSystemClock(); + var limits = _connectionContext.ServiceContext.ServerOptions.Limits; + + _timeoutControl.Initialize(mockSystemClock.UtcNow); + + await InitializeConnectionAsync(_noopApplication); + + await SendGoAwayAsync(); + + await WaitForConnectionStopAsync(expectedLastStreamId: 0, ignoreNonGoAwayFrames: false); + + mockSystemClock.UtcNow += + TimeSpan.FromSeconds(limits.MaxResponseBufferSize.Value * 2 / limits.MinResponseDataRate.BytesPerSecond) + + Heartbeat.Interval; + _timeoutControl.Tick(mockSystemClock.UtcNow); + + _mockTimeoutHandler.Verify(h => h.OnTimeout(It.IsAny()), Times.Never); + _mockConnectionContext.Verify(c => c.Abort(It.IsAny()), Times.Never); + + mockSystemClock.UtcNow += TimeSpan.FromTicks(1); + _timeoutControl.Tick(mockSystemClock.UtcNow); + + _mockTimeoutHandler.Verify(h => h.OnTimeout(TimeoutReason.WriteDataRate), Times.Once); + + _mockConnectionContext.Verify(c =>c.Abort(It.Is(e => + e.Message == CoreStrings.ConnectionTimedBecauseResponseMininumDataRateNotSatisfied)), Times.Once); + } + } +} diff --git a/test/Kestrel.Transport.BindTests/AddressRegistrationTests.cs b/test/Kestrel.Transport.BindTests/AddressRegistrationTests.cs index 219db7c252..98abbc3a5c 100644 --- a/test/Kestrel.Transport.BindTests/AddressRegistrationTests.cs +++ b/test/Kestrel.Transport.BindTests/AddressRegistrationTests.cs @@ -117,7 +117,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests await RegisterIPEndPoint_Success(endpoint, testUrl, 443); } - [ConditionalTheory(Skip="https://github.com/aspnet/KestrelHttpServer/issues/2434")] + [ConditionalTheory] [MemberData(nameof(AddressRegistrationDataIPv6))] [IPv6SupportedCondition] public async Task RegisterAddresses_IPv6_Success(string addressInput, string[] testUrls) diff --git a/test/Kestrel.Transport.FunctionalTests/ResponseTests.cs b/test/Kestrel.Transport.FunctionalTests/ResponseTests.cs index a36c0dc89f..539f701cab 100644 --- a/test/Kestrel.Transport.FunctionalTests/ResponseTests.cs +++ b/test/Kestrel.Transport.FunctionalTests/ResponseTests.cs @@ -456,95 +456,98 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests [Fact] public async Task ConnectionClosedWhenResponseDoesNotSatisfyMinimumDataRate() { - using (StartLog(out var loggerFactory, "ConnClosedWhenRespDoesNotSatisfyMin")) + var logger = LoggerFactory.CreateLogger($"{ typeof(ResponseTests).FullName}.{ nameof(ConnectionClosedWhenResponseDoesNotSatisfyMinimumDataRate)}"); + const int chunkSize = 1024; + const int chunks = 256 * 1024; + var responseSize = chunks * chunkSize; + var chunkData = new byte[chunkSize]; + + var responseRateTimeoutMessageLogged = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var connectionStopMessageLogged = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var requestAborted = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var appFuncCompleted = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + + var mockKestrelTrace = new Mock(); + mockKestrelTrace + .Setup(trace => trace.ResponseMinimumDataRateNotSatisfied(It.IsAny(), It.IsAny())) + .Callback(() => responseRateTimeoutMessageLogged.SetResult(null)); + mockKestrelTrace + .Setup(trace => trace.ConnectionStop(It.IsAny())) + .Callback(() => connectionStopMessageLogged.SetResult(null)); + + var testContext = new TestServiceContext(LoggerFactory, mockKestrelTrace.Object) { - var logger = loggerFactory.CreateLogger($"{ typeof(ResponseTests).FullName}.{ nameof(ConnectionClosedWhenResponseDoesNotSatisfyMinimumDataRate)}"); - const int chunkSize = 1024; - const int chunks = 256 * 1024; - var responseSize = chunks * chunkSize; - var chunkData = new byte[chunkSize]; - - var responseRateTimeoutMessageLogged = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); - var connectionStopMessageLogged = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); - var requestAborted = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); - var appFuncCompleted = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); - - var mockKestrelTrace = new Mock(); - mockKestrelTrace - .Setup(trace => trace.ResponseMinimumDataRateNotSatisfied(It.IsAny(), It.IsAny())) - .Callback(() => responseRateTimeoutMessageLogged.SetResult(null)); - mockKestrelTrace - .Setup(trace => trace.ConnectionStop(It.IsAny())) - .Callback(() => connectionStopMessageLogged.SetResult(null)); - - var testContext = new TestServiceContext(loggerFactory, mockKestrelTrace.Object) + ServerOptions = { - ServerOptions = + Limits = { - Limits = - { - MinResponseDataRate = new MinDataRate(bytesPerSecond: 1024 * 1024, gracePeriod: TimeSpan.FromSeconds(2)) - } - } - }; - - testContext.InitializeHeartbeat(); - - var listenOptions = new ListenOptions(new IPEndPoint(IPAddress.Loopback, 0)); - listenOptions.ConnectionAdapters.Add(new LoggingConnectionAdapter(loggerFactory.CreateLogger())); - - var appLogger = loggerFactory.CreateLogger("App"); - async Task App(HttpContext context) - { - appLogger.LogInformation("Request received"); - context.RequestAborted.Register(() => requestAborted.SetResult(null)); - - context.Response.ContentLength = responseSize; - - try - { - for (var i = 0; i < chunks; i++) - { - await context.Response.Body.WriteAsync(chunkData, 0, chunkData.Length, context.RequestAborted); - appLogger.LogInformation("Wrote chunk of {chunkSize} bytes", chunkSize); - } - } - catch (OperationCanceledException) - { - appFuncCompleted.SetResult(null); - throw; - } - finally - { - await requestAborted.Task.DefaultTimeout(); + MinResponseDataRate = new MinDataRate(bytesPerSecond: 1024 * 1024, gracePeriod: TimeSpan.FromSeconds(2)) } } + }; - using (var server = new TestServer(App, testContext, listenOptions)) + testContext.InitializeHeartbeat(); + + var appLogger = LoggerFactory.CreateLogger("App"); + async Task App(HttpContext context) + { + appLogger.LogInformation("Request received"); + context.RequestAborted.Register(() => requestAborted.SetResult(null)); + + context.Response.ContentLength = responseSize; + + var i = 0; + + try { - using (var connection = server.CreateConnection()) + for (; i < chunks; i++) { - logger.LogInformation("Sending request"); - await connection.Send( - "GET / HTTP/1.1", - "Host:", - "", - ""); - - logger.LogInformation("Sent request"); - - var sw = Stopwatch.StartNew(); - logger.LogInformation("Waiting for connection to abort."); - - await requestAborted.Task.DefaultTimeout(); - await responseRateTimeoutMessageLogged.Task.DefaultTimeout(); - await connectionStopMessageLogged.Task.DefaultTimeout(); - await appFuncCompleted.Task.DefaultTimeout(); - await AssertStreamAborted(connection.Stream, chunkSize * chunks); - - sw.Stop(); - logger.LogInformation("Connection was aborted after {totalMilliseconds}ms.", sw.ElapsedMilliseconds); + await context.Response.Body.WriteAsync(chunkData, 0, chunkData.Length, context.RequestAborted); + await Task.Yield(); } + + appFuncCompleted.SetException(new Exception("This shouldn't be reached.")); + } + catch (OperationCanceledException) + { + appFuncCompleted.SetResult(null); + throw; + } + catch (Exception ex) + { + appFuncCompleted.SetException(ex); + } + finally + { + appLogger.LogInformation("Wrote {total} bytes", chunkSize * i); + await requestAborted.Task.DefaultTimeout(); + } + } + + using (var server = new TestServer(App, testContext)) + { + using (var connection = server.CreateConnection()) + { + logger.LogInformation("Sending request"); + await connection.Send( + "GET / HTTP/1.1", + "Host:", + "", + ""); + + logger.LogInformation("Sent request"); + + var sw = Stopwatch.StartNew(); + logger.LogInformation("Waiting for connection to abort."); + + await requestAborted.Task.DefaultTimeout(); + await responseRateTimeoutMessageLogged.Task.DefaultTimeout(); + await connectionStopMessageLogged.Task.DefaultTimeout(); + await appFuncCompleted.Task.DefaultTimeout(); + await AssertStreamAborted(connection.Stream, chunkSize * chunks); + + sw.Stop(); + logger.LogInformation("Connection was aborted after {totalMilliseconds}ms.", sw.ElapsedMilliseconds); } } }