diff --git a/src/Kestrel.Transport.Libuv/Internal/ILibuvTrace.cs b/src/Kestrel.Transport.Libuv/Internal/ILibuvTrace.cs index db282bf4b2..4906efadf0 100644 --- a/src/Kestrel.Transport.Libuv/Internal/ILibuvTrace.cs +++ b/src/Kestrel.Transport.Libuv/Internal/ILibuvTrace.cs @@ -14,8 +14,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal void ConnectionWriteFin(string connectionId); - void ConnectionWroteFin(string connectionId, int status); - void ConnectionWrite(string connectionId, int count); void ConnectionWriteCallback(string connectionId, int status); @@ -28,6 +26,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal void ConnectionResume(string connectionId); - void ConnectionAborted(string connectionId); + void ConnectionAborted(string connectionId, string message); } } diff --git a/src/Kestrel.Transport.Libuv/Internal/LibuvConnection.cs b/src/Kestrel.Transport.Libuv/Internal/LibuvConnection.cs index 47f4b112dd..4d01959cda 100644 --- a/src/Kestrel.Transport.Libuv/Internal/LibuvConnection.cs +++ b/src/Kestrel.Transport.Libuv/Internal/LibuvConnection.cs @@ -119,7 +119,11 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal public override void Abort(ConnectionAbortedException abortReason) { + Log.ConnectionAborted(ConnectionId, abortReason?.Message); + _abortReason = abortReason; + + // Cancel WriteOutputAsync loop after setting _abortReason. Output.CancelPendingRead(); // This cancels any pending I/O. diff --git a/src/Kestrel.Transport.Libuv/Internal/LibuvTrace.cs b/src/Kestrel.Transport.Libuv/Internal/LibuvTrace.cs index 0467c7b776..fa70bd3853 100644 --- a/src/Kestrel.Transport.Libuv/Internal/LibuvTrace.cs +++ b/src/Kestrel.Transport.Libuv/Internal/LibuvTrace.cs @@ -22,9 +22,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal private static readonly Action _connectionWriteFin = LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(ConnectionWriteFin)), @"Connection id ""{ConnectionId}"" sending FIN."); - private static readonly Action _connectionWroteFin = - LoggerMessage.Define(LogLevel.Debug, new EventId(8, nameof(ConnectionWroteFin)), @"Connection id ""{ConnectionId}"" sent FIN with status ""{Status}""."); - // ConnectionWrite: Reserved: 11 // ConnectionWriteCallback: Reserved: 12 @@ -35,8 +32,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal private static readonly Action _connectionReset = LoggerMessage.Define(LogLevel.Debug, new EventId(19, nameof(ConnectionReset)), @"Connection id ""{ConnectionId}"" reset."); - private static readonly Action _connectionAborted = - LoggerMessage.Define(LogLevel.Debug, new EventId(20, nameof(ConnectionAborted)), @"Connection id ""{ConnectionId}"" aborted."); + private static readonly Action _connectionAborted = + LoggerMessage.Define(LogLevel.Debug, new EventId(20, nameof(ConnectionAborted)), @"Connection id ""{ConnectionId}"" closing because: ""{Message}"""); private readonly ILogger _logger; @@ -61,11 +58,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal _connectionWriteFin(_logger, connectionId, null); } - public void ConnectionWroteFin(string connectionId, int status) - { - _connectionWroteFin(_logger, connectionId, status, null); - } - public void ConnectionWrite(string connectionId, int count) { // Don't log for now since this could be *too* verbose. @@ -98,9 +90,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Libuv.Internal _connectionResume(_logger, connectionId, null); } - public void ConnectionAborted(string connectionId) + public void ConnectionAborted(string connectionId, string message) { - _connectionAborted(_logger, connectionId, null); + _connectionAborted(_logger, connectionId, message, null); } public IDisposable BeginScope(TState state) => _logger.BeginScope(state); diff --git a/src/Kestrel.Transport.Sockets/Internal/ISocketsTrace.cs b/src/Kestrel.Transport.Sockets/Internal/ISocketsTrace.cs index d08408e2b0..585bfcc816 100644 --- a/src/Kestrel.Transport.Sockets/Internal/ISocketsTrace.cs +++ b/src/Kestrel.Transport.Sockets/Internal/ISocketsTrace.cs @@ -20,6 +20,6 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal void ConnectionResume(string connectionId); - void ConnectionAborted(string connectionId); + void ConnectionAborted(string connectionId, string message); } } diff --git a/src/Kestrel.Transport.Sockets/Internal/SocketConnection.cs b/src/Kestrel.Transport.Sockets/Internal/SocketConnection.cs index d9cd3887e5..f78cd69584 100644 --- a/src/Kestrel.Transport.Sockets/Internal/SocketConnection.cs +++ b/src/Kestrel.Transport.Sockets/Internal/SocketConnection.cs @@ -92,7 +92,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal public override void Abort(ConnectionAbortedException abortReason) { - _trace.ConnectionAborted(ConnectionId); + _trace.ConnectionAborted(ConnectionId, abortReason?.Message); // Try to gracefully close the socket to match libuv behavior. Shutdown(abortReason); diff --git a/src/Kestrel.Transport.Sockets/Internal/SocketsTrace.cs b/src/Kestrel.Transport.Sockets/Internal/SocketsTrace.cs index 5b132ccf9c..53d902312b 100644 --- a/src/Kestrel.Transport.Sockets/Internal/SocketsTrace.cs +++ b/src/Kestrel.Transport.Sockets/Internal/SocketsTrace.cs @@ -22,14 +22,18 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal private static readonly Action _connectionWriteFin = LoggerMessage.Define(LogLevel.Debug, new EventId(7, nameof(ConnectionWriteFin)), @"Connection id ""{ConnectionId}"" sending FIN."); + // ConnectionWrite: Reserved: 11 + + // ConnectionWriteCallback: Reserved: 12 + private static readonly Action _connectionError = LoggerMessage.Define(LogLevel.Information, new EventId(14, nameof(ConnectionError)), @"Connection id ""{ConnectionId}"" communication error."); private static readonly Action _connectionReset = LoggerMessage.Define(LogLevel.Debug, new EventId(19, nameof(ConnectionReset)), @"Connection id ""{ConnectionId}"" reset."); - private static readonly Action _connectionAborted = - LoggerMessage.Define(LogLevel.Debug, new EventId(20, nameof(ConnectionAborted)), @"Connection id ""{ConnectionId}"" aborted."); + private static readonly Action _connectionAborted = + LoggerMessage.Define(LogLevel.Debug, new EventId(20, nameof(ConnectionAborted)), @"Connection id ""{ConnectionId}"" closing because: ""{Message}"""); private readonly ILogger _logger; @@ -86,9 +90,9 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal _connectionResume(_logger, connectionId, null); } - public void ConnectionAborted(string connectionId) + public void ConnectionAborted(string connectionId, string message) { - _connectionAborted(_logger, connectionId, null); + _connectionAborted(_logger, connectionId, message, null); } public IDisposable BeginScope(TState state) => _logger.BeginScope(state); diff --git a/test/Kestrel.InMemory.FunctionalTests/TestTransport/InMemoryTransportConnection.cs b/test/Kestrel.InMemory.FunctionalTests/TestTransport/InMemoryTransportConnection.cs index 37a83df22b..50db85725d 100644 --- a/test/Kestrel.InMemory.FunctionalTests/TestTransport/InMemoryTransportConnection.cs +++ b/test/Kestrel.InMemory.FunctionalTests/TestTransport/InMemoryTransportConnection.cs @@ -8,6 +8,7 @@ using System.Net; using System.Threading; using Microsoft.AspNetCore.Connections; using Microsoft.AspNetCore.Server.Kestrel.Transport.Abstractions.Internal; +using Microsoft.Extensions.Logging; namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTransport { @@ -15,11 +16,13 @@ namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTrans { private readonly CancellationTokenSource _connectionClosedTokenSource = new CancellationTokenSource(); + private readonly ILogger _logger; private bool _isClosed; - public InMemoryTransportConnection(MemoryPool memoryPool) + public InMemoryTransportConnection(MemoryPool memoryPool, ILogger logger) { MemoryPool = memoryPool; + _logger = logger; LocalAddress = IPAddress.Loopback; RemoteAddress = IPAddress.Loopback; @@ -28,6 +31,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTrans } public override MemoryPool MemoryPool { get; } + public override PipeScheduler InputWriterScheduler => PipeScheduler.ThreadPool; public override PipeScheduler OutputReaderScheduler => PipeScheduler.ThreadPool; @@ -35,6 +39,8 @@ namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTrans public override void Abort(ConnectionAbortedException abortReason) { + _logger.LogDebug(@"Connection id ""{ConnectionId}"" closing because: ""{Message}""", ConnectionId, abortReason?.Message); + Input.Complete(abortReason); AbortReason = abortReason; diff --git a/test/Kestrel.InMemory.FunctionalTests/TestTransport/TestServer.cs b/test/Kestrel.InMemory.FunctionalTests/TestTransport/TestServer.cs index eab6513a53..388b8fa944 100644 --- a/test/Kestrel.InMemory.FunctionalTests/TestTransport/TestServer.cs +++ b/test/Kestrel.InMemory.FunctionalTests/TestTransport/TestServer.cs @@ -96,7 +96,7 @@ namespace Microsoft.AspNetCore.Server.Kestrel.InMemory.FunctionalTests.TestTrans public InMemoryConnection CreateConnection() { - var transportConnection = new InMemoryTransportConnection(_memoryPool); + var transportConnection = new InMemoryTransportConnection(_memoryPool, Context.Log); _ = HandleConnection(transportConnection); return new InMemoryConnection(transportConnection); }