From 1ebf98d40d715fba0028250ca2acdf0408ab7e0d Mon Sep 17 00:00:00 2001 From: Stephen Halter Date: Wed, 9 Sep 2015 13:06:47 -0700 Subject: [PATCH] Log message style changes - Disabled some log messages for possibly being too verbose. - Don't log ConnectionReadFin when there is an error. --- .../Http/Connection.cs | 17 ++++++---- .../Infrastructure/IKestrelTrace.cs | 4 ++- .../Infrastructure/KestrelTrace.cs | 34 ++++++++++++------- 3 files changed, 34 insertions(+), 21 deletions(-) diff --git a/src/Microsoft.AspNet.Server.Kestrel/Http/Connection.cs b/src/Microsoft.AspNet.Server.Kestrel/Http/Connection.cs index fdccb3122b..2524516181 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/Http/Connection.cs +++ b/src/Microsoft.AspNet.Server.Kestrel/Http/Connection.cs @@ -72,7 +72,6 @@ namespace Microsoft.AspNet.Server.Kestrel.Http } else if (normalDone || errorDone) { - Log.ConnectionReadFin(_connectionId); SocketInput.RemoteIntakeFin = true; _socket.ReadStop(); @@ -80,6 +79,10 @@ namespace Microsoft.AspNet.Server.Kestrel.Http { Log.LogError("Connection.OnRead", error); } + else + { + Log.ConnectionReadFin(_connectionId); + } } @@ -118,19 +121,19 @@ namespace Microsoft.AspNet.Server.Kestrel.Http } _connectionState = ConnectionState.Shutdown; - Log.ConnectionWriteFin(_connectionId, 0); + Log.ConnectionWriteFin(_connectionId); Thread.Post( state => { - Log.ConnectionWriteFin(_connectionId, 1); var self = (Connection)state; - var shutdown = new UvShutdownReq(Log); + var shutdown = new UvShutdownReq(self.Log); shutdown.Init(self.Thread.Loop); - shutdown.Shutdown(self._socket, (req, status, _) => + shutdown.Shutdown(self._socket, (req, status, state2) => { - Log.ConnectionWriteFin(_connectionId, 1); + var self2 = (Connection)state2; + self2.Log.ConnectionWroteFin(_connectionId, status); req.Dispose(); - }, null); + }, this); }, this); break; diff --git a/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/IKestrelTrace.cs b/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/IKestrelTrace.cs index 478b573fe8..cb825bac39 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/IKestrelTrace.cs +++ b/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/IKestrelTrace.cs @@ -16,7 +16,9 @@ namespace Microsoft.AspNet.Server.Kestrel.Infrastructure void ConnectionReadFin(long connectionId); - void ConnectionWriteFin(long connectionId, int step); + void ConnectionWriteFin(long connectionId); + + void ConnectionWroteFin(long connectionId, int status); void ConnectionKeepAlive(long connectionId); diff --git a/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelTrace.cs b/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelTrace.cs index c9ce6bb820..2a148ed302 100644 --- a/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelTrace.cs +++ b/src/Microsoft.AspNet.Server.Kestrel/Infrastructure/KestrelTrace.cs @@ -21,57 +21,65 @@ namespace Microsoft.AspNet.Server.Kestrel public void ConnectionStart(long connectionId) { - _logger.LogDebug(13, $"{nameof(ConnectionStart)} -> Id: {connectionId}"); + _logger.LogDebug(1, @"Connection id ""{ConnectionId}"" started.", connectionId); } public void ConnectionStop(long connectionId) { - _logger.LogDebug(14, $"{nameof(ConnectionStop)} -> Id: {connectionId}"); + _logger.LogDebug(2, @"Connection id ""{ConnectionId}"" stopped.", connectionId); } - public void ConnectionRead(long connectionId, int status) + public void ConnectionRead(long connectionId, int count) { - _logger.LogDebug(4, $"{nameof(ConnectionRead)} -> Id: {connectionId}, Status: {status}"); + // Don't log for now since this could be *too* verbose. + //_logger.LogVerbose(3, @"Connection id ""{ConnectionId}"" received ""{Count}"" bytes.", connectionId, count); } public void ConnectionPause(long connectionId) { - _logger.LogDebug(5, $"{nameof(ConnectionPause)} -> Id: {connectionId}"); + _logger.LogDebug(4, @"Connection id ""{ConnectionId}"" paused.", connectionId); } public void ConnectionResume(long connectionId) { - _logger.LogDebug(6, $"{nameof(ConnectionResume)} -> Id: {connectionId}"); + _logger.LogDebug(5, @"Connection id ""{ConnectionId}"" resumed.", connectionId); } public void ConnectionReadFin(long connectionId) { - _logger.LogDebug(7, $"{nameof(ConnectionReadFin)} -> Id: {connectionId}"); + _logger.LogDebug(6, @"Connection id ""{ConnectionId}"" received FIN.", connectionId); } - public void ConnectionWriteFin(long connectionId, int step) + public void ConnectionWriteFin(long connectionId) { - _logger.LogDebug(8, $"{nameof(ConnectionWriteFin)} -> Id: {connectionId}, Step: {step}"); + _logger.LogDebug(7, @"Connection id ""{ConnectionId}"" sending FIN."); + } + + public void ConnectionWroteFin(long connectionId, int status) + { + _logger.LogDebug(8, @"Connection id ""{ConnectionId}"" sent FIN with status ""{Status}"".", status); } public void ConnectionKeepAlive(long connectionId) { - _logger.LogDebug(9, $"{nameof(ConnectionKeepAlive)} -> Id: {connectionId}"); + _logger.LogDebug(9, @"Connection id ""{ConnectionId}"" completed keep alive response.", connectionId); } public void ConnectionDisconnect(long connectionId) { - _logger.LogDebug(10, $"{nameof(ConnectionDisconnect)} -> Id: {connectionId}"); + _logger.LogDebug(10, @"Connection id ""{ConnectionId}"" disconnected.", connectionId); } public void ConnectionWrite(long connectionId, int count) { - _logger.LogDebug(11, $"{nameof(ConnectionWrite)} -> Id: {connectionId}, Count: {count}"); + // Don't log for now since this could be *too* verbose. + //_logger.LogVerbose(11, @"Connection id ""{ConnectionId}"" sent ""{Count}"" bytes.", connectionId, count); } public void ConnectionWriteCallback(long connectionId, int status) { - _logger.LogDebug(12, $"{nameof(ConnectionWriteCallback)} -> Id: {connectionId}, Status: {status}"); + // Don't log for now since this could be *too* verbose. + //_logger.LogVerbose(12, @"Connection id ""{ConnectionId}"" finished write with status ""{Status}"".", connectionId, status); } public void Log(LogLevel logLevel, int eventId, object state, Exception exception, Func formatter)