Simplify usage of logging in transports

src/Servers/Kestrel/Transport.Quic/src/Internal/IQuicTrace.cs

@@ -2,19 +2,20 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
+using Microsoft.AspNetCore.Connections;
 using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Experimental.Quic.Internal
 {
  internal interface IQuicTrace : ILogger
  {
- void AcceptedConnection(string connectionId);
- void AcceptedStream(string streamId);
- void ConnectionError(string connectionId, Exception ex);
- void StreamError(string streamId, Exception ex);
- void StreamPause(string streamId);
- void StreamResume(string streamId);
- void StreamShutdownWrite(string streamId, string reason);
- void StreamAbort(string streamId, string reason);
+ void AcceptedConnection(BaseConnectionContext connection);
+ void AcceptedStream(QuicStreamContext streamContext);
+ void ConnectionError(BaseConnectionContext connection, Exception ex);
+ void StreamError(QuicStreamContext streamContext, Exception ex);
+ void StreamPause(QuicStreamContext streamContext);
+ void StreamResume(QuicStreamContext streamContext);
+ void StreamShutdownWrite(QuicStreamContext streamContext, string reason);
+ void StreamAbort(QuicStreamContext streamContext, string reason);
  }
 }

src/Servers/Kestrel/Transport.Quic/src/Internal/QuicConnectionContext.cs

@@ -32,10 +32,7 @@ public QuicConnectionContext(QuicConnection connection, QuicTransportContext con
  Features.Set<ITlsConnectionFeature>(new FakeTlsConnectionFeature());
  Features.Set<IProtocolErrorCodeFeature>(this);
 
- if (_log.IsEnabled(LogLevel.Debug))
- {
- _log.AcceptedConnection(ConnectionId);
- }
+ _log.AcceptedConnection(this);
  }
 
  public ValueTask<ConnectionContext> StartUnidirectionalStreamAsync()

src/Servers/Kestrel/Transport.Quic/src/Internal/QuicStreamContext.cs

@@ -131,10 +131,7 @@ private async Task DoReceive()
  {
  // This is unexpected.
  error = ex;
- if (_log.IsEnabled(LogLevel.Debug))
- {
- _log.StreamError(ConnectionId, error);
- }
+ _log.StreamError(this, error);
  }
  finally
  {
@@ -167,16 +164,16 @@ private async Task ProcessReceives()
 
  var paused = !flushTask.IsCompleted;
 
- if (paused && _log.IsEnabled(LogLevel.Debug))
+ if (paused)
  {
- _log.StreamPause(ConnectionId);
+ _log.StreamPause(this);
  }
 
  var result = await flushTask;
 
- if (paused && _log.IsEnabled(LogLevel.Debug))
+ if (paused)
  {
- _log.StreamResume(ConnectionId);
+ _log.StreamResume(this);
  }
 
  if (result.IsCompleted || result.IsCanceled)
@@ -237,10 +234,7 @@ private async Task DoSend()
  {
  shutdownReason = ex;
  unexpectedError = ex;
- if (_log.IsEnabled(LogLevel.Debug))
- {
- _log.ConnectionError(ConnectionId, unexpectedError);
- }
+ _log.ConnectionError(this, unexpectedError);
  }
  finally
  {
@@ -297,10 +291,7 @@ public override void Abort(ConnectionAbortedException abortReason)
 
  _aborted = true;
 
- if (_log.IsEnabled(LogLevel.Debug))
- {
- _log.StreamAbort(ConnectionId, abortReason.Message);
- }
+ _log.StreamAbort(this, abortReason.Message);
 
  lock (_shutdownLock)
  {
@@ -320,11 +311,8 @@ private async ValueTask ShutdownWrite(Exception? shutdownReason)
  {
  // TODO: Exception is always allocated. Consider only allocating if receive hasn't completed.
  _shutdownReason = shutdownReason ?? new ConnectionAbortedException("The Quic transport's send loop completed gracefully.");
+ _log.StreamShutdownWrite(this, _shutdownReason.Message);
 
- if (_log.IsEnabled(LogLevel.Debug))
- {
- _log.StreamShutdownWrite(ConnectionId, _shutdownReason.Message);
- }
  _stream.Shutdown();
  }
 

src/Servers/Kestrel/Transport.Quic/src/Internal/QuicTrace.cs

@@ -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 Microsoft.AspNetCore.Connections;
 using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Experimental.Quic.Internal
@@ -11,7 +12,7 @@ internal class QuicTrace : IQuicTrace
  private static readonly Action<ILogger, string, Exception?> _acceptedConnection =
  LoggerMessage.Define<string>(LogLevel.Debug, new EventId(1, "AcceptedConnection"), @"Connection id ""{ConnectionId}"" accepted.", skipEnabledCheck: true);
  private static readonly Action<ILogger, string, Exception?> _acceptedStream =
- LoggerMessage.Define<string>(LogLevel.Debug, new EventId(2, "AcceptedStream"), @"Stream id ""{ConnectionId}"" accepted.");
+ LoggerMessage.Define<string>(LogLevel.Debug, new EventId(2, "AcceptedStream"), @"Stream id ""{ConnectionId}"" accepted.", skipEnabledCheck: true);
  private static readonly Action<ILogger, string, Exception?> _connectionError =
  LoggerMessage.Define<string>(LogLevel.Debug, new EventId(3, "ConnectionError"), @"Connection id ""{ConnectionId}"" unexpected error.", skipEnabledCheck: true);
  private static readonly Action<ILogger, string, Exception?> _streamError =
@@ -39,44 +40,60 @@ public QuicTrace(ILogger logger)
  public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
  => _logger.Log(logLevel, eventId, state, exception, formatter);
 
- public void AcceptedConnection(string connectionId)
+ public void AcceptedConnection(BaseConnectionContext connection)
  {
- _acceptedConnection(_logger, connectionId, null);
+ if (!_logger.IsEnabled(LogLevel.Debug)) return;
+
+ _acceptedConnection(_logger, connection.ConnectionId, null);
  }
 
- public void AcceptedStream(string streamId)
+ public void AcceptedStream(QuicStreamContext streamContext)
  {
- _acceptedStream(_logger, streamId, null);
+ if (!_logger.IsEnabled(LogLevel.Debug)) return;
+
+ _acceptedStream(_logger, streamContext.ConnectionId, null);
  }
 
- public void ConnectionError(string connectionId, Exception ex)
+ public void ConnectionError(BaseConnectionContext connection, Exception ex)
  {
- _connectionError(_logger, connectionId, ex);
+ if (!_logger.IsEnabled(LogLevel.Debug)) return;
+
+ _connectionError(_logger, connection.ConnectionId, ex);
  }
 
- public void StreamError(string streamId, Exception ex)
+ public void StreamError(QuicStreamContext streamContext, Exception ex)
  {
- _streamError(_logger, streamId, ex);
+ if (!_logger.IsEnabled(LogLevel.Debug)) return;
+
+ _streamError(_logger, streamContext.ConnectionId, ex);
  }
 
- public void StreamPause(string streamId)
+ public void StreamPause(QuicStreamContext streamContext)
  {
- _streamPause(_logger, streamId, null);
+ if (!_logger.IsEnabled(LogLevel.Debug)) return;
+
+ _streamPause(_logger, streamContext.ConnectionId, null);
  }
 
- public void StreamResume(string streamId)
+ public void StreamResume(QuicStreamContext streamContext)
  {
- _streamResume(_logger, streamId, null);
+ if (!_logger.IsEnabled(LogLevel.Debug)) return;
+
+ _streamResume(_logger, streamContext.ConnectionId, null);
  }
 
- public void StreamShutdownWrite(string streamId, string reason)
+ public void StreamShutdownWrite(QuicStreamContext streamContext, string reason)
  {
- _streamShutdownWrite(_logger, streamId, reason, null);
+ if (!_logger.IsEnabled(LogLevel.Debug)) return;
+
+ _streamShutdownWrite(_logger, streamContext.ConnectionId, reason, null);
  }
 
- public void StreamAbort(string streamId, string reason)
+ public void StreamAbort(QuicStreamContext streamContext, string reason)
  {
- _streamAborted(_logger, streamId, reason, null);
+ if (!_logger.IsEnabled(LogLevel.Debug)) return;
+
+ _streamAborted(_logger, streamContext.ConnectionId, reason, null);
  }
  }
 }

src/Servers/Kestrel/Transport.Sockets/src/Internal/ISocketsTrace.cs

@@ -8,16 +8,17 @@ namespace Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.Internal
 {
  internal interface ISocketsTrace : ILogger
  {
- void ConnectionReadFin(string connectionId);
+ void ConnectionReadFin(SocketConnection connection);
 
- void ConnectionWriteFin(string connectionId, string reason);
+ void ConnectionWriteFin(SocketConnection connection, string reason);
 
- void ConnectionError(string connectionId, Exception ex);
+ void ConnectionError(SocketConnection connection, Exception ex);
 
  void ConnectionReset(string connectionId);
+ void ConnectionReset(SocketConnection connection);
 
- void ConnectionPause(string connectionId);
+ void ConnectionPause(SocketConnection connection);
 
- void ConnectionResume(string connectionId);
+ void ConnectionResume(SocketConnection connection);
  }
 }

src/Servers/Kestrel/Transport.Sockets/src/Internal/SocketConnection.cs

@@ -156,10 +156,7 @@ private async Task DoReceive()
  if (bytesReceived == 0)
  {
  // FIN
- if (_trace.IsEnabled(LogLevel.Debug))
- {
- _trace.ConnectionReadFin(ConnectionId);
- }
+ _trace.ConnectionReadFin(this);
  break;
  }
 
@@ -169,16 +166,16 @@ private async Task DoReceive()
 
  var paused = !flushTask.IsCompleted;
 
- if (paused && _trace.IsEnabled(LogLevel.Debug))
+ if (paused)
  {
- _trace.ConnectionPause(ConnectionId);
+ _trace.ConnectionPause(this);
  }
 
  var result = await flushTask;
 
- if (paused && _trace.IsEnabled(LogLevel.Debug))
+ if (paused)
  {
- _trace.ConnectionResume(ConnectionId);
+ _trace.ConnectionResume(this);
  }
 
  if (result.IsCompleted || result.IsCanceled)
@@ -197,7 +194,7 @@ private async Task DoReceive()
  // Both logs will have the same ConnectionId. I don't think it's worthwhile to lock just to avoid this.
  if (!_socketDisposed)
  {
- _trace.ConnectionReset(ConnectionId);
+ _trace.ConnectionReset(this);
  }
  }
  catch (Exception ex)
@@ -207,20 +204,17 @@ private async Task DoReceive()
  // This exception should always be ignored because _shutdownReason should be set.
  error = ex;
 
- if (!_socketDisposed && _trace.IsEnabled(LogLevel.Debug))
+ if (!_socketDisposed)
  {
  // This is unexpected if the socket hasn't been disposed yet.
- _trace.ConnectionError(ConnectionId, error);
+ _trace.ConnectionError(this, error);
  }
  }
  catch (Exception ex)
  {
  // This is unexpected.
  error = ex;
- if (_trace.IsEnabled(LogLevel.Debug))
- {
- _trace.ConnectionError(ConnectionId, error);
- }
+ _trace.ConnectionError(this, error);
  }
  finally
  {
@@ -271,10 +265,7 @@ private async Task DoSend()
  catch (SocketException ex) when (IsConnectionResetError(ex.SocketErrorCode))
  {
  shutdownReason = new ConnectionResetException(ex.Message, ex);
- if (_trace.IsEnabled(LogLevel.Debug))
- {
- _trace.ConnectionReset(ConnectionId);
- }
+ _trace.ConnectionReset(this);
  }
  catch (Exception ex)
  when ((ex is SocketException socketEx && IsConnectionAbortError(socketEx.SocketErrorCode)) ||
@@ -287,10 +278,7 @@ private async Task DoSend()
  {
  shutdownReason = ex;
  unexpectedError = ex;
- if (_trace.IsEnabled(LogLevel.Debug))
- {
- _trace.ConnectionError(ConnectionId, unexpectedError);
- }
+ _trace.ConnectionError(this, unexpectedError);
  }
  finally
  {
@@ -342,11 +330,7 @@ private void Shutdown(Exception? shutdownReason)
  // ever observe the nondescript ConnectionAbortedException except for connection middleware attempting
  // to half close the connection which is currently unsupported.
  _shutdownReason = shutdownReason ?? new ConnectionAbortedException("The Socket transport's send loop completed gracefully.");
-
- if (_trace.IsEnabled(LogLevel.Debug))
- {
- _trace.ConnectionWriteFin(ConnectionId, _shutdownReason.Message);
- }
+ _trace.ConnectionWriteFin(this, _shutdownReason.Message);
 
  try
  {