Revert the Console Formatter Default

[ldillonel]

In .NET 6 we made the decision to default the console logger in CreateDefaultBuilder() to structured JSON logs; to support container environments where folks use tools like fluentd or Azure Monitor to collect those logs. However, this resulted in non-human readable output that does not work well when viewing this output to analyze logs. Please see this issue for more details. We have made the decision to revert the default behavior back to multiline human-readable output.

.NET 6 default Logging__Console__FormatterName="Json" output:

{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Now listening on: http://localhost:7000/","State":{"Message":"Now listening on: http://localhost:7000/","address":"http://localhost:7000/","{OriginalFormat}":"Now listening on: {address}"}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Now listening on: http://localhost:7001/","State":{"Message":"Now listening on: http://localhost:7001/","address":"http://localhost:7001/","{OriginalFormat}":"Now listening on: {address}"}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Now listening on: http://localhost:7002/","State":{"Message":"Now listening on: http://localhost:7002/","address":"http://localhost:7002/","{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: Development","State":{"Message":"Hosting environment: Development","envName":"Development","{OriginalFormat}":"Hosting environment: {envName}"}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Content root path: C:\\Users\\shirh\\source\\temp\\web50","State":{"Message":"Content root path: C:\\Users\\shirh\\source\\temp\\web50","contentRoot":"C:\\Users\\shirh\\source\\temp\\web50","{OriginalFormat}":"Content root path: {contentRoot}"}}

Patch Update

In the May 2022 servicing update for .NET 6, we will change the Logging__Console__FormatterName environment variable to be unset for the ASP.NET Core container images. This will cause it to revert back to the original simple output.

Example output:

warn: Microsoft.AspNetCore.Server.HttpSys.MessagePump[37]
      Overriding address(es) ''. Binding to endpoints added to UrlPrefixes instead.
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:7000/
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:7001/
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:7002/
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\Users\shirh\source\temp\web50

Breaking Change

Question: What do I do if this change breaks my system that relies on JSON formatting?

If you are currently using or want to use JSON, you will need to opt into this behavior since it will no longer be on by default. To do this please set the Logging__Console__FormatterName environment variable to Json.

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[LadyNaggaga]

Suggested changes to the intro

In .NET 6 we made the decision to default, the console logger in CreateDefaultBuilder() to structured JSON logs; to support container environments where folks use tools like fluentd or Azure Monitor to collect those logs. However, this resulted in non-human readable output does not work well when viewing this output to analyze logs. Please see this issue for more details. We have made the decision to revert the default behavior back to multiline human-readable output.

.NET 6 default Logging__Console__FormatterName="Json" output:

{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Now listening on: http://localhost:7000/","State":{"Message":"Now listening on: http://localhost:7000/","address":"http://localhost:7000/","{OriginalFormat}":"Now listening on: {address}"}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Now listening on: http://localhost:7001/","State":{"Message":"Now listening on: http://localhost:7001/","address":"http://localhost:7001/","{OriginalFormat}":"Now listening on: {address}"}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Now listening on: http://localhost:7002/","State":{"Message":"Now listening on: http://localhost:7002/","address":"http://localhost:7002/","{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: Development","State":{"Message":"Hosting environment: Development","envName":"Development","{OriginalFormat}":"Hosting environment: {envName}"}}
{"EventId":0,"LogLevel":"Information","Category":"Microsoft.Hosting.Lifetime","Message":"Content root path: C:\\Users\\shirh\\source\\temp\\web50","State":{"Message":"Content root path: C:\\Users\\shirh\\source\\temp\\web50","contentRoot":"C:\\Users\\shirh\\source\\temp\\web50","{OriginalFormat}":"Content root path: {contentRoot}"}}

Patch update

.NET 6 Patch update reverted back to Logging__Console__FormatterName="" output

warn: Microsoft.AspNetCore.Server.HttpSys.MessagePump[37]
     Overriding address(es) ''. Binding to endpoints added to UrlPrefixes instead.
info: Microsoft.Hosting.Lifetime[0]
     Now listening on: http://localhost:7000/
info: Microsoft.Hosting.Lifetime[0]
     Now listening on: http://localhost:7001/
info: Microsoft.Hosting.Lifetime[0]
     Now listening on: http://localhost:7002/
info: Microsoft.Hosting.Lifetime[0]
     Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
     Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
     Content root path: C:\Users\shirh\source\temp\web50

[mthalman]

@mthalman and @ldillonel what are the specific break changes we need to call out to the customer?

If they use automated tools to collect the container logs and are expecting the default behavior of those logs being formatted as JSON, this change will break them. They will need to explicitly set Logging__Console__FormatterName to Json.

[LadyNaggaga]

Thank you @mthalman. Looks like @ldillonel made some updates based on the feedback above are we okay to ship this announcement?
cc - @davidfowl

[mthalman]

My only remaining feedback is on the last section, Setting ConsoleFormatter to JSON. That's framed around the solution. I think it instead needs to be framed around the problem, (i.e. the breaking change). There needs to be text which calls out that this is breaking and letting the customer know what to do when they've been broken. Here's a suggestion:

Breaking Change

Question: What do I do if this change breaks my system that relies on JSON formatting?

If you are currently using or want to use JSON, you will need to opt into this behavior since it will no longer be on by default. To do this please set the Logging__Console__FormatterName environment variable to Json.

[mthalman]

I've updated the Patch Update section to include timeframe of the change. The intention is to announce this ahead of time, at least in this repo, so people can know it's coming ahead of time. That's why we need to indicate a timeframe.

[mthalman]

Review is completed. Closing.