ILogger.LogInformation skips destructuring when passed single parameter

[cperras]

If I pass a single param to ILogger.LogInformation (or similar), the param is not destructured. However, if i pass more than one parameter, all objects are destructured as expected:

        string[] myArray = new[] { "one", "two" };
        _logger.LogInformation("MyArray: {@MyArray}", myArray);
        _logger.LogInformation("MyArray: {@MyArray1} {@MyArray2}", myArray, myArray);

output, using JsonFormatter:

{"Timestamp":"2018-04-10T16:18:22.8926560-07:00","Level":"Information","MessageTemplate":"MyArray: {@MyArray}","Properties":{"MyArray":"one"}} {"Timestamp":"2018-04-10T16:18:22.8954264-07:00","Level":"Information","MessageTemplate":"MyArray: {@MyArray1} {@MyArray2}","Properties":{"MyArray1":["one","two"],"MyArray2":["one","two"]}

[nblumhardt]

This is an issue with C# array covariance; your call:

_logger.LogInformation("MyArray: {@MyArray}", myArray)

is being resolved to the params object[] overload of LogInformation().

(Serilog has some tricky code to work around this in its own ILogger implementation, IIRC, but MEL doesn't do anything special with it.)

_logger.LogInformation("MyArray: {@MyArray}", new object[] { myArray })

will do the trick. HTH!

[Mario-Hofstaetter]

Sorry for replying to an old thread. We hit the same issue and found this. While using this example https://github.com/serilog/serilog/wiki/Structured-Data#collections the MEL ILogger logs incorrect.

This is a landmine for ours devs waiting to blow up (missing Collection data in logs when they need them later).

I am also able to reproduce one case with the Serilog Logger (but this issue would belong in the core repo):

object[] fruitArr = { "Apple", "Pear", "Orange" };
Serilog.Log.Information("7 Does not work: {Fruit}", fruitArr);

Output: [11:07:14 INF] 7 Does not work: Apple

Is it impossible for serilog to make the right decision in this case?

@nblumhardt Do you think this is something Microsoft can fix in their ILogger ? I'd like to open an issue in their repository. The workaround _logger.LogInformation("MyArray: {@MyArray}", new object[] { myArray }) is easy to forget and quite the eyesore.

I guess currently the only solution is to ban usage of arrays and always use a List

https://dotnetfiddle.net/If7ySo

Full Code if anyone google lands here:

using System.Collections.Generic;
using Microsoft.Extensions.Logging;
using Serilog;
using Serilog.Sinks.SystemConsole.Themes;

namespace ConsoleApp1
{
    class Program
    {
        static void Main(string[] args)
        {
            Serilog.Log.Logger = new LoggerConfiguration()
                .WriteTo.Console(theme: ConsoleTheme.None) // Theme necessary for dotnetfiddle output
                .CreateLogger();

            using var loggerFactory = LoggerFactory.Create(builder =>
            {
                builder.ClearProviders();
                builder.AddSerilog(Serilog.Log.Logger);
            });

            var melILogger = loggerFactory.CreateLogger<Program>();

            string[] fruitStringArray = { "Apple", "Pear", "Orange" };

            Serilog.Log.Information("1 Works: {Fruit}", fruitStringArray);
            melILogger.LogInformation("2 Does not work: {Fruit}", fruitStringArray);
            melILogger.LogInformation("3 Works: {@Fruit}", new []{fruitStringArray});
            melILogger.LogInformation("4 Works: {Fruit} and {Foobar}", fruitStringArray, "barbaz");

            var fruitList = new List<string> { "Apple", "Pear", "Orange" };

            Serilog.Log.Information("5 Works: {FruitList}", fruitList);
            melILogger.LogInformation("6 Works: {FruitList}", fruitList);

            object[] fruitArr = { "Apple", "Pear", "Orange" };

            Serilog.Log.Information("7 Does not work: {Fruit}", fruitArr);
            melILogger.LogInformation("8 Does not work: {Fruit}", fruitArr);
        }
    }
}

[Numpsy]

Is that an area where the logging analyzer packages (either the Serilog one or the MEL equivalent one) could highlight possible issues? (I don't know if they can, i'm just wondering about the possibility)

[Mario-Hofstaetter]

Is that an area where the logging analyzer packages (either the Serilog one or the MEL equivalent one) could highlight possible issues? (I don't know if they can, i'm just wondering about the possibility)

I have tried the SerilogAnalyzer nuget package and it did not seem to support MEL ILogger unfortunately (just Serilogs Logger).

We have installed this Structured Logging Jetbrains Rider Extension, which is great. But it does not warn about this particular issue though.

It is Open Source, I could try to raise an issue in the authors repo. Theoretically we could also fork it and implement ourselves, but ain't nobody got time for that.

[nblumhardt]

FWIW, the current behavior is consistent with how other .NET APIs work:

> Console.WriteLine("Test {0}", new object[] { 1, 2, 3 })
Test 1

Definitely seems like the analyzer path is a better option than attempting more workarounds :+1: