Skip to content
This repository was archived by the owner on Dec 13, 2018. It is now read-only.

Logging shouldn't throw after dispose #578

Merged
merged 2 commits into from
Apr 4, 2017
Merged

Logging shouldn't throw after dispose #578

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
ab43352
Logging shouldn't throw after dispose
davidfowl Mar 24, 2017
81424d2
Always log messages and never throw
pakrym Apr 3, 2017
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 12 additions & 1 deletion src/Microsoft.Extensions.Logging.Console/Internal/ConsoleLoggerProcessor.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,18 @@ public ConsoleLoggerProcessor()

public virtual void EnqueueMessage(LogMessageEntry message)
{
_messageQueue.Add(message);
if (!_messageQueue.IsAddingCompleted)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Other threads can call EnqueueMessage while Dispose is being called, so this doesn't get rid of the issue, just decreases how often it happens.

{
try
{
_messageQueue.Add(message);
return;
}
catch (InvalidOperationException) { }
}

// Adding is completed so just log the message
WriteMessage(message);
}

// for testing
Expand Down
58 changes: 38 additions & 20 deletions test/Microsoft.Extensions.Logging.Test/ConsoleLoggerTest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand All @@ -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);
Expand All @@ -824,17 +824,35 @@ 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 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)
=> GetMessage(logLevelString, eventId, _state, exception);

Expand All @@ -849,9 +867,9 @@ private string GetMessage<TState>(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)
Expand Down