Skip to content

Commit 4a33e2d

Browse files
MarusykBrennanConroy
authored andcommitted
Fix arguments order for call of HeartbeatSlow (#28698)
1 parent 19785cc commit 4a33e2d

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
@@ -47,8 +47,8 @@ internal class KestrelTrace : IKestrelTrace
4747
private static readonly Action<ILogger, Exception> _notAllConnectionsAborted =
4848
LoggerMessage.Define(LogLevel.Debug, new EventId(21, nameof(NotAllConnectionsAborted)), "Some connections failed to abort during server shutdown.");
4949

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

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

197197
public virtual void HeartbeatSlow(TimeSpan heartbeatDuration, TimeSpan interval, DateTimeOffset now)
198198
{
199-
_heartbeatSlow(_logger, heartbeatDuration, interval, now, null);
199+
_heartbeatSlow(_logger, now, heartbeatDuration, interval, null);
200200
}
201201

202202
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)