huahaofeng
/
aspnetcore
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Use a dedicated thread for timers in rather than a Timer (#21490) 

* Use a dedicated thread for timers in rather than a Timer
- This make it possible to still timeout various operations when there's thread pool starvation occurring.
- Print heartbeat slow if duration > interval
This commit is contained in:
David Fowler 2020-05-08 01:07:36 -07:00 committed by GitHub
parent a8b8c19a3b
commit 6aa13dde98
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 54 additions and 47 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

71
src/Servers/Kestrel/Core/src/Internal/Infrastructure/Heartbeat.cs
View File

@ -16,9 +16,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
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 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
_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);
_timerThread.Start(this);
}
private static void OnHeartbeat(object state)
{
((Heartbeat)state).OnHeartbeat();
}
// 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
{
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
{
if (!_debugger.IsAttached)
{
var lastHeartbeatTicks = Volatile.Read(ref _lastHeartbeatTicks);
_trace.HeartbeatSlow(TimeSpan.FromTicks(now.Ticks - lastHeartbeatTicks), _interval, now);
var after = _systemClock.UtcNow;
var duration = TimeSpan.FromTicks(after.Ticks - now.Ticks);
if (duration > _interval)
{
_trace.HeartbeatSlow(duration, _interval, now);
}
}
}
catch (Exception ex)
{
_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
}
}
}

2
src/Servers/Kestrel/Core/test/DateHeaderValueManagerTests.cs
View File

@ -85,7 +85,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
heartbeat.OnHeartbeat();
Assert.Equal(future.ToString(Rfc1123DateFormat), dateHeaderValueManager.GetDateHeaderValues().String);
Assert.Equal(2, systemClock.UtcNowCalled);
Assert.Equal(4, systemClock.UtcNowCalled);
}
}

28
src/Servers/Kestrel/Core/test/HeartbeatTests.cs
View File

@ -22,7 +22,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
}
[Fact]
public async Task BlockedHeartbeatDoesntCauseOverlapsAndIsLoggedAsError()
public async Task HeartbeatTakingLongerThanIntervalIsLoggedAsError()
{
var systemClock = new MockSystemClock();
var heartbeatHandler = new Mock<IHeartbeatHandler>();
@ -30,8 +30,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
var kestrelTrace = new Mock<IKestrelTrace>();
var handlerMre = new ManualResetEventSlim();
var handlerStartedTcs = new TaskCompletionSource<object>(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 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
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<IHeartbeatHandler>();
@ -66,8 +68,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
var kestrelTrace = new Mock<IKestrelTrace>();
var handlerMre = new ManualResetEventSlim();
var handlerStartedTcs = new TaskCompletionSource<object>(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 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
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]