From ab4335266aa7c8920381c1fc383560afe3cd0c3a Mon Sep 17 00:00:00 2001 From: David Fowler Date: Fri, 24 Mar 2017 02:03:46 -0700 Subject: [PATCH 1/2] Logging shouldn't throw after dispose - Check complete adding before adding new messages to the list. - Added a test --- .../Internal/ConsoleLoggerProcessor.cs | 5 +- .../ConsoleLoggerTest.cs | 52 ++++++++++++------- 2 files changed, 36 insertions(+), 21 deletions(-) diff --git a/src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs b/src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs index b6b676e3..fba97a03 100644 --- a/src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs +++ b/src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs @@ -27,7 +27,10 @@ public ConsoleLoggerProcessor() public virtual void EnqueueMessage(LogMessageEntry message) { - _messageQueue.Add(message); + if (!_messageQueue.IsAddingCompleted) + { + _messageQueue.Add(message); + } } // for testing diff --git a/test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs b/test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs index bfe02d1d..2d2c4063 100644 --- a/test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs +++ b/test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs @@ -769,12 +769,12 @@ public void WriteCore_NullMessageWithException() var expected = ex.ToString() + Environment.NewLine; // Act - logger.Log(LogLevel.Critical, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Error, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Warning, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Information, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Debug, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Trace, 0, message, ex, (s,e) => s); + logger.Log(LogLevel.Critical, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Error, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Warning, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Information, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Debug, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Trace, 0, message, ex, (s, e) => s); // Assert Assert.Equal(6, sink.Writes.Count); @@ -796,12 +796,12 @@ public void WriteCore_MessageWithNullException() Exception ex = null; // Act - logger.Log(LogLevel.Critical, 0, _state, ex, (s,e) => s); - logger.Log(LogLevel.Error, 0, _state, ex, (s,e) => s); - logger.Log(LogLevel.Warning, 0, _state, ex, (s,e) => s); - logger.Log(LogLevel.Information, 0, _state, ex, (s,e) => s); - logger.Log(LogLevel.Debug, 0, _state, ex, (s,e) => s); - logger.Log(LogLevel.Trace, 0, _state, ex, (s,e) => s); + logger.Log(LogLevel.Critical, 0, _state, ex, (s, e) => s); + logger.Log(LogLevel.Error, 0, _state, ex, (s, e) => s); + logger.Log(LogLevel.Warning, 0, _state, ex, (s, e) => s); + logger.Log(LogLevel.Information, 0, _state, ex, (s, e) => s); + logger.Log(LogLevel.Debug, 0, _state, ex, (s, e) => s); + logger.Log(LogLevel.Trace, 0, _state, ex, (s, e) => s); // Assert Assert.Equal(12, sink.Writes.Count); @@ -824,17 +824,29 @@ public void WriteCore_NullMessageWithNullException() string message = null; // Act - logger.Log(LogLevel.Critical, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Error, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Warning, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Information, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Debug, 0, message, ex, (s,e) => s); - logger.Log(LogLevel.Trace, 0, message, ex, (s,e) => s); + logger.Log(LogLevel.Critical, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Error, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Warning, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Information, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Debug, 0, message, ex, (s, e) => s); + logger.Log(LogLevel.Trace, 0, message, ex, (s, e) => s); // Assert Assert.Equal(0, sink.Writes.Count); } + [Fact] + public void LogAfterDisposeDoesNotThrow() + { + var sink = new ConsoleSink(); + var console = new TestConsole(sink); + var processor = new ConsoleLoggerProcessor(); + var logger = new ConsoleLogger(_loggerName, filter: null, includeScopes: false, loggerProcessor: processor); + logger.Console = console; + processor.Dispose(); + logger.LogInformation("Logging after dispose"); + } + private string GetMessage(string logLevelString, int eventId, Exception exception) => GetMessage(logLevelString, eventId, _state, exception); @@ -849,9 +861,9 @@ private string GetMessage(string logLevelString, int eventId, TState sta + _paddingString + ReplaceMessageNewLinesWithPadding(state?.ToString()) + Environment.NewLine - + ( exception != null + + (exception != null ? exception.ToString() + Environment.NewLine - : string.Empty ); + : string.Empty); } private string ReplaceMessageNewLinesWithPadding(string message) From 81424d2d6a70058c1f06aca3111e6ae6c24df9ce Mon Sep 17 00:00:00 2001 From: Pavel Krymets Date: Mon, 3 Apr 2017 13:41:27 -0700 Subject: [PATCH 2/2] Always log messages and never throw --- .../Internal/ConsoleLoggerProcessor.cs | 10 +++++++++- .../ConsoleLoggerTest.cs | 8 +++++++- 2 files changed, 16 insertions(+), 2 deletions(-) diff --git a/src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs b/src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs index fba97a03..43efe5cb 100644 --- a/src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs +++ b/src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs @@ -29,8 +29,16 @@ public virtual void EnqueueMessage(LogMessageEntry message) { if (!_messageQueue.IsAddingCompleted) { - _messageQueue.Add(message); + try + { + _messageQueue.Add(message); + return; + } + catch (InvalidOperationException) { } } + + // Adding is completed so just log the message + WriteMessage(message); } // for testing diff --git a/test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs b/test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs index 2d2c4063..44de8333 100644 --- a/test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs +++ b/test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs @@ -836,15 +836,21 @@ public void WriteCore_NullMessageWithNullException() } [Fact] - public void LogAfterDisposeDoesNotThrow() + public void LogAfterDisposeWritesLog() { + // Arrange var sink = new ConsoleSink(); var console = new TestConsole(sink); var processor = new ConsoleLoggerProcessor(); var logger = new ConsoleLogger(_loggerName, filter: null, includeScopes: false, loggerProcessor: processor); logger.Console = console; + + // Act processor.Dispose(); logger.LogInformation("Logging after dispose"); + + // Assert + Assert.True(sink.Writes.Count == 2); } private string GetMessage(string logLevelString, int eventId, Exception exception)