Change the default ConsoleFormatter to Json when running in a container

[shirhatti]

Currently, the console logger in CreateDefaultBuilder() defaults to a multiline human-readable output. This doesn’t work well in container environments where folks use tools like fluentd or Azure Monitor to collect those logs.

https://github.com/dotnet/runtime/blob/8a52f1e948b6f22f418817ec1068f07b8dae2aa5/src/libraries/Microsoft.Extensions.Hosting/src/Host.cs#L108

Some limitations of the current formatter:

1. Individual log are split across multiple log entries
2. Structure is no longer preserved
3. Stack traces are torn across multiple lines
4. Logs have color codes embedded in them

What I would like to do is to switch the default ConsoleLoggerFormatter to output structured JSON logs instead of our current format when running in a container.

Old 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

New output:

{"EventId":37,"LogLevel":"Warning","Category":"Microsoft.AspNetCore.Server.HttpSys.MessagePump","Message":"Overriding address(es) \u0027\u0027. Binding to endpoints added to UrlPrefixes instead.","State":{"Message":"Overriding address(es) \u0027\u0027. Binding to endpoints added to UrlPrefixes instead.","{OriginalFormat}":"Overriding address(es) \u0027\u0027. Binding to endpoints added to UrlPrefixes instead."}}
{"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}"}}

Proposal

Use the DOTNET_RUNNING_IN_CONTAINER environment variable to control which ConsoleFormatter we default to.

DOTNET_RUNNING_IN_CONTAINER	ConsoleFormatter
True	JsonConsoleFormatter
False	SimpleConsoleFormatter

Questions

Should we make this change to all images or just aspnet? Just aspnet is very hard because we have to decide whether to adopt the aspnet or not aspnet behavior for the SDK. Maybe this is easier than I think, but I can imagine SDK scenarios where people use aspnet. Maybe that is easy to scope out.

Unless folks opt-in to using ILogger there’s no way to make this change to all images. We can do this for all hosted (ASP.NET/worker) app models.

If you chose to Console.WriteLine directly, there’s not much we can (or should) do.

Would this behavior be better as opt-in?

Possibly? That’s why I was hoping to solicit feedback before making the change.

Why is this behavior important for ASP.NET Core in containers and not elsewhere?
I am surprised we are limiting the change to only containers when I'd expect this problem is similarly impactful for non-container scenarios.

Looking at the common deployment targets for hosted app models:

• Deploy on Windows with IIS
  • There is no Console attached and console format isn’t applicable
• Deploy on Windows as a Windows Service
  • There is no Console attached and console format isn’t applicable
• Deploy on Linux as a systemd service
  • Use the systemd console formatter
• Deploy on Linux as a container
  • Use the json formatter

Of the top four most common deployment targets, it seems like Linux containers are the only scenario where defaulting to json makes sense.
However, given that the change is mostly inconsequential on Windows, I could be convinced that this change needs to made more broadly.

What do you think of the scenario w/rt SDK containers? Do you think users will want to use the json formatter in that container?

There’s no impact here to other processes in a container. The change we’re discussing only impacts the output of hosted applications. If you do happen to build and run in an SDK container, then yes I expect the console logging from your hosted application to be JSON formatted.

Does this change the behavior during development?

Yes, I propose we gate this change solely on running in a container. The hosting environment (IWebHostEnvironment) has no impact.

👀 @maryamariyan @richlander @davidfowl @noahfalk

Tagging subscribers to this area: @maryamariyan
See info in area-owners.md if you want to be subscribed.

Issue Details

---

Currently, the console logger in CreateDefaultBuilder() defaults to a multiline human-readable output. This doesn’t work well in container environments where folks use tools like fluentd or Azure Monitor to collect those logs.

https://github.com/dotnet/runtime/blob/8a52f1e948b6f22f418817ec1068f07b8dae2aa5/src/libraries/Microsoft.Extensions.Hosting/src/Host.cs#L108

Some limitations of the current formatter:

1. Individual log are split across multiple log entries
2. Structure is no longer preserved
3. Stack traces are torn across multiple lines
4. Logs have color codes embedded in them

What I would like to do is to switch the default ConsoleLoggerFormatter to output structured JSON logs instead of our current format when running in a container.

Proposal

Use the DOTNET_RUNNING_IN_CONTAINER environment variable to control which ConsoleFormatter we default to.

DOTNET_RUNNING_IN_CONTAINER	ConsoleFormatter
True	JsonConsoleFormatter
False	SimpleConsoleFormatter

Questions

Should we make this change to all images or just aspnet? Just aspnet is very hard because we have to decide whether to adopt the aspnet or not aspnet behavior for the SDK. Maybe this is easier than I think, but I can imagine SDK scenarios where people use aspnet. Maybe that is easy to scope out.

Unless folks opt-in to using ILogger there’s no way to make this change to all images. We can do this for all hosted (ASP.NET/worker) app models.

If you chose to Console.WriteLine directly, there’s not much we can (or should) do.

Would this behavior be better as opt-in?

Possibly? That’s why I was hoping to solicit feedback before making the change.

Why is this behavior important for ASP.NET Core in containers and not elsewhere?
I am surprised we are limiting the change to only containers when I'd expect this problem is similarly impactful for non-container scenarios.

Looking at the common deployment targets for hosted app models:

• Deploy on Windows with IIS
  • There is no Console attached and console format isn’t applicable
• Deploy on Windows as a Windows Service
  • There is no Console attached and console format isn’t applicable
• Deploy on Linux as a systemd service
  • Use the systemd console formatter
• Deploy on Linux as a container
  • Use the json formatter

Of the top four most common deployment targets, it seems like Linux containers are the only scenario where defaulting to json makes sense.
However, given that the change is mostly inconsequential on Windows, I could be convinced that this change needs to made more broadly.

What do you think of the scenario w/rt SDK containers? Do you think users will want to use the json formatter in that container?

There’s no impact here to other processes in a container. The change we’re discussing only impacts the output of hosted applications. If you do happen to build and run in an SDK container, then yes I expect the console logging from your hosted application to be JSON formatted.

👀 @maryamariyan @richlander @davidfowl @noahfalk

Author:	shirhatti
Assignees:	-
Labels:	area-Extensions-Logging
Milestone:	-

[ericstj]

This doesn’t work well in container environments where folks use tools like fluentd or Azure Monitor to collect those logs.

Is this the only case where folks want a different default logger? Seems like correlation rather than causation. Would it make more sense to do this whenever the console is redirected?

Use the DOTNET_RUNNING_IN_CONTAINER environment variable to control which ConsoleFormatter we default to.

If they can set an environment variable, why not just set the logger this way? Goes back to the correlation question.

[shirhatti]

Would it make more sense to do this whenever the console is redirected?

It may not be possible to tell. If I'm writing to stdout in Docker, there's no way to tell what logging driver is used and whether it's being redirected. Console.IsOutputRedirected doesn't work in this case.

If they can set an environment variable, why not just set the logger this way?

This environment variable is already baked into all container images we (dotnet) produce. See- https://github.com/dotnet/dotnet-docker/blob/master/src/runtime-deps/3.1/alpine3.12/amd64/Dockerfile#L18

My less preferred option is to detect whether we're in a container using something like what we have below:

public static bool IsInDockerContainer
{
    get
    {
        if (RuntimeInformation.IsOSPlatform(OSPlatform.Linux))
        {
            // Check if one of the control groups of this process is owned by docker
            if (File.ReadAllText("/proc/self/cgroup").Contains("/docker/"))
            {
                return true;
            }

            // Most of the control groups are owned by "kubepods" when running in kubernetes;
            // Check for docker environment file
            return File.Exists("/.dockerenv");
        }

        // TODO: Add detection for other platforms
        return false;
    }
}

[shirhatti]

@maryamariyan I would rather we do this in an earlier preview since this is a breaking behavior change

[shirhatti]

As a third option, we could invent a new variable for this. There is some prior art for using a new variable- https://github.com/dotnet/runtime/blob/79ae74f5ca5c8a6fe3a48935e85bd7374959c570/src/libraries/Microsoft.Extensions.FileProviders.Physical/src/PhysicalFileProvider.cs#L24

[shirhatti]

For sake of completeness, I should also mention that aspnetcore already uses the existing DOTNET_RUNNING_IN_CONTAINER variable- https://github.com/dotnet/aspnetcore/blob/c925f99cddac0df90ed0bc4a07ecda6b054a0b02/src/DataProtection/DataProtection/src/Internal/ContainerUtils.cs#L15

[ericstj]

we could invent a new variable for this.

That's what I was getting at with

If they can set an environment variable, why not just set the logger this way

I'm fine either way, but trying to think about whether all customers who set DOTNET_RUNNING_IN_CONTAINER want the new behavior. If someone who's already setting DOTNET_RUNNING_IN_CONTAINER decides they don't want the new behavior, what should they do?

Are there any other customers who want this behavior but don't want to set DOTNET_RUNNING_IN_CONTAINER?

[shirhatti]

If someone who's already setting DOTNET_RUNNING_IN_CONTAINER decides they don't want the new behavior, what should they do?

Be more explicit in their code about which logger formatter they want to use.

Are there any other customers who want this behavior but don't want to set DOTNET_RUNNING_IN_CONTAINER?

Possibly. I tried to answer that with the FAQ in my issue, but I'll repost it here 😄

Looking at the common deployment targets for hosted app models:

• Deploy on Windows with IIS
  • There is no Console attached and console format isn’t applicable
• Deploy on Windows as a Windows Service
  • There is no Console attached and console format isn’t applicable
• Deploy on Linux as a systemd service
  • Use the systemd console formatter
• Deploy on Linux as a container
  • Use the json formatter

Of the top four most common deployment targets, it seems like Linux containers are the only scenario where defaulting to json makes sense.
However, given that the change is mostly inconsequential on Windows, I could be convinced that this change needs to made more broadly.

[maryamariyan]

we could invent a new variable for this.

Seems like there is agreement on taking this approach

[maryamariyan]

So the fix plan for this issue here is to have dotnet docker images take environment variable Logging__Console__FormatterName="Json" which will ensure console logs to have Json format by default.

@shirhatti @MichaelSimons

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.