serilog / serilog-extensions-logging

Serilog provider for Microsoft.Extensions.Logging
Apache License 2.0
307 stars 97 forks source link

SerilogLogger.cs - Always calls formatter with the Exception parameter as null #237

Open wooster11 opened 5 months ago

wooster11 commented 5 months ago

In the AsLoggableValue method of the SerilogLogger, the formatter delegate is always invoked with the exception parameter as null. This causes issues if the Exception object is used in the formatter delegate that gets passed into a "Log" call. Is there a specific design decision for this?

static object? AsLoggableValue<TState>(TState state, Func<TState, Exception?, string>? formatter)
{
    object? stateObj = state;
    if (formatter != null)
        stateObj = formatter(state, null);
    return stateObj;
}

This is a very contrived example of when this fails. If my application uses Serilog for logging but needs to pass a Microsoft.Extensions.Logging.ILogger into a class library of some kind for logging, it's possible that the class library will fail if it expects the exception to be there and formattable. The class library should handle the null reference through a null check, but this will always be true, and the exception will never be formatted to be logged even when expected.

Example code of a call that will fail:

public class SomeLibraryClass
{
    public SomeLibraryClass(ILogger logger)
    {
        this._logger = logger;
    }

    private ILogger _logger;

    public void DoWork(string workType)
    {
        this._logger.LogInformation($"SomeLibraryClass: Starting DoWork for work type: {workType}");

        var dict = new Dictionary<int, string>
        {
            { 1, "One" },
            { 2, "Two" },
            { 3, "Three" },
            { 4, "Four" }
        };

        // This call works and handles the exception properly.
        this._logger.LogWarning(new System.Exception("An Exception"), "A Message");

        // The exception parameter of the formatter is always null. It will never be logged.
        this._logger.Log(LogLevel.Warning,
            100,
            dict,
            new System.Exception("Some kind of Exception Message for this Dictionary"),
            (state, exception) =>
            {
                var sb = new StringBuilder();
                foreach (var key in state.Keys)
                {
                    sb.AppendLine($"{key}: {state[key]}");
                }

                if (exception != null)
                {
                    sb.AppendLine(exception.Message);
                }

                return sb.ToString();
            });

        this._logger.LogInformation($"SomeLibraryClass: Ending DoWork for work type: {workType}");
    }
}
nblumhardt commented 5 months ago

Thanks for raising this. Serilog needs the message and exception separately, so my guess is that this is done this way to avoid redundantly stringifying the exception into the message.

If there's a path to obtaining the behavior you want without breaking any existing consumers of the library (i.e. by unexpectedly changing the way events are constructed) it could definitely be considered, if you're keen to dig in deeper.

Otherwise, I suspect your best option might be to wrap SerilogLoggerProvider and adapt it using your own implementation of the Log method.

HTH!