Microsoft.Extensions.Logging.Console logs an unnecessary Message node in a Scopes node

[bartlomiejgawel]

Description

Consider the following code:

var serviceProvider = new ServiceCollection()
    .AddLogging(options =>
    {
        options.AddJsonConsole(jsonOptions =>
        {
            jsonOptions.IncludeScopes = true;
            jsonOptions.JsonWriterOptions = new JsonWriterOptions { Indented = true };
        });
    })
    .BuildServiceProvider();

var logger = serviceProvider.GetRequiredService<ILogger<Program>>();

using (logger.BeginScope(new Dictionary<string, object> { ["Id"] = "Value" }))
{
    logger.LogInformation("Test");
}

You want to add an additional property by using the BeginScope method. It works but it also adds an unnecessary node Message for no reason:

{
  "EventId": 0,
  "LogLevel": "Information",
  "Category": "Program",
  "Message": "Test",
  "State": {
    "Message": "Test",
    "{OriginalFormat}": "Test"
  },
  "Scopes": [
    {
      "Message": "System.Collections.Generic.Dictionary\u00602[System.String,System.Object]",
      "Id": "Value"
    }
  ]
}

It would be nice to either remove that Message node or add a flag to remove it:
https://github.com/dotnet/runtime/blob/main/src/libraries/Microsoft.Extensions.Logging.Console/src/JsonConsoleFormatter.cs#L111

Reproduction Steps

You can test it here or by running the following code:

using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using System.Collections.Generic;
using System.Text.Json;

public class Program
{
    public static void Main()
    {
        var serviceProvider = new ServiceCollection()
            .AddLogging(options =>
            {
                options.AddJsonConsole(jsonOptions =>
                {
                    jsonOptions.IncludeScopes = true;
                    jsonOptions.JsonWriterOptions = new JsonWriterOptions { Indented = true };
                });
            })
            .BuildServiceProvider();

        var logger = serviceProvider.GetRequiredService<ILogger<Program>>();

        using (logger.BeginScope(new Dictionary<string, object> { ["Id"] = "Value" }))
        {
            logger.LogInformation("Test");
        }
    }
}

Expected behavior

It would be nice to have the following output:

{
  "EventId": 0,
  "LogLevel": "Information",
  "Category": "Program",
  "Message": "Test",
  "State": {
    "Message": "Test",
    "{OriginalFormat}": "Test"
  },
  "Scopes": [
    {
      "Id": "Value"
    }
  ]
}

Actual behavior

Currently, it prints the following result:

{
  "EventId": 0,
  "LogLevel": "Information",
  "Category": "Program",
  "Message": "Test",
  "State": {
    "Message": "Test",
    "{OriginalFormat}": "Test"
  },
  "Scopes": [
    {
      "Message": "System.Collections.Generic.Dictionary\u00602[System.String,System.Object]",
      "Id": "Value"
    }
  ]
}

Regression?

No

Known Workarounds

No response

Configuration

No response

Other information

No response

Tagging subscribers to this area: @dotnet/area-extensions-logging
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Description

Consider the following code:

var serviceProvider = new ServiceCollection()
    .AddLogging(options =>
    {
        options.AddJsonConsole(options =>
        {
            options.IncludeScopes = true;
            options.JsonWriterOptions = new JsonWriterOptions { Indented = true };
        });
    })
    .BuildServiceProvider();

var logger = serviceProvider.GetRequiredService<ILogger<Program>>();

using (logger.BeginScope(new Dictionary<string, object> { ["Id"] = "Value" }))
{
    logger.LogInformation("Test");
}

You want to add an additional property by using the BeginScope method. It works but it also adds an unnecessary node Message for no reason:

{
  "EventId": 0,
  "LogLevel": "Information",
  "Category": "Program",
  "Message": "Test",
  "State": {
    "Message": "Test",
    "{OriginalFormat}": "Test"
  },
  "Scopes": [
    {
      "Message": "System.Collections.Generic.Dictionary\u00602[System.String,System.Object]",
      "Id": "Value"
    }
  ]
}

It would be nice to either remove that Message node or add a flag to remove it:
https://github.com/dotnet/runtime/blob/main/src/libraries/Microsoft.Extensions.Logging.Console/src/JsonConsoleFormatter.cs#L111

Reproduction Steps

You can test it here or by running the following code:

using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using System;
using System.Collections.Generic;
using System.Text.Json;

public class Program
{
    public static void Main()
    {
        var serviceProvider = new ServiceCollection()
            .AddLogging(options =>
            {
                options.AddJsonConsole(options =>
                {
                    options.IncludeScopes = true;
                    options.JsonWriterOptions = new JsonWriterOptions { Indented = true };
                });
            })
            .BuildServiceProvider();

        var logger = serviceProvider.GetRequiredService<ILogger<Program>>();

        using (logger.BeginScope(new Dictionary<string, object> { ["Id"] = "Value" }))
        {
            logger.LogInformation("Test");
        }
    }
}

Expected behavior

It would be nice to have the following output:

{
  "EventId": 0,
  "LogLevel": "Information",
  "Category": "Program",
  "Message": "Test",
  "State": {
    "Message": "Test",
    "{OriginalFormat}": "Test"
  },
  "Scopes": [
    {
      "Message": "System.Collections.Generic.Dictionary\u00602[System.String,System.Object]",
      "Id": "Value"
    }
  ]
}

Actual behavior

Currently, it prints the following result:

{
  "EventId": 0,
  "LogLevel": "Information",
  "Category": "Program",
  "Message": "Test",
  "State": {
    "Message": "Test",
    "{OriginalFormat}": "Test"
  },
  "Scopes": [
    {
      "Id": "Value"
    }
  ]
}

Regression?

No

Known Workarounds

No response

Configuration

No response

Other information

No response

Author:	bartlomiejgawel
Assignees:	-
Labels:	untriaged, area-Extensions-Logging
Milestone:	-

[centur]

What is worse, this behaviour produces invalid JSON in output.
According to RFC8259

The names within an object SHOULD be unique.

And it's very easy to trigger if Scope dictionary is built on some filtered external values - like HTTP request headers or keys from other log systems (which often may use "Message" as a json key).

If Scope's Dictionary would contain key "Message" like this:

using (logger.BeginScope(new Dictionary<string, object> { ["Message"] = "SomeText",  ["Id"] = "Value"}))
{
  logger.LogInformation("Test");
}

Actual output in such case will have 2 keys with non-unique names:

...
"Scopes":[
 {
  "Message":"System.Collections.Generic.Dictionary\u00602[System.String,System.Object]",
  "Message":"SomeText",
  "Id":"Value"
}]
...

Looks like a bug, not just some extra details written in output.

[hmcguirk]

Is there any update on this? Is this not a bug? Is there any workaround?