Skip to content

Commit 8b8ef39

Browse files
authored
Fix arguments order for call of HeartbeatSlow (#28698)
1 parent f4d10f6 commit 8b8ef39

File tree

2 files changed

+15
-8
lines changed

2 files changed

+15
-8
lines changed

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

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -49,8 +49,8 @@ internal class KestrelTrace : IKestrelTrace
4949
private static readonly Action<ILogger, Exception?> _notAllConnectionsAborted =
5050
LoggerMessage.Define(LogLevel.Debug, new EventId(21, "NotAllConnectionsAborted"), "Some connections failed to abort during server shutdown.");
5151

52-
private static readonly Action<ILogger, TimeSpan, TimeSpan, DateTimeOffset, Exception?> _heartbeatSlow =
53-
LoggerMessage.Define<TimeSpan, TimeSpan, DateTimeOffset>(LogLevel.Warning, new EventId(22, "HeartbeatSlow"), @"As of ""{now}"", the heartbeat has been running for ""{heartbeatDuration}"" which is longer than ""{interval}"". This could be caused by thread pool starvation.");
52+
private static readonly Action<ILogger, DateTimeOffset, TimeSpan, TimeSpan, Exception?> _heartbeatSlow =
53+
LoggerMessage.Define<DateTimeOffset, TimeSpan, TimeSpan>(LogLevel.Warning, new EventId(22, "HeartbeatSlow"), @"As of ""{now}"", the heartbeat has been running for ""{heartbeatDuration}"" which is longer than ""{interval}"". This could be caused by thread pool starvation.");
5454

5555
private static readonly Action<ILogger, string, Exception?> _applicationNeverCompleted =
5656
LoggerMessage.Define<string>(LogLevel.Critical, new EventId(23, "ApplicationNeverCompleted"), @"Connection id ""{ConnectionId}"" application never completed.");
@@ -225,7 +225,7 @@ public virtual void NotAllConnectionsAborted()
225225

226226
public virtual void HeartbeatSlow(TimeSpan heartbeatDuration, TimeSpan interval, DateTimeOffset now)
227227
{
228-
_heartbeatSlow(_logger, heartbeatDuration, interval, now, null);
228+
_heartbeatSlow(_logger, now, heartbeatDuration, interval, null);
229229
}
230230

231231
public virtual void ApplicationNeverCompleted(string connectionId)

src/Servers/Kestrel/Core/test/HeartbeatTests.cs

Lines changed: 12 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
33

44
using System;
5+
using System.Globalization;
56
using System.Linq;
67
using System.Threading;
78
using System.Threading.Tasks;
@@ -22,15 +23,16 @@ public void HeartbeatIntervalIsOneSecond()
2223
}
2324

2425
[Fact]
25-
public async Task HeartbeatTakingLongerThanIntervalIsLoggedAsError()
26+
public async Task HeartbeatTakingLongerThanIntervalIsLoggedAsWarning()
2627
{
2728
var systemClock = new MockSystemClock();
2829
var heartbeatHandler = new Mock<IHeartbeatHandler>();
2930
var debugger = new Mock<IDebugger>();
30-
var kestrelTrace = new Mock<IKestrelTrace>();
31+
var kestrelTrace = new TestKestrelTrace();
3132
var handlerMre = new ManualResetEventSlim();
3233
var handlerStartedTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
3334
var now = systemClock.UtcNow;
35+
var heartbeatDuration = TimeSpan.FromSeconds(2);
3436

3537
heartbeatHandler.Setup(h => h.OnHeartbeat(now)).Callback(() =>
3638
{
@@ -41,7 +43,7 @@ public async Task HeartbeatTakingLongerThanIntervalIsLoggedAsError()
4143

4244
Task blockedHeartbeatTask;
4345

44-
using (var heartbeat = new Heartbeat(new[] { heartbeatHandler.Object }, systemClock, debugger.Object, kestrelTrace.Object))
46+
using (var heartbeat = new Heartbeat(new[] { heartbeatHandler.Object }, systemClock, debugger.Object, kestrelTrace))
4547
{
4648
blockedHeartbeatTask = Task.Run(() => heartbeat.OnHeartbeat());
4749

@@ -56,11 +58,16 @@ public async Task HeartbeatTakingLongerThanIntervalIsLoggedAsError()
5658
await blockedHeartbeatTask.DefaultTimeout();
5759

5860
heartbeatHandler.Verify(h => h.OnHeartbeat(now), Times.Once());
59-
kestrelTrace.Verify(t => t.HeartbeatSlow(TimeSpan.FromSeconds(2), Heartbeat.Interval, now), Times.Once());
61+
62+
var warningMessage = kestrelTrace.Logger.Messages.Single(message => message.LogLevel == LogLevel.Warning).Message;
63+
Assert.Equal($"As of \"{now.ToString(CultureInfo.InvariantCulture)}\", the heartbeat has been running for "
64+
+ $"\"{heartbeatDuration.ToString("c", CultureInfo.InvariantCulture)}\" which is longer than "
65+
+ $"\"{Heartbeat.Interval.ToString("c", CultureInfo.InvariantCulture)}\". "
66+
+ "This could be caused by thread pool starvation.", warningMessage);
6067
}
6168

6269
[Fact]
63-
public async Task HeartbeatTakingLongerThanIntervalIsNotLoggedAsErrorIfDebuggerAttached()
70+
public async Task HeartbeatTakingLongerThanIntervalIsNotLoggedIfDebuggerAttached()
6471
{
6572
var systemClock = new MockSystemClock();
6673
var heartbeatHandler = new Mock<IHeartbeatHandler>();

0 commit comments

Comments
 (0)