runtime: LoggerExtensions.MessageFormatter takes an exception as argument but ignores it. - TraceSourceProvider should take exception into account, even if the formatter is not null.

Describe the bug

We are using Asp.net Core (3.1) and the “TraceSourceProvider” (logging.AddTraceSource(sourceSwitchName), which in turn uses the Microsoft.Extensions.Logging.TraceSource.TraceSourceLogger --> the TraceSourceLogger relies on the given MessageFormatter and does nothing withe the given exception. Because Func<TState, Exception, string> formatter of the ILogger interface is not null the TraceSourceLogger “thinks” the exception has already been taken into account by the formatter and does not add the exception (message/stacktrace,…) to the message that will be finally logged.

We are using Microsoft.Extensions.Logging 3.1.3, should this be fixed in the MessageFormatter method or should the TraceSourceLogger take care to add exception details?

To Reproduce

Steps to reproduce the behavior:

Configure Asp.Net Core logging to use the TraceSourceLogger (logging.AddTraceSource(sourceSwitchName))
Use ILogger<SomeClass> and log an exception, e.q logger.LogError("some message", someException);
Look at the log file, the exception is missing, the message (“some message”) is available

Expected behavior

If an exception is available it should be taken care of in the MessageFormatter and therfore the exception should be visible in the log file.

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 17 (15 by maintainers)

Most upvoted comments

so method " MessageFormatter " “private static string MessageFormatter(FormattedLogValues state, Exception error)” should include the exception details as well correct

I don’t think so. If it did that would cause duplicate exception logging. My understanding is that the default formatter delegate MessageFormatter should remain untouched and the only change made should be to TraceSourceLogger to include the exception even when formatter is not null.

ericstj on Sep 21, 2020

@ericstj your solution was working fine, thx.

rizi on Sep 24, 2020

Just to restate what’s going on here with some code.

TraceSourceLogger only includes the exception when a formatter is not present: https://github.com/dotnet/runtime/blob/8933510b35aab8bb49f999586d4169a2cd6d920a/src/libraries/Microsoft.Extensions.Logging.TraceSource/src/TraceSourceLogger.cs#L26-L40

The default formatter used doesn’t include exception: https://github.com/dotnet/runtime/blob/92b125fc7671b82433f3adbd085b7e6b29b1a73d/src/libraries/Microsoft.Extensions.Logging.Abstractions/src/LoggerExtensions.cs#L425-L428

As @KalleOlaviNiemitalo mentions above, @BrennanConroy stated this was by-design in aspnet/Announcements#148

We can look at other ILogger implementations and they all include the exception, even when formatter is not null.

https://github.com/dotnet/runtime/blob/92b125fc7671b82433f3adbd085b7e6b29b1a73d/src/libraries/Microsoft.Extensions.Logging.EventLog/src/EventLogLogger.cs#L115-L118 https://github.com/dotnet/runtime/blob/92b125fc7671b82433f3adbd085b7e6b29b1a73d/src/libraries/Microsoft.Extensions.Logging.Console/src/JsonConsoleFormatter.cs#L59-L67 https://github.com/dotnet/runtime/blob/92b125fc7671b82433f3adbd085b7e6b29b1a73d/src/libraries/Microsoft.Extensions.Logging.Console/src/SimpleConsoleFormatter.cs#L94-L98

etc…

Should TraceSourceLogger.Log<TState> then throw ArgumentNullException if formatter == null, like e.g. ConsoleLogger and DebugLogger do?

I don’t think so. That’s a public API that already defines behavior for null. Throwing would be a breaking change and I don’t see the value of making such a breaking change.

We just need to be sure to add the exception to the message even in the case formatter is non-null, just like the other ILogger implementations.

ericstj on Sep 18, 2020