Breaking Change: Default console logger format set to JSON

[mthalman]

Breaking Change: Default console logger format set to JSON

In the .NET 6 aspnet image type, the default console logger format has been changed to a JSON formatter. The default in .NET 5 was set to the simple console formatter. This change was made in order to have a default configuration that works with automated tools that rely on a machine-readable format like JSON.

Details

This change only impacts the aspnet image type. The runtime and sdk image types are unaffected and remain configured with the simple console formatter.

Any code which logs to the console will have its output affected by this change. As an example, the following output illustrates the differences in the default output when starting an ASP.NET Core container:

.NET 5 Output (simple format)

warn: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[60]
      Storing keys in a directory '/root/.aspnet/DataProtection-Keys' that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed.
warn: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[35]
      No XML encryptor configured. Key {94519747-9185-49e1-b5af-352c1a5078da} may be persisted to storage in unencrypted form.
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: http://[::]:80
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: /app

.NET 6 Output (JSON format)

{"EventId":60,"LogLevel":"Warning","Category":"Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository","Message":"Storing keys in a directory \u0027/root/.aspnet/DataProtection-Keys\u0027 that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed.","State":{"Message":"Storing keys in a directory \u0027/root/.aspnet/DataProtection-Keys\u0027 that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed.","path":"/root/.aspnet/DataProtection-Keys","{OriginalFormat}":"Storing keys in a directory \u0027{path}\u0027 that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed."}}
{"EventId":35,"LogLevel":"Warning","Category":"Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager","Message":"No XML encryptor configured. Key {86cafacf-ab57-434a-b09c-66a929ae4fd7} may be persisted to storage in unencrypted form.","State":{"Message":"No XML encryptor configured. Key {86cafacf-ab57-434a-b09c-66a929ae4fd7} may be persisted to storage in unencrypted form.","KeyId":"86cafacf-ab57-434a-b09c-66a929ae4fd7","{OriginalFormat}":"No XML encryptor configured. Key {KeyId:B} may be persisted to storage in unencrypted form."}}
{"EventId":14,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Now listening on: http://[::]:80","State":{"Message":"Now listening on: http://[::]:80","address":"http://[::]:80","{OriginalFormat}":"Now listening on: {address}"}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Application started. Press Ctrl\u002BC to shut down.","State":{"Message":"Application started. Press Ctrl\u002BC to shut down.","{OriginalFormat}":"Application started. Press Ctrl\u002BC to shut down."}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Hosting environment: Production","State":{"Message":"Hosting environment: Production","envName":"Production","{OriginalFormat}":"Hosting environment: {envName}"}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Content root path: /app","State":{"Message":"Content root path: /app","contentRoot":"/app","{OriginalFormat}":"Content root path: {contentRoot}"}}

Overriding the Default Configuration

The logger format type can be changed by setting or unsetting the Logging__Console__FormatterName environment variable or via code change (see Console log formatting for more details).

Example:

$ docker run --rm -it -p 8000:80 -e Logging__Console__FormatterName="" mcr.microsoft.com/dotnet/samples:aspnetapp
warn: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[60]
      Storing keys in a directory '/root/.aspnet/DataProtection-Keys' that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed.
warn: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[35]
      No XML encryptor configured. Key {8d4ddd1d-ccfc-4898-9fe1-3e7403bf23a0} may be persisted to storage in unencrypted form.
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: http://[::]:80
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: /app

Related Issue

#2725

[ralftar]

Is it by design or that configuring FormatterName to simple in appsettings.json is not applied when running inside a docker container? As opposite to native Windows where the simple formatting is applied and overrides the default JSON format. (edit: simple is ofc. the default in windows.. but the precedence question still stands).

[mthalman]

Is it by design or that configuring FormattingName to simple in appsettings.json is not applied when running inside a docker container? As opposite to native Windows where the simple formatting is applied and overrides the default JSON format.

@shirhatti - What takes precedence here? The appsettings.json configuration or the setting of the Logging__Console__FormatterName environment variable?

[kodedylf]

As I understand it, the environment variable takes precedence, so by setting the environment variable in the aspnet Docker images, it's no longer possible to configure console logging via appsettings.json.

[ralftar]

I have a hunch that FormatterName inside appsettings.json won't take effect even if the Logging__Console__FormatterName environment variable is not set.

(I ended up setting the environment variable inside the Dockerfile)

[davidfowl]

cc @shirhatti

[wuhkuh]

@ralftar That's because FormattingName contains a typo 😉
The environment variable Logging__Console__FormatterName with value simple is the equivalent of

{
  "Logging": {
    "Console": {
      "FormatterName": "simple"
    }
  }
}

We've unset Logging__Console__FormatterName in our dockerfile (based on the aspnet image) like so:

ENV Logging__Console__FormatterName=

And now everything works as expected.

[ralftar]

That's because FormattingName contains a typo

Thanks for pointing this out @wuhkuh, but a comment typo was also all that it was.

The original question still stands: If Logging__Console__FormatterName evt variable is not set then FormatterName inside appsettings.json won't take effect, is this by intention?

Same applies to @wuhkuh's example above: Setting FormatterName to json in appsettings.json won't take effect, even when Logging__Console__FormatterName is "unset". Thus appsettings's FormatterName will also here not be applied as expected.

Regarding setting Logging__Console__FormatterName to blank: I suspects it's really not an "unset", but rather sets to simple formatter when `Logging__Console__FormatterName is blank...?

[wuhkuh]

Same applies to @wuhkuh's example above: Setting FormatterName to json in appsettings.json won't take effect, even when Logging__Console__FormatterName is "unset". Thus appsettings's FormatterName will also here not be applied as expected.

Regarding setting Logging__Console__FormatterName to blank: I suspects it's really not an "unset", but rather sets to simple formatter when `Logging__Console__FormatterName is blank...?

Ah, good catch, you're spot on: it uses the simple formatter because the environment variable now contains an empty string.

To work around this, you can supply an entrypoint script, calling unset Logging__Console__FormatterName before invoking your application.
Docker does not support removing environment variables from a previous layer; it would require removal of that layer 😞

[ralftar]

Since we are diving into this 🐰🕳️ another observation for the record:

Setting Logging__Console__FormatterName to blank is not the same as setting it to simple. When set to blank there are no level colors in the console, and more importantly: FormatterOptions with TimestampFormat inside appsettings.json for the console is not applied.

[MaxRev-Dev]

Love this. I'm not using azure containers, rather bare metal droplets. After updating from .net5.0 to .net6.0, I figured out that the logger somehow changed it's configuration. So I've opened the docs and did not found any note or warning about this breaking change in there. Only 5 minutes of "googling" revealed me this issue.
https://docs.microsoft.com/en-us/dotnet/core/extensions/console-log-formatter

[dlaudams]

This change has been reverted to the previous simple console logger behaviour with this second breaking change: #3706