diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/ConnectionHandler.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/ConnectionHandler.cs index ff075f35da..4cf062d7ca 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/ConnectionHandler.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/ConnectionHandler.cs @@ -1,6 +1,7 @@ // 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.Threading; using Microsoft.AspNetCore.Hosting.Server; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; @@ -11,6 +12,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal { public class ConnectionHandler : IConnectionHandler { + private static long _lastFrameConnectionId = long.MinValue; + private readonly ListenOptions _listenOptions; private readonly ServiceContext _serviceContext; private readonly IHttpApplication _application; @@ -28,6 +31,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal var outputPipe = connectionInfo.PipeFactory.Create(GetOutputPipeOptions(connectionInfo.OutputReaderScheduler)); var connectionId = CorrelationIdGenerator.GetNextId(); + var frameConnectionId = Interlocked.Increment(ref _lastFrameConnectionId); var frameContext = new FrameContext { @@ -44,6 +48,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal var connection = new FrameConnection(new FrameConnectionContext { ConnectionId = connectionId, + FrameConnectionId = frameConnectionId, ServiceContext = _serviceContext, PipeFactory = connectionInfo.PipeFactory, ConnectionAdapters = _listenOptions.ConnectionAdapters, diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/FrameConnection.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/FrameConnection.cs index a80d3f6e92..19014e8e7a 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/FrameConnection.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/FrameConnection.cs @@ -3,7 +3,9 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.IO; +using System.Threading; using System.Threading.Tasks; using Microsoft.AspNetCore.Server.Kestrel.Core.Adapter; using Microsoft.AspNetCore.Server.Kestrel.Core.Adapter.Internal; @@ -16,13 +18,17 @@ using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal { - public class FrameConnection : IConnectionContext + public class FrameConnection : IConnectionContext, ITimeoutControl { private readonly FrameConnectionContext _context; private readonly Frame _frame; private readonly List _connectionAdapters; private readonly TaskCompletionSource _frameStartedTcs = new TaskCompletionSource(); + private long _lastTimestamp; + private long _timeoutTimestamp = long.MaxValue; + private TimeoutAction _timeoutAction; + private AdaptedPipeline _adaptedPipeline; private Stream _filteredStream; private Task _adaptedPipelineTask = TaskCache.CompletedTask; @@ -32,6 +38,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal _context = context; _frame = context.Frame; _connectionAdapters = context.ConnectionAdapters; + context.ServiceContext.ConnectionManager.AddConnection(context.FrameConnectionId, this); } public string ConnectionId => _context.ConnectionId; @@ -55,11 +62,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal { _frame.Input = _context.Input.Reader; _frame.Output = _context.OutputProducer; + _frame.TimeoutControl = this; if (_connectionAdapters.Count == 0) { - _frame.Start(); - _frameStartedTcs.SetResult(null); + StartFrame(); } else { @@ -75,6 +82,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal public void OnConnectionClosed() { + _context.ServiceContext.ConnectionManager.RemoveConnection(_context.FrameConnectionId); Log.ConnectionStop(ConnectionId); KestrelEventSource.Log.ConnectionStop(this); } @@ -127,8 +135,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal } _frame.AdaptedConnections = adaptedConnections; - _frame.Start(); - _frameStartedTcs.SetResult(null); + StartFrame(); } catch (Exception ex) { @@ -161,5 +168,58 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal _context.OutputProducer.Dispose(); _context.Input.Reader.Complete(); } + + private void StartFrame() + { + _lastTimestamp = _context.ServiceContext.SystemClock.UtcNow.Ticks; + _frame.Start(); + _frameStartedTcs.SetResult(null); + } + + public void Tick(DateTimeOffset now) + { + var timestamp = now.Ticks; + + // TODO: Use PlatformApis.VolatileRead equivalent again + if (timestamp > Interlocked.Read(ref _timeoutTimestamp)) + { + CancelTimeout(); + + if (_timeoutAction == TimeoutAction.SendTimeoutResponse) + { + Timeout(); + } + + var ignore = StopAsync(); + } + + Interlocked.Exchange(ref _lastTimestamp, timestamp); + } + + public void SetTimeout(long ticks, TimeoutAction timeoutAction) + { + Debug.Assert(_timeoutTimestamp == long.MaxValue, "Concurrent timeouts are not supported"); + + AssignTimeout(ticks, timeoutAction); + } + + public void ResetTimeout(long ticks, TimeoutAction timeoutAction) + + { + AssignTimeout(ticks, timeoutAction); + } + + public void CancelTimeout() + { + Interlocked.Exchange(ref _timeoutTimestamp, long.MaxValue); + } + + private void AssignTimeout(long ticks, TimeoutAction timeoutAction) + { + _timeoutAction = timeoutAction; + + // 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/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/FrameConnectionContext.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/FrameConnectionContext.cs index f04ea5f877..c4edded73e 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/FrameConnectionContext.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/FrameConnectionContext.cs @@ -11,6 +11,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal public class FrameConnectionContext { public string ConnectionId { get; set; } + public long FrameConnectionId { get; set; } public ServiceContext ServiceContext { get; set; } public PipeFactory PipeFactory { get; set; } public List ConnectionAdapters { get; set; } diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/DateHeaderValueManager.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/DateHeaderValueManager.cs index 349345e5fe..b2cb874364 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/DateHeaderValueManager.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/DateHeaderValueManager.cs @@ -12,23 +12,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http /// /// Manages the generation of the date header value. /// - public class DateHeaderValueManager : IDisposable + public class DateHeaderValueManager : IHeartbeatHandler { private static readonly byte[] _datePreambleBytes = Encoding.ASCII.GetBytes("\r\nDate: "); - private readonly ISystemClock _systemClock; - private readonly TimeSpan _timeWithoutRequestsUntilIdle; - private readonly TimeSpan _timerInterval; - private readonly object _timerLocker = new object(); - private DateHeaderValues _dateValues; - private volatile bool _isDisposed = false; - private volatile bool _hadRequestsSinceLastTimerTick = false; - private Timer _dateValueTimer; - private long _lastRequestSeenTicks; - private volatile bool _timerIsRunning; - /// /// Initializes a new instance of the class. /// @@ -39,28 +28,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http // Internal for testing internal DateHeaderValueManager(ISystemClock systemClock) - : this( - systemClock: systemClock, - timeWithoutRequestsUntilIdle: TimeSpan.FromSeconds(10), - timerInterval: TimeSpan.FromSeconds(1)) { - } - - // Internal for testing - internal DateHeaderValueManager( - ISystemClock systemClock, - TimeSpan timeWithoutRequestsUntilIdle, - TimeSpan timerInterval) - { - if (systemClock == null) - { - throw new ArgumentNullException(nameof(systemClock)); - } - - _systemClock = systemClock; - _timeWithoutRequestsUntilIdle = timeWithoutRequestsUntilIdle; - _timerInterval = timerInterval; - _dateValueTimer = new Timer(TimerLoop, state: null, dueTime: Timeout.Infinite, period: Timeout.Infinite); + SetDateValues(systemClock.UtcNow); } /// @@ -68,102 +37,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http /// in accordance with http://www.w3.org/Protocols/rfc2616/rfc2616-sec14.html#sec14.18 /// /// The value in string and byte[] format. - public DateHeaderValues GetDateHeaderValues() - { - _hadRequestsSinceLastTimerTick = !_isDisposed; - - if (!_timerIsRunning) - { - StartTimer(); - } - - return _dateValues; - } - - /// - /// Releases all resources used by the current instance of . - /// - public void Dispose() - { - if (!_isDisposed) - { - _isDisposed = true; - _hadRequestsSinceLastTimerTick = false; - - lock (_timerLocker) - { - if (_dateValueTimer != null) - { - _timerIsRunning = false; - _dateValueTimer.Dispose(); - _dateValueTimer = null; - } - } - } - } - - /// - /// Starts the timer - /// - private void StartTimer() - { - var now = _systemClock.UtcNow; - SetDateValues(now); - - if (!_isDisposed) - { - lock (_timerLocker) - { - if (!_timerIsRunning && _dateValueTimer != null) - { - _timerIsRunning = true; - _dateValueTimer.Change(_timerInterval, _timerInterval); - } - } - } - } - - /// - /// Stops the timer - /// - private void StopTimer() - { - if (!_isDisposed) - { - lock (_timerLocker) - { - if (_dateValueTimer != null) - { - _timerIsRunning = false; - _dateValueTimer.Change(Timeout.Infinite, Timeout.Infinite); - _hadRequestsSinceLastTimerTick = false; - } - } - } - } + public DateHeaderValues GetDateHeaderValues() => _dateValues; // Called by the Timer (background) thread - private void TimerLoop(object state) + public void OnHeartbeat(DateTimeOffset now) { - var now = _systemClock.UtcNow; - SetDateValues(now); - - if (_hadRequestsSinceLastTimerTick) - { - // We served requests since the last tick, reset the flag and return as we're still active - _hadRequestsSinceLastTimerTick = false; - Interlocked.Exchange(ref _lastRequestSeenTicks, now.Ticks); - return; - } - - // No requests since the last timer tick, we need to check if we're beyond the idle threshold - // TODO: Use PlatformApis.VolatileRead equivalent again - if ((now.Ticks - Interlocked.Read(ref _lastRequestSeenTicks)) >= _timeWithoutRequestsUntilIdle.Ticks) - { - // No requests since idle threshold so stop the timer if it's still running - StopTimer(); - } } /// diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/Frame.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/Frame.cs index 9c4035ff8e..875e406463 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/Frame.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/Frame.cs @@ -74,8 +74,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http private int _remainingRequestHeadersBytesAllowed; private int _requestHeadersParsed; - protected readonly long _keepAliveMilliseconds; - private readonly long _requestHeadersTimeoutMilliseconds; + protected readonly long _keepAliveTicks; + private readonly long _requestHeadersTimeoutTicks; protected long _responseBytesWritten; @@ -91,8 +91,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http _parser = ServiceContext.HttpParserFactory(new FrameAdapter(this)); FrameControl = this; - _keepAliveMilliseconds = (long)ServerOptions.Limits.KeepAliveTimeout.TotalMilliseconds; - _requestHeadersTimeoutMilliseconds = (long)ServerOptions.Limits.RequestHeadersTimeout.TotalMilliseconds; + _keepAliveTicks = ServerOptions.Limits.KeepAliveTimeout.Ticks; + _requestHeadersTimeoutTicks = ServerOptions.Limits.RequestHeadersTimeout.Ticks; } public ServiceContext ServiceContext => _frameContext.ServiceContext; @@ -102,10 +102,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http public ISocketOutput Output { get; set; } public IEnumerable AdaptedConnections { get; set; } public ConnectionLifetimeControl LifetimeControl { get; set; } + public ITimeoutControl TimeoutControl { get; set; } - protected ITimeoutControl TimeoutControl => ConnectionInformation.TimeoutControl; protected IKestrelTrace Log => ServiceContext.Log; - private DateHeaderValueManager DateHeaderValueManager => ServiceContext.DateHeaderValueManager; // Hold direct reference to ServerOptions since this is used very often in the request processing path private KestrelServerOptions ServerOptions { get; } @@ -1017,7 +1016,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http break; } - TimeoutControl.ResetTimeout(_requestHeadersTimeoutMilliseconds, TimeoutAction.SendTimeoutResponse); + TimeoutControl.ResetTimeout(_requestHeadersTimeoutTicks, TimeoutAction.SendTimeoutResponse); _requestProcessingStatus = RequestProcessingStatus.ParsingRequestLine; goto case RequestProcessingStatus.ParsingRequestLine; diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/FrameOfT.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/FrameOfT.cs index 0d4ffe7544..4073bc0837 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/FrameOfT.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Http/FrameOfT.cs @@ -34,7 +34,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http { while (!_requestProcessingStopping) { - TimeoutControl.SetTimeout(_keepAliveMilliseconds, TimeoutAction.CloseConnection); + TimeoutControl.SetTimeout(_keepAliveTicks, TimeoutAction.CloseConnection); InitializeHeaders(); diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/FrameConnectionManager.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/FrameConnectionManager.cs new file mode 100644 index 0000000000..a789ea7c1d --- /dev/null +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/FrameConnectionManager.cs @@ -0,0 +1,38 @@ +// 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.Collections.Concurrent; + +namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure +{ + public class FrameConnectionManager : IHeartbeatHandler + { + private readonly ConcurrentDictionary _connections + = new ConcurrentDictionary(); + + public void AddConnection(long id, FrameConnection connection) + { + if (!_connections.TryAdd(id, connection)) + { + throw new ArgumentException(nameof(id)); + } + } + + public void RemoveConnection(long id) + { + if (!_connections.TryRemove(id, out _)) + { + throw new ArgumentException(nameof(id)); + } + } + + public void OnHeartbeat(DateTimeOffset now) + { + foreach (var kvp in _connections) + { + kvp.Value.Tick(now); + } + } + } +} diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/Heartbeat.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/Heartbeat.cs new file mode 100644 index 0000000000..089b779e92 --- /dev/null +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/Heartbeat.cs @@ -0,0 +1,70 @@ +// 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; +using Microsoft.Extensions.Logging; + +namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure +{ + public class Heartbeat : IDisposable + { + public static readonly TimeSpan Interval = TimeSpan.FromSeconds(1); + + private readonly IHeartbeatHandler[] _callbacks; + private readonly TimeSpan _interval; + private readonly ISystemClock _systemClock; + private readonly IKestrelTrace _trace; + private readonly Timer _timer; + private int _executingOnHeartbeat; + + public Heartbeat(IHeartbeatHandler[] callbacks, ISystemClock systemClock, IKestrelTrace trace) + : this(callbacks, systemClock, trace, Interval) + { + } + + // For testing + internal Heartbeat(IHeartbeatHandler[] callbacks, ISystemClock systemClock, IKestrelTrace trace, TimeSpan interval) + { + _callbacks = callbacks; + _interval = interval; + _systemClock = systemClock; + _trace = trace; + _timer = new Timer(OnHeartbeat, state: this, dueTime: _interval, period: _interval); + } + + // Called by the Timer (background) thread + private void OnHeartbeat(object state) + { + var now = _systemClock.UtcNow; + + if (Interlocked.Exchange(ref _executingOnHeartbeat, 1) == 0) + { + try + { + foreach (var callback in _callbacks) + { + callback.OnHeartbeat(now); + } + } + catch (Exception ex) + { + _trace.LogError(0, ex, $"{nameof(Heartbeat)}.{nameof(OnHeartbeat)}"); + } + finally + { + Interlocked.Exchange(ref _executingOnHeartbeat, 0); + } + } + else + { + _trace.TimerSlow(_interval, now); + } + } + + public void Dispose() + { + _timer.Dispose(); + } + } +} diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/IHeartbeatHandler.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/IHeartbeatHandler.cs new file mode 100644 index 0000000000..e6a355e829 --- /dev/null +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/IHeartbeatHandler.cs @@ -0,0 +1,12 @@ +// 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; + +namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure +{ + public interface IHeartbeatHandler + { + void OnHeartbeat(DateTimeOffset now); + } +} diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/IKestrelTrace.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/IKestrelTrace.cs index f14c1b33c7..67ef9b2b34 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/IKestrelTrace.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/IKestrelTrace.cs @@ -29,5 +29,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure void ConnectionBadRequest(string connectionId, BadHttpRequestException ex); void ApplicationError(string connectionId, string traceIdentifier, Exception ex); + + void TimerSlow(TimeSpan interval, DateTimeOffset now); + } } \ No newline at end of file diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/ISystemClock.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/ISystemClock.cs index e29312dda8..ddc5b1fd66 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/ISystemClock.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/ISystemClock.cs @@ -8,7 +8,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure /// /// Abstracts the system clock to facilitate testing. /// - internal interface ISystemClock + public interface ISystemClock { /// /// Retrieves the current system time in UTC. diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/ITimeoutControl.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/ITimeoutControl.cs similarity index 53% rename from src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/ITimeoutControl.cs rename to src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/ITimeoutControl.cs index 824263da13..d71b423873 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/ITimeoutControl.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/ITimeoutControl.cs @@ -1,12 +1,12 @@ // 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. -namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions +namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure { public interface ITimeoutControl { - void SetTimeout(long milliseconds, TimeoutAction timeoutAction); - void ResetTimeout(long milliseconds, TimeoutAction timeoutAction); + void SetTimeout(long ticks, TimeoutAction timeoutAction); + void ResetTimeout(long ticks, TimeoutAction timeoutAction); void CancelTimeout(); } } \ No newline at end of file diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/KestrelTrace.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/KestrelTrace.cs index cc7204e203..a1079fa633 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/KestrelTrace.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/KestrelTrace.cs @@ -45,6 +45,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal private static readonly Action _requestProcessingError = LoggerMessage.Define(LogLevel.Information, 20, @"Connection id ""{ConnectionId}"" request processing ended abnormally."); + private static readonly Action _timerSlow = + LoggerMessage.Define(LogLevel.Warning, 21, @"Heartbeat took longer than ""{interval}"" at ""{now}""."); + protected readonly ILogger _logger; public KestrelTrace(ILogger logger) @@ -107,6 +110,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal _requestProcessingError(_logger, connectionId, ex); } + public virtual void TimerSlow(TimeSpan interval, DateTimeOffset now) + { + _timerSlow(_logger, interval, now, null); + } + public virtual void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) => _logger.Log(logLevel, eventId, state, exception, formatter); diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/TimeoutAction.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/TimeoutAction.cs similarity index 78% rename from src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/TimeoutAction.cs rename to src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/TimeoutAction.cs index 06aae8627e..96af620550 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/TimeoutAction.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/Infrastructure/TimeoutAction.cs @@ -1,7 +1,7 @@ // 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. -namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions +namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure { public enum TimeoutAction { diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/ServiceContext.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/ServiceContext.cs index 4df0cb751f..72017e5d43 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/ServiceContext.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/Internal/ServiceContext.cs @@ -15,8 +15,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal public Func> HttpParserFactory { get; set; } + public ISystemClock SystemClock { get; set; } + public DateHeaderValueManager DateHeaderValueManager { get; set; } + public FrameConnectionManager ConnectionManager { get; set; } + public KestrelServerOptions ServerOptions { get; set; } } } diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Core/KestrelServer.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Core/KestrelServer.cs index d5962ee0a1..6b8085e3a5 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Core/KestrelServer.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Core/KestrelServer.cs @@ -29,7 +29,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core private readonly ITransportFactory _transportFactory; private bool _isRunning; - private DateHeaderValueManager _dateHeaderValueManager; + private Heartbeat _heartbeat; public KestrelServer( IOptions options, @@ -85,9 +85,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core } _isRunning = true; - _dateHeaderValueManager = new DateHeaderValueManager(); var trace = new KestrelTrace(_logger); + var systemClock = new SystemClock(); + var dateHeaderValueManager = new DateHeaderValueManager(systemClock); + var connectionManager = new FrameConnectionManager(); + _heartbeat = new Heartbeat(new IHeartbeatHandler[] { dateHeaderValueManager, connectionManager }, systemClock, trace); + IThreadPool threadPool; if (InternalOptions.ThreadPoolDispatching) { @@ -103,7 +107,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core Log = trace, HttpParserFactory = frameParser => new HttpParser(frameParser.Frame.ServiceContext.Log), ThreadPool = threadPool, - DateHeaderValueManager = _dateHeaderValueManager, + SystemClock = systemClock, + DateHeaderValueManager = dateHeaderValueManager, + ConnectionManager = connectionManager, ServerOptions = Options }; @@ -232,7 +238,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core Task.WaitAll(tasks); } - _dateHeaderValueManager?.Dispose(); + _heartbeat?.Dispose(); } private void ValidateOptions() diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/IConnectionContext.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/IConnectionContext.cs index 3cba9448b8..e38bc5d359 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/IConnectionContext.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/IConnectionContext.cs @@ -17,6 +17,5 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions void OnConnectionClosed(); Task StopAsync(); void Abort(Exception ex); - void Timeout(); } } diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/IConnectionInformation.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/IConnectionInformation.cs index f819a34913..a06bd16dd9 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/IConnectionInformation.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions/IConnectionInformation.cs @@ -14,8 +14,5 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions PipeFactory PipeFactory { get; } IScheduler InputWriterScheduler { get; } IScheduler OutputReaderScheduler { get; } - - // TODO: Remove timeout management from transport - ITimeoutControl TimeoutControl { get; } } } diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvConnection.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvConnection.cs index d0a5563de1..0e997c7b51 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvConnection.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvConnection.cs @@ -13,7 +13,7 @@ using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal { - public class LibuvConnection : LibuvConnectionContext, ITimeoutControl + public class LibuvConnection : LibuvConnectionContext { private const int MinAllocBufferSize = 2048; @@ -28,16 +28,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal private TaskCompletionSource _socketClosedTcs = new TaskCompletionSource(); - private long _lastTimestamp; - private long _timeoutTimestamp = long.MaxValue; - private TimeoutAction _timeoutAction; private WritableBuffer? _currentWritableBuffer; public LibuvConnection(ListenerContext context, UvStreamHandle socket) : base(context) { _socket = socket; socket.Connection = this; - TimeoutControl = this; var tcpHandle = _socket as UvTcpHandle; if (tcpHandle != null) @@ -45,8 +41,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal RemoteEndPoint = tcpHandle.GetPeerIPEndPoint(); LocalEndPoint = tcpHandle.GetSockIPEndPoint(); } - - _lastTimestamp = Thread.Loop.Now(); } // For testing @@ -74,7 +68,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal // Start socket prior to applying the ConnectionAdapter _socket.ReadStart(_allocCallback, _readCallback, this); - _lastTimestamp = Thread.Loop.Now(); // This *must* happen after socket.ReadStart // The socket output consumer is the only thing that can close the connection. If the @@ -110,24 +103,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal _socketClosedTcs.TrySetResult(null); } - // Called on Libuv thread - public void Tick(long timestamp) - { - if (timestamp > PlatformApis.VolatileRead(ref _timeoutTimestamp)) - { - TimeoutControl.CancelTimeout(); - - if (_timeoutAction == TimeoutAction.SendTimeoutResponse) - { - _connectionContext.Timeout(); - } - - StopAsync(); - } - - Interlocked.Exchange(ref _lastTimestamp, timestamp); - } - private static LibuvFunctions.uv_buf_t AllocCallback(UvStreamHandle handle, int suggestedSize, object state) { return ((LibuvConnection)state).OnAlloc(handle, suggestedSize); @@ -251,30 +226,5 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal } } } - - void ITimeoutControl.SetTimeout(long milliseconds, TimeoutAction timeoutAction) - { - Debug.Assert(_timeoutTimestamp == long.MaxValue, "Concurrent timeouts are not supported"); - - AssignTimeout(milliseconds, timeoutAction); - } - - void ITimeoutControl.ResetTimeout(long milliseconds, TimeoutAction timeoutAction) - { - AssignTimeout(milliseconds, timeoutAction); - } - - void ITimeoutControl.CancelTimeout() - { - Interlocked.Exchange(ref _timeoutTimestamp, long.MaxValue); - } - - private void AssignTimeout(long milliseconds, TimeoutAction timeoutAction) - { - _timeoutAction = timeoutAction; - - // Add LibuvThread.HeartbeatMilliseconds extra milliseconds since this can be called right before the next heartbeat. - Interlocked.Exchange(ref _timeoutTimestamp, _lastTimestamp + milliseconds + LibuvThread.HeartbeatMilliseconds); - } } } diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvConnectionContext.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvConnectionContext.cs index 4f76cc097f..6c9d0cfcf5 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvConnectionContext.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvConnectionContext.cs @@ -26,7 +26,5 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal public PipeFactory PipeFactory => ListenerContext.Thread.PipeFactory; public IScheduler InputWriterScheduler => ListenerContext.Thread; public IScheduler OutputReaderScheduler => ListenerContext.Thread; - - public ITimeoutControl TimeoutControl { get; set; } } } \ No newline at end of file diff --git a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvThread.cs b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvThread.cs index 11b279c66f..5fb6f33d00 100644 --- a/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvThread.cs +++ b/src/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv/Internal/LibuvThread.cs @@ -16,16 +16,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal { public class LibuvThread : IScheduler { - public const long HeartbeatMilliseconds = 1000; - - private static readonly LibuvFunctions.uv_walk_cb _heartbeatWalkCallback = (ptr, arg) => - { - var streamHandle = UvMemory.FromIntPtr(ptr) as UvStreamHandle; - var thisHandle = GCHandle.FromIntPtr(arg); - var libuvThread = (LibuvThread)thisHandle.Target; - streamHandle?.Connection?.Tick(libuvThread.Now); - }; - // maximum times the work queues swapped and are processed in a single pass // as completing a task may immediately have write data to put on the network // otherwise it needs to wait till the next pass of the libuv loop @@ -37,7 +27,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal private readonly TaskCompletionSource _threadTcs = new TaskCompletionSource(); private readonly UvLoopHandle _loop; private readonly UvAsyncHandle _post; - private readonly UvTimerHandle _heartbeatTimer; private Queue _workAdding = new Queue(1024); private Queue _workRunning = new Queue(1024); private Queue _closeHandleAdding = new Queue(256); @@ -49,7 +38,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal private ExceptionDispatchInfo _closeError; private readonly ILibuvTrace _log; private readonly TimeSpan _shutdownTimeout; - private IntPtr _thisPtr; public LibuvThread(LibuvTransport transport) { @@ -61,7 +49,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal _post = new UvAsyncHandle(_log); _thread = new Thread(ThreadStart); _thread.Name = nameof(LibuvThread); - _heartbeatTimer = new UvTimerHandle(_log); #if !DEBUG // Mark the thread as being as unimportant to keeping the process alive. // Don't do this for debug builds, so we know if the thread isn't terminating. @@ -170,7 +157,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal private void AllowStop() { - _heartbeatTimer.Stop(); _post.Unreference(); } @@ -269,8 +255,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal { _loop.Init(_transport.Libuv); _post.Init(_loop, OnPost, EnqueueCloseHandle); - _heartbeatTimer.Init(_loop, EnqueueCloseHandle); - _heartbeatTimer.Start(OnHeartbeat, timeout: HeartbeatMilliseconds, repeat: HeartbeatMilliseconds); _initCompleted = true; tcs.SetResult(0); } @@ -286,8 +270,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal try { - _thisPtr = GCHandle.ToIntPtr(thisHandle); - _loop.Run(); if (_stopImmediate) { @@ -298,7 +280,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal // run the loop one more time to delete the open handles _post.Reference(); _post.Dispose(); - _heartbeatTimer.Dispose(); // Ensure the Dispose operations complete in the event loop. _loop.Run(); @@ -333,12 +314,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal } while (wasWork && loopsRemaining > 0); } - private void OnHeartbeat(UvTimerHandle timer) - { - Now = Loop.Now(); - Walk(_heartbeatWalkCallback, _thisPtr); - } - private bool DoPostWork() { Queue queue; diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/DateHeaderValueManagerTests.cs b/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/DateHeaderValueManagerTests.cs index 875e0f5d73..8bcc60ea07 100644 --- a/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/DateHeaderValueManagerTests.cs +++ b/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/DateHeaderValueManagerTests.cs @@ -4,7 +4,9 @@ using System; using System.Threading.Tasks; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; using Microsoft.AspNetCore.Testing; +using Moq; using Xunit; namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests @@ -27,21 +29,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests { UtcNow = now }; - var timeWithoutRequestsUntilIdle = TimeSpan.FromSeconds(1); - var timerInterval = TimeSpan.FromSeconds(10); - var dateHeaderValueManager = new DateHeaderValueManager(systemClock, timeWithoutRequestsUntilIdle, timerInterval); - string result; - try - { - result = dateHeaderValueManager.GetDateHeaderValues().String; - } - finally - { - dateHeaderValueManager.Dispose(); - } - - Assert.Equal(now.ToString(Rfc1123DateFormat), result); + var dateHeaderValueManager = new DateHeaderValueManager(systemClock); + Assert.Equal(now.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String); } [Fact] @@ -53,30 +43,22 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests { UtcNow = now }; - var timeWithoutRequestsUntilIdle = TimeSpan.FromSeconds(1); + var timerInterval = TimeSpan.FromSeconds(10); - var dateHeaderValueManager = new DateHeaderValueManager(systemClock, timeWithoutRequestsUntilIdle, timerInterval); - string result1; - string result2; + var dateHeaderValueManager = new DateHeaderValueManager(systemClock); - try + using (new Heartbeat(new IHeartbeatHandler[] { dateHeaderValueManager }, systemClock, null, timerInterval)) { - result1 = dateHeaderValueManager.GetDateHeaderValues().String; + Assert.Equal(now.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String); systemClock.UtcNow = future; - result2 = dateHeaderValueManager.GetDateHeaderValues().String; - } - finally - { - dateHeaderValueManager.Dispose(); + Assert.Equal(now.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String); } - Assert.Equal(now.ToString(Rfc1123DateFormat), result1); - Assert.Equal(now.ToString(Rfc1123DateFormat), result2); Assert.Equal(1, systemClock.UtcNowCalled); } [Fact] - public async Task GetDateHeaderValue_ReturnsUpdatedValueAfterIdle() + public async Task GetDateHeaderValue_ReturnsUpdatedValueAfterHeartbeat() { var now = DateTimeOffset.UtcNow; var future = now.AddSeconds(10); @@ -84,32 +66,30 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests { UtcNow = now }; - var timeWithoutRequestsUntilIdle = TimeSpan.FromMilliseconds(250); + var timerInterval = TimeSpan.FromMilliseconds(100); - var dateHeaderValueManager = new DateHeaderValueManager(systemClock, timeWithoutRequestsUntilIdle, timerInterval); - string result1; - string result2; + var dateHeaderValueManager = new DateHeaderValueManager(systemClock); - try + var heartbeatTcs = new TaskCompletionSource(); + var mockHeartbeatHandler = new Mock(); + + mockHeartbeatHandler.Setup(h => h.OnHeartbeat(future)).Callback(() => heartbeatTcs.TrySetResult(null)); + + using (new Heartbeat(new[] { dateHeaderValueManager, mockHeartbeatHandler.Object }, systemClock, null, timerInterval)) { - result1 = dateHeaderValueManager.GetDateHeaderValues().String; + Assert.Equal(now.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String); + + // Wait for the next heartbeat before verifying GetDateHeaderValues picks up new time. systemClock.UtcNow = future; - // Wait for longer than the idle timeout to ensure the timer is stopped - await Task.Delay(TimeSpan.FromSeconds(1)); - result2 = dateHeaderValueManager.GetDateHeaderValues().String; - } - finally - { - dateHeaderValueManager.Dispose(); - } + await heartbeatTcs.Task; - Assert.Equal(now.ToString(Rfc1123DateFormat), result1); - Assert.Equal(future.ToString(Rfc1123DateFormat), result2); - Assert.True(systemClock.UtcNowCalled >= 2); + Assert.Equal(future.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String); + Assert.True(systemClock.UtcNowCalled >= 2); + } } [Fact] - public void GetDateHeaderValue_ReturnsDateValueAfterDisposed() + public void GetDateHeaderValue_ReturnsLastDateValueAfterHeartbeatDisposed() { var now = DateTimeOffset.UtcNow; var future = now.AddSeconds(10); @@ -117,17 +97,17 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests { UtcNow = now }; - var timeWithoutRequestsUntilIdle = TimeSpan.FromSeconds(1); - var timerInterval = TimeSpan.FromSeconds(10); - var dateHeaderValueManager = new DateHeaderValueManager(systemClock, timeWithoutRequestsUntilIdle, timerInterval); - var result1 = dateHeaderValueManager.GetDateHeaderValues().String; - dateHeaderValueManager.Dispose(); + var timerInterval = TimeSpan.FromSeconds(10); + var dateHeaderValueManager = new DateHeaderValueManager(systemClock); + + using (new Heartbeat(new IHeartbeatHandler[] { dateHeaderValueManager }, systemClock, null, timerInterval)) + { + Assert.Equal(now.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String); + } + systemClock.UtcNow = future; - var result2 = dateHeaderValueManager.GetDateHeaderValues().String; - - Assert.Equal(now.ToString(Rfc1123DateFormat), result1); - Assert.Equal(future.ToString(Rfc1123DateFormat), result2); + Assert.Equal(now.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String); } } } diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/FrameTests.cs b/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/FrameTests.cs index b5c0b1546f..33646df6ed 100644 --- a/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/FrameTests.cs +++ b/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/FrameTests.cs @@ -13,7 +13,6 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.Hosting.Server; using Microsoft.AspNetCore.Http; 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.Core.Internal.Infrastructure; @@ -67,7 +66,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests _frame = new TestFrame(application: null, context: _frameContext) { Input = _input.Reader, - Output = new MockSocketOutput() + Output = new MockSocketOutput(), + TimeoutControl = Mock.Of() }; _frame.Reset(); @@ -320,16 +320,15 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests [Fact] public async Task ParseRequestStartsRequestHeadersTimeoutOnFirstByteAvailable() { - var connectionInfo = (MockConnectionInformation)_frameContext.ConnectionInformation; var connectionControl = new Mock(); - connectionInfo.TimeoutControl = connectionControl.Object; + _frame.TimeoutControl = connectionControl.Object; await _input.Writer.WriteAsync(Encoding.ASCII.GetBytes("G")); _frame.ParseRequest((await _input.Reader.ReadAsync()).Buffer, out _consumed, out _examined); _input.Reader.Advance(_consumed, _examined); - var expectedRequestHeadersTimeout = (long)_serviceContext.ServerOptions.Limits.RequestHeadersTimeout.TotalMilliseconds; + var expectedRequestHeadersTimeout = _serviceContext.ServerOptions.Limits.RequestHeadersTimeout.Ticks; connectionControl.Verify(cc => cc.ResetTimeout(expectedRequestHeadersTimeout, TimeoutAction.SendTimeoutResponse)); } @@ -444,13 +443,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests [Fact] public void RequestProcessingAsyncEnablesKeepAliveTimeout() { - var connectionInfo = (MockConnectionInformation)_frameContext.ConnectionInformation; var connectionControl = new Mock(); - connectionInfo.TimeoutControl = connectionControl.Object; + _frame.TimeoutControl = connectionControl.Object; var requestProcessingTask = _frame.RequestProcessingAsync(); - var expectedKeepAliveTimeout = (long)_serviceContext.ServerOptions.Limits.KeepAliveTimeout.TotalMilliseconds; + var expectedKeepAliveTimeout = _serviceContext.ServerOptions.Limits.KeepAliveTimeout.Ticks; connectionControl.Verify(cc => cc.SetTimeout(expectedKeepAliveTimeout, TimeoutAction.CloseConnection)); _frame.StopAsync(); @@ -817,7 +815,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests public PipeFactory PipeFactory { get; } public IScheduler InputWriterScheduler { get; } public IScheduler OutputReaderScheduler { get; } - public ITimeoutControl TimeoutControl { get; set; } = Mock.Of(); } private class RequestHeadersWrapper : IHeaderDictionary diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/HeartbeatTests.cs b/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/HeartbeatTests.cs new file mode 100644 index 0000000000..8c7ea7d850 --- /dev/null +++ b/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/HeartbeatTests.cs @@ -0,0 +1,59 @@ +// 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.Linq; +using System.Threading; +using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; +using Microsoft.AspNetCore.Testing; +using Microsoft.Extensions.Logging; +using Moq; +using Xunit; + +namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests +{ + public class HeartbeatTests + { + [Fact] + public void BlockedHeartbeatDoesntCauseOverlapsAndIsLoggedAsError() + { + var systemClock = new MockSystemClock(); + var heartbeatInterval = TimeSpan.FromMilliseconds(10); + var heartbeatHandler = new Mock(); + var kestrelTrace = new Mock(); + var handlerMre = new ManualResetEventSlim(); + var traceMre = new ManualResetEventSlim(); + + heartbeatHandler.Setup(h => h.OnHeartbeat(systemClock.UtcNow)).Callback(() => handlerMre.Wait()); + kestrelTrace.Setup(t => t.TimerSlow(heartbeatInterval, systemClock.UtcNow)).Callback(() => traceMre.Set()); + + using (new Heartbeat(new[] {heartbeatHandler.Object}, systemClock, kestrelTrace.Object, heartbeatInterval)) + { + Assert.True(traceMre.Wait(TimeSpan.FromSeconds(10))); + } + + handlerMre.Set(); + + heartbeatHandler.Verify(h => h.OnHeartbeat(systemClock.UtcNow), Times.Once()); + kestrelTrace.Verify(t => t.TimerSlow(heartbeatInterval, systemClock.UtcNow), Times.AtLeastOnce()); + } + + [Fact] + public void ExceptionFromHeartbeatHandlerIsLoggedAsError() + { + var systemClock = new MockSystemClock(); + var heartbeatHandler = new Mock(); + var kestrelTrace = new TestKestrelTrace(); + var ex = new Exception(); + + heartbeatHandler.Setup(h => h.OnHeartbeat(systemClock.UtcNow)).Throws(ex); + + using (new Heartbeat(new[] { heartbeatHandler.Object }, systemClock, kestrelTrace)) + { + Assert.True(kestrelTrace.Logger.MessageLoggedTask.Wait(TimeSpan.FromSeconds(10))); + } + + Assert.Equal(ex, kestrelTrace.Logger.Messages.Single(message => message.LogLevel == LogLevel.Error).Exception); + } + } +} diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/TestInput.cs b/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/TestInput.cs index 73f6f170bf..56b959a738 100644 --- a/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/TestInput.cs +++ b/test/Microsoft.AspNetCore.Server.Kestrel.Core.Tests/TestInput.cs @@ -14,7 +14,7 @@ using Microsoft.Extensions.Internal; namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests { - class TestInput : ITimeoutControl, IFrameControl, IDisposable + class TestInput : IFrameControl, IDisposable { private MemoryPool _memoryPool; private PipeFactory _pipelineFactory; @@ -58,18 +58,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests { } - public void SetTimeout(long milliseconds, TimeoutAction timeoutAction) - { - } - - public void ResetTimeout(long milliseconds, TimeoutAction timeoutAction) - { - } - - public void CancelTimeout() - { - } - public void Abort() { } diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/KeepAliveTimeoutTests.cs b/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/KeepAliveTimeoutTests.cs index 28e4ece5d8..01b070dac6 100644 --- a/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/KeepAliveTimeoutTests.cs +++ b/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/KeepAliveTimeoutTests.cs @@ -2,12 +2,14 @@ // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; +using System.Net; using System.Text; using System.Threading; using System.Threading.Tasks; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http.Features; using Microsoft.AspNetCore.Server.Kestrel.Core; +using Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.TestHelpers; using Microsoft.AspNetCore.Testing; using Xunit; @@ -49,22 +51,22 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests } } - private async Task ConnectionClosedWhenKeepAliveTimeoutExpires(TestServer server) + private async Task ConnectionClosedWhenKeepAliveTimeoutExpires(TimeoutTestServer server) { - using (var connection = new TestConnection(server.Port)) + using (var connection = server.CreateConnection()) { await connection.Send( "GET / HTTP/1.1", "", ""); - await ReceiveResponse(connection, server.Context); + await ReceiveResponse(connection); await connection.WaitForConnectionClose().TimeoutAfter(LongDelay); } } - private async Task ConnectionKeptAliveBetweenRequests(TestServer server) + private async Task ConnectionKeptAliveBetweenRequests(TimeoutTestServer server) { - using (var connection = new TestConnection(server.Port)) + using (var connection = server.CreateConnection()) { for (var i = 0; i < 10; i++) { @@ -77,14 +79,14 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests for (var i = 0; i < 10; i++) { - await ReceiveResponse(connection, server.Context); + await ReceiveResponse(connection); } } } - private async Task ConnectionNotTimedOutWhileRequestBeingSent(TestServer server) + private async Task ConnectionNotTimedOutWhileRequestBeingSent(TimeoutTestServer server) { - using (var connection = new TestConnection(server.Port)) + using (var connection = server.CreateConnection()) { var cts = new CancellationTokenSource(); cts.CancelAfter(LongDelay); @@ -108,13 +110,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests "0", "", ""); - await ReceiveResponse(connection, server.Context); + await ReceiveResponse(connection); } } - private async Task ConnectionNotTimedOutWhileAppIsRunning(TestServer server, CancellationTokenSource cts) + private async Task ConnectionNotTimedOutWhileAppIsRunning(TimeoutTestServer server, CancellationTokenSource cts) { - using (var connection = new TestConnection(server.Port)) + using (var connection = server.CreateConnection()) { await connection.Send( "GET /longrunning HTTP/1.1", @@ -127,28 +129,28 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests await Task.Delay(1000); } - await ReceiveResponse(connection, server.Context); + await ReceiveResponse(connection); await connection.Send( "GET / HTTP/1.1", "", ""); - await ReceiveResponse(connection, server.Context); + await ReceiveResponse(connection); } } - private async Task ConnectionTimesOutWhenOpenedButNoRequestSent(TestServer server) + private async Task ConnectionTimesOutWhenOpenedButNoRequestSent(TimeoutTestServer server) { - using (var connection = new TestConnection(server.Port)) + using (var connection = server.CreateConnection()) { await Task.Delay(LongDelay); await connection.WaitForConnectionClose().TimeoutAfter(LongDelay); } } - private async Task KeepAliveTimeoutDoesNotApplyToUpgradedConnections(TestServer server, CancellationTokenSource cts) + private async Task KeepAliveTimeoutDoesNotApplyToUpgradedConnections(TimeoutTestServer server, CancellationTokenSource cts) { - using (var connection = new TestConnection(server.Port)) + using (var connection = server.CreateConnection()) { await connection.Send( "GET /upgrade HTTP/1.1", @@ -157,7 +159,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests await connection.Receive( "HTTP/1.1 101 Switching Protocols", "Connection: Upgrade", - $"Date: {server.Context.DateHeaderValue}", + ""); + await connection.ReceiveStartsWith("Date: "); + await connection.Receive( "", ""); cts.CancelAfter(LongDelay); @@ -171,18 +175,12 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests } } - private TestServer CreateServer(CancellationToken longRunningCt, CancellationToken upgradeCt) + private TimeoutTestServer CreateServer(CancellationToken longRunningCt, CancellationToken upgradeCt) { - return new TestServer(httpContext => App(httpContext, longRunningCt, upgradeCt), new TestServiceContext + return new TimeoutTestServer(httpContext => App(httpContext, longRunningCt, upgradeCt), new KestrelServerOptions { - ServerOptions = new KestrelServerOptions - { - AddServerHeader = false, - Limits = - { - KeepAliveTimeout = KeepAliveTimeout - } - } + AddServerHeader = false, + Limits = { KeepAliveTimeout = KeepAliveTimeout } }); } @@ -218,11 +216,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests } } - private async Task ReceiveResponse(TestConnection connection, TestServiceContext testServiceContext) + private async Task ReceiveResponse(TestConnection connection) { await connection.Receive( "HTTP/1.1 200 OK", - $"Date: {testServiceContext.DateHeaderValue}", + ""); + await connection.ReceiveStartsWith("Date: "); + await connection.Receive( "Transfer-Encoding: chunked", "", "c", diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/RequestHeadersTimeoutTests.cs b/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/RequestHeadersTimeoutTests.cs index e3807704a7..4514ace0d2 100644 --- a/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/RequestHeadersTimeoutTests.cs +++ b/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/RequestHeadersTimeoutTests.cs @@ -6,6 +6,7 @@ using System.IO; using System.Threading.Tasks; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Server.Kestrel.Core; +using Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.TestHelpers; using Microsoft.AspNetCore.Testing; using Xunit; @@ -37,18 +38,18 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests } } - private async Task ConnectionAbortedWhenRequestHeadersNotReceivedInTime(TestServer server, string headers) + private async Task ConnectionAbortedWhenRequestHeadersNotReceivedInTime(TimeoutTestServer server, string headers) { using (var connection = server.CreateConnection()) { await connection.Send( "GET / HTTP/1.1", headers); - await ReceiveTimeoutResponse(connection, server.Context); + await ReceiveTimeoutResponse(connection); } } - private async Task RequestHeadersTimeoutCanceledAfterHeadersReceived(TestServer server) + private async Task RequestHeadersTimeoutCanceledAfterHeadersReceived(TimeoutTestServer server) { using (var connection = server.CreateConnection()) { @@ -60,20 +61,20 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests await Task.Delay(RequestHeadersTimeout); await connection.Send( "a"); - await ReceiveResponse(connection, server.Context); + await ReceiveResponse(connection); } } - private async Task ConnectionAbortedWhenRequestLineNotReceivedInTime(TestServer server, string requestLine) + private async Task ConnectionAbortedWhenRequestLineNotReceivedInTime(TimeoutTestServer server, string requestLine) { using (var connection = server.CreateConnection()) { await connection.Send(requestLine); - await ReceiveTimeoutResponse(connection, server.Context); + await ReceiveTimeoutResponse(connection); } } - private async Task TimeoutNotResetOnEachRequestLineCharacterReceived(TestServer server) + private async Task TimeoutNotResetOnEachRequestLineCharacterReceived(TimeoutTestServer server) { using (var connection = server.CreateConnection()) { @@ -88,31 +89,30 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests } } - private TestServer CreateServer() + private TimeoutTestServer CreateServer() { - return new TestServer(async httpContext => + return new TimeoutTestServer(async httpContext => { await httpContext.Request.Body.ReadAsync(new byte[1], 0, 1); await httpContext.Response.WriteAsync("hello, world"); }, - new TestServiceContext + new KestrelServerOptions { - ServerOptions = new KestrelServerOptions + AddServerHeader = false, + Limits = { - AddServerHeader = false, - Limits = - { - RequestHeadersTimeout = RequestHeadersTimeout - } + RequestHeadersTimeout = RequestHeadersTimeout } }); } - private async Task ReceiveResponse(TestConnection connection, TestServiceContext testServiceContext) + private async Task ReceiveResponse(TestConnection connection) { await connection.Receive( "HTTP/1.1 200 OK", - $"Date: {testServiceContext.DateHeaderValue}", + ""); + await connection.ReceiveStartsWith("Date: "); + await connection.Receive( "Transfer-Encoding: chunked", "", "c", @@ -122,12 +122,14 @@ namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests ""); } - private async Task ReceiveTimeoutResponse(TestConnection connection, TestServiceContext testServiceContext) + private async Task ReceiveTimeoutResponse(TestConnection connection) { - await connection.ReceiveForcedEnd( + await connection.Receive( "HTTP/1.1 408 Request Timeout", "Connection: close", - $"Date: {testServiceContext.DateHeaderValue}", + ""); + await connection.ReceiveStartsWith("Date: "); + await connection.ReceiveForcedEnd( "Content-Length: 0", "", ""); diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/TestHelpers/TimeoutTestServer.cs b/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/TestHelpers/TimeoutTestServer.cs new file mode 100644 index 0000000000..9cf5e46e3d --- /dev/null +++ b/test/Microsoft.AspNetCore.Server.Kestrel.FunctionalTests/TestHelpers/TimeoutTestServer.cs @@ -0,0 +1,49 @@ +// 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.Net; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.Server.Kestrel.Core; +using Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv; +using Microsoft.AspNetCore.Testing; +using Microsoft.Extensions.Options; + +namespace Microsoft.AspNetCore.Server.Kestrel.FunctionalTests.TestHelpers +{ + public class TimeoutTestServer : IDisposable + { + private readonly KestrelServer _server; + private readonly ListenOptions _listenOptions; + + public TimeoutTestServer(RequestDelegate app, KestrelServerOptions serverOptions) + { + var loggerFactory = new KestrelTestLoggerFactory(new TestApplicationErrorLogger()); + var libuvTransportFactory = new LibuvTransportFactory(Options.Create(new LibuvTransportOptions()), new LifetimeNotImplemented(), loggerFactory); + + _listenOptions = new ListenOptions(new IPEndPoint(IPAddress.Loopback, 0)); + serverOptions.ListenOptions.Add(_listenOptions); + _server = new KestrelServer(Options.Create(serverOptions), libuvTransportFactory, loggerFactory); + + try + { + _server.Start(new DummyApplication(app)); + } + catch + { + _server.Dispose(); + throw; + } + } + + public TestConnection CreateConnection() + { + return new TestConnection(_listenOptions.IPEndPoint.Port, _listenOptions.IPEndPoint.AddressFamily); + } + + public void Dispose() + { + _server?.Dispose(); + } + } +} diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.Performance/Mocks/MockConnectionInformation.cs b/test/Microsoft.AspNetCore.Server.Kestrel.Performance/Mocks/MockConnectionInformation.cs index fd1915cff7..7aa345898b 100644 --- a/test/Microsoft.AspNetCore.Server.Kestrel.Performance/Mocks/MockConnectionInformation.cs +++ b/test/Microsoft.AspNetCore.Server.Kestrel.Performance/Mocks/MockConnectionInformation.cs @@ -15,22 +15,5 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Performance public PipeFactory PipeFactory { get; } public IScheduler InputWriterScheduler { get; } public IScheduler OutputReaderScheduler { get; } - - public ITimeoutControl TimeoutControl { get; } = new MockTimeoutControl(); - - private class MockTimeoutControl : ITimeoutControl - { - public void CancelTimeout() - { - } - - public void ResetTimeout(long milliseconds, TimeoutAction timeoutAction) - { - } - - public void SetTimeout(long milliseconds, TimeoutAction timeoutAction) - { - } - } } } diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.Performance/Mocks/MockTrace.cs b/test/Microsoft.AspNetCore.Server.Kestrel.Performance/Mocks/MockTrace.cs index f98d3c15cf..bfb22e1d65 100644 --- a/test/Microsoft.AspNetCore.Server.Kestrel.Performance/Mocks/MockTrace.cs +++ b/test/Microsoft.AspNetCore.Server.Kestrel.Performance/Mocks/MockTrace.cs @@ -34,5 +34,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Performance public void NotAllConnectionsAborted() { } public void NotAllConnectionsClosedGracefully() { } public void RequestProcessingError(string connectionId, Exception ex) { } + public virtual void TimerSlow(TimeSpan interval, DateTimeOffset now) { } } } diff --git a/test/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Tests/TestHelpers/MockConnection.cs b/test/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Tests/TestHelpers/MockConnection.cs index a40892a1d0..5e2802f976 100644 --- a/test/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Tests/TestHelpers/MockConnection.cs +++ b/test/Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Tests/TestHelpers/MockConnection.cs @@ -15,7 +15,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Tests.TestHelpers public MockConnection() { - TimeoutControl = this; RequestAbortedSource = new CancellationTokenSource(); ListenerContext = new ListenerContext(new LibuvTransportContext()); } diff --git a/test/shared/TestApplicationErrorLogger.cs b/test/shared/TestApplicationErrorLogger.cs index d77a1c08ed..404b2cabc8 100644 --- a/test/shared/TestApplicationErrorLogger.cs +++ b/test/shared/TestApplicationErrorLogger.cs @@ -3,6 +3,7 @@ using System; using System.Collections.Concurrent; +using System.Threading.Tasks; using System.Linq; using Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure; using Microsoft.Extensions.Logging; @@ -14,6 +15,8 @@ namespace Microsoft.AspNetCore.Testing // Application errors are logged using 13 as the eventId. private const int ApplicationErrorEventId = 13; + private TaskCompletionSource _messageLoggedTcs = new TaskCompletionSource(); + public bool ThrowOnCriticalErrors { get; set; } = true; public ConcurrentBag Messages { get; } = new ConcurrentBag(); @@ -24,6 +27,8 @@ namespace Microsoft.AspNetCore.Testing public int ApplicationErrorsLogged => Messages.Count(message => message.EventId.Id == ApplicationErrorEventId); + public Task MessageLoggedTask => _messageLoggedTcs.Task; + public IDisposable BeginScope(TState state) { return new Disposable(() => { }); @@ -55,6 +60,8 @@ namespace Microsoft.AspNetCore.Testing Exception = exception, Message = formatter(state, exception) }); + + _messageLoggedTcs.TrySetResult(null); } public class LogMessage diff --git a/test/shared/TestConnection.cs b/test/shared/TestConnection.cs index 33016bd473..b3b377118d 100644 --- a/test/shared/TestConnection.cs +++ b/test/shared/TestConnection.cs @@ -126,6 +126,38 @@ namespace Microsoft.AspNetCore.Testing } } + public async Task ReceiveStartsWith(string prefix, int maxLineLength = 1024) + { + var actual = new char[maxLineLength]; + var offset = 0; + + while (offset < maxLineLength) + { + // Read one char at a time so we don't read past the end of the line. + var task = _reader.ReadAsync(actual, offset, 1); + if (!Debugger.IsAttached) + { + Assert.True(task.Wait(4000), "timeout"); + } + var count = await task; + if (count == 0) + { + break; + } + + Assert.True(count == 1); + offset++; + + if (actual[offset - 1] == '\n') + { + break; + } + } + + var actualLine = new string(actual, 0, offset); + Assert.StartsWith(prefix, actualLine); + } + public void Shutdown(SocketShutdown how) { _socket.Shutdown(how); diff --git a/test/shared/TestServiceContext.cs b/test/shared/TestServiceContext.cs index 808a03998d..5b9cbea147 100644 --- a/test/shared/TestServiceContext.cs +++ b/test/shared/TestServiceContext.cs @@ -16,7 +16,9 @@ namespace Microsoft.AspNetCore.Testing Log = new TestKestrelTrace(logger); ThreadPool = new LoggingThreadPool(Log); - DateHeaderValueManager = new DateHeaderValueManager(systemClock: new MockSystemClock()); + SystemClock = new MockSystemClock(); + DateHeaderValueManager = new DateHeaderValueManager(SystemClock); + ConnectionManager = new FrameConnectionManager(); DateHeaderValue = DateHeaderValueManager.GetDateHeaderValues().String; HttpParserFactory = frameAdapter => new HttpParser(frameAdapter.Frame.ServiceContext.Log); ServerOptions = new KestrelServerOptions