diff --git a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/Heartbeat.cs b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/Heartbeat.cs index 9cf9e2d62e35..e26a2961cbba 100644 --- a/src/Servers/Kestrel/Core/src/Internal/Infrastructure/Heartbeat.cs +++ b/src/Servers/Kestrel/Core/src/Internal/Infrastructure/Heartbeat.cs @@ -16,9 +16,8 @@ internal class Heartbeat : IDisposable private readonly IDebugger _debugger; private readonly IKestrelTrace _trace; private readonly TimeSpan _interval; - private Timer _timer; - private int _executingOnHeartbeat; - private long _lastHeartbeatTicks; + private Thread _timerThread; + private volatile bool _stopped; public Heartbeat(IHeartbeatHandler[] callbacks, ISystemClock systemClock, IDebugger debugger, IKestrelTrace trace) { @@ -27,58 +26,62 @@ public Heartbeat(IHeartbeatHandler[] callbacks, ISystemClock systemClock, IDebug _debugger = debugger; _trace = trace; _interval = Interval; + _timerThread = new Thread(state => ((Heartbeat)state).TimerLoop()) + { + Name = "Kestrel Timer", + IsBackground = true + }; } public void Start() { OnHeartbeat(); - _timer = new Timer(OnHeartbeat, state: this, dueTime: _interval, period: _interval); - } - - private static void OnHeartbeat(object state) - { - ((Heartbeat)state).OnHeartbeat(); + _timerThread.Start(this); } - // Called by the Timer (background) thread internal void OnHeartbeat() { var now = _systemClock.UtcNow; - if (Interlocked.Exchange(ref _executingOnHeartbeat, 1) == 0) + try { - Volatile.Write(ref _lastHeartbeatTicks, now.Ticks); + foreach (var callback in _callbacks) + { + callback.OnHeartbeat(now); + } - try + if (!_debugger.IsAttached) { - foreach (var callback in _callbacks) + var after = _systemClock.UtcNow; + + var duration = TimeSpan.FromTicks(after.Ticks - now.Ticks); + + if (duration > _interval) { - callback.OnHeartbeat(now); + _trace.HeartbeatSlow(duration, _interval, now); } } - catch (Exception ex) - { - _trace.LogError(0, ex, $"{nameof(Heartbeat)}.{nameof(OnHeartbeat)}"); - } - finally - { - Interlocked.Exchange(ref _executingOnHeartbeat, 0); - } } - else + catch (Exception ex) { - if (!_debugger.IsAttached) - { - var lastHeartbeatTicks = Volatile.Read(ref _lastHeartbeatTicks); - - _trace.HeartbeatSlow(TimeSpan.FromTicks(now.Ticks - lastHeartbeatTicks), _interval, now); - } + _trace.LogError(0, ex, $"{nameof(Heartbeat)}.{nameof(OnHeartbeat)}"); + } + } + + private void TimerLoop() + { + while (!_stopped) + { + Thread.Sleep(_interval); + + OnHeartbeat(); } } public void Dispose() { - _timer?.Dispose(); + _stopped = true; + // Don't block waiting for the thread to exit } } } diff --git a/src/Servers/Kestrel/Core/test/DateHeaderValueManagerTests.cs b/src/Servers/Kestrel/Core/test/DateHeaderValueManagerTests.cs index 4e5d76b15673..ec393bd688b6 100644 --- a/src/Servers/Kestrel/Core/test/DateHeaderValueManagerTests.cs +++ b/src/Servers/Kestrel/Core/test/DateHeaderValueManagerTests.cs @@ -85,7 +85,7 @@ public void GetDateHeaderValue_ReturnsUpdatedValueAfterHeartbeat() heartbeat.OnHeartbeat(); Assert.Equal(future.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String); - Assert.Equal(2, systemClock.UtcNowCalled); + Assert.Equal(4, systemClock.UtcNowCalled); } } diff --git a/src/Servers/Kestrel/Core/test/HeartbeatTests.cs b/src/Servers/Kestrel/Core/test/HeartbeatTests.cs index bb4e896b44b7..680fa6af8b64 100644 --- a/src/Servers/Kestrel/Core/test/HeartbeatTests.cs +++ b/src/Servers/Kestrel/Core/test/HeartbeatTests.cs @@ -22,7 +22,7 @@ public void HeartbeatIntervalIsOneSecond() } [Fact] - public async Task BlockedHeartbeatDoesntCauseOverlapsAndIsLoggedAsError() + public async Task HeartbeatTakingLongerThanIntervalIsLoggedAsError() { var systemClock = new MockSystemClock(); var heartbeatHandler = new Mock(); @@ -30,8 +30,9 @@ public async Task BlockedHeartbeatDoesntCauseOverlapsAndIsLoggedAsError() var kestrelTrace = new Mock(); var handlerMre = new ManualResetEventSlim(); var handlerStartedTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var now = systemClock.UtcNow; - heartbeatHandler.Setup(h => h.OnHeartbeat(systemClock.UtcNow)).Callback(() => + heartbeatHandler.Setup(h => h.OnHeartbeat(now)).Callback(() => { handlerStartedTcs.SetResult(null); handlerMre.Wait(); @@ -45,20 +46,21 @@ public async Task BlockedHeartbeatDoesntCauseOverlapsAndIsLoggedAsError() blockedHeartbeatTask = Task.Run(() => heartbeat.OnHeartbeat()); await handlerStartedTcs.Task.DefaultTimeout(); - - heartbeat.OnHeartbeat(); } + // 2 seconds passes... + systemClock.UtcNow = systemClock.UtcNow.AddSeconds(2); + handlerMre.Set(); await blockedHeartbeatTask.DefaultTimeout(); - heartbeatHandler.Verify(h => h.OnHeartbeat(systemClock.UtcNow), Times.Once()); - kestrelTrace.Verify(t => t.HeartbeatSlow(TimeSpan.Zero, Heartbeat.Interval, systemClock.UtcNow), Times.Once()); + heartbeatHandler.Verify(h => h.OnHeartbeat(now), Times.Once()); + kestrelTrace.Verify(t => t.HeartbeatSlow(TimeSpan.FromSeconds(2), Heartbeat.Interval, now), Times.Once()); } [Fact] - public async Task BlockedHeartbeatIsNotLoggedAsErrorIfDebuggerAttached() + public async Task HeartbeatTakingLongerThanIntervalIsNotLoggedAsErrorIfDebuggerAttached() { var systemClock = new MockSystemClock(); var heartbeatHandler = new Mock(); @@ -66,8 +68,9 @@ public async Task BlockedHeartbeatIsNotLoggedAsErrorIfDebuggerAttached() var kestrelTrace = new Mock(); var handlerMre = new ManualResetEventSlim(); var handlerStartedTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var now = systemClock.UtcNow; - heartbeatHandler.Setup(h => h.OnHeartbeat(systemClock.UtcNow)).Callback(() => + heartbeatHandler.Setup(h => h.OnHeartbeat(now)).Callback(() => { handlerStartedTcs.SetResult(null); handlerMre.Wait(); @@ -82,16 +85,17 @@ public async Task BlockedHeartbeatIsNotLoggedAsErrorIfDebuggerAttached() blockedHeartbeatTask = Task.Run(() => heartbeat.OnHeartbeat()); await handlerStartedTcs.Task.DefaultTimeout(); - - heartbeat.OnHeartbeat(); } + // 2 seconds passes... + systemClock.UtcNow = systemClock.UtcNow.AddSeconds(2); + handlerMre.Set(); await blockedHeartbeatTask.DefaultTimeout(); - heartbeatHandler.Verify(h => h.OnHeartbeat(systemClock.UtcNow), Times.Once()); - kestrelTrace.Verify(t => t.HeartbeatSlow(TimeSpan.Zero, Heartbeat.Interval, systemClock.UtcNow), Times.Never()); + heartbeatHandler.Verify(h => h.OnHeartbeat(now), Times.Once()); + kestrelTrace.Verify(t => t.HeartbeatSlow(TimeSpan.FromSeconds(2), Heartbeat.Interval, now), Times.Never()); } [Fact]