Fix arguments order for call of HeartbeatSlow (#28698) (#31080)

Co-authored-by: Roman Marusyk <Marusyk@users.noreply.github.com>
This commit is contained in:
Brennan 2021-04-07 16:07:47 -07:00 committed by GitHub
parent 00c3e7cd85
commit dfbbc40f67
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 15 additions and 8 deletions

View File

@ -47,8 +47,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
private static readonly Action<ILogger, Exception> _notAllConnectionsAborted =
LoggerMessage.Define(LogLevel.Debug, new EventId(21, nameof(NotAllConnectionsAborted)), "Some connections failed to abort during server shutdown.");
private static readonly Action<ILogger, TimeSpan, TimeSpan, DateTimeOffset, Exception> _heartbeatSlow =
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.");
private static readonly Action<ILogger, DateTimeOffset, TimeSpan, TimeSpan, Exception> _heartbeatSlow =
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.");
private static readonly Action<ILogger, string, Exception> _applicationNeverCompleted =
LoggerMessage.Define<string>(LogLevel.Critical, new EventId(23, nameof(ApplicationNeverCompleted)), @"Connection id ""{ConnectionId}"" application never completed");
@ -196,7 +196,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Infrastructure
public virtual void HeartbeatSlow(TimeSpan heartbeatDuration, TimeSpan interval, DateTimeOffset now)
{
_heartbeatSlow(_logger, heartbeatDuration, interval, now, null);
_heartbeatSlow(_logger, now, heartbeatDuration, interval, null);
}
public virtual void ApplicationNeverCompleted(string connectionId)

View File

@ -2,6 +2,7 @@
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System;
using System.Globalization;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
@ -22,15 +23,16 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
}
[Fact]
public async Task HeartbeatTakingLongerThanIntervalIsLoggedAsError()
public async Task HeartbeatTakingLongerThanIntervalIsLoggedAsWarning()
{
var systemClock = new MockSystemClock();
var heartbeatHandler = new Mock<IHeartbeatHandler>();
var debugger = new Mock<IDebugger>();
var kestrelTrace = new Mock<IKestrelTrace>();
var kestrelTrace = new TestKestrelTrace();
var handlerMre = new ManualResetEventSlim();
var handlerStartedTcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
var now = systemClock.UtcNow;
var heartbeatDuration = TimeSpan.FromSeconds(2);
heartbeatHandler.Setup(h => h.OnHeartbeat(now)).Callback(() =>
{
@ -41,7 +43,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
Task blockedHeartbeatTask;
using (var heartbeat = new Heartbeat(new[] { heartbeatHandler.Object }, systemClock, debugger.Object, kestrelTrace.Object))
using (var heartbeat = new Heartbeat(new[] { heartbeatHandler.Object }, systemClock, debugger.Object, kestrelTrace))
{
blockedHeartbeatTask = Task.Run(() => heartbeat.OnHeartbeat());
@ -56,11 +58,16 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Core.Tests
await blockedHeartbeatTask.DefaultTimeout();
heartbeatHandler.Verify(h => h.OnHeartbeat(now), Times.Once());
kestrelTrace.Verify(t => t.HeartbeatSlow(TimeSpan.FromSeconds(2), Heartbeat.Interval, now), Times.Once());
var warningMessage = kestrelTrace.Logger.Messages.Single(message => message.LogLevel == LogLevel.Warning).Message;
Assert.Equal($"As of \"{now.ToString(CultureInfo.InvariantCulture)}\", the heartbeat has been running for "
+ $"\"{heartbeatDuration.ToString("c", CultureInfo.InvariantCulture)}\" which is longer than "
+ $"\"{Heartbeat.Interval.ToString("c", CultureInfo.InvariantCulture)}\". "
+ "This could be caused by thread pool starvation.", warningMessage);
}
[Fact]
public async Task HeartbeatTakingLongerThanIntervalIsNotLoggedAsErrorIfDebuggerAttached()
public async Task HeartbeatTakingLongerThanIntervalIsNotLoggedIfDebuggerAttached()
{
var systemClock = new MockSystemClock();
var heartbeatHandler = new Mock<IHeartbeatHandler>();