Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ConsoleLogger output is garbled with color codes when redirected #37421

Closed
tmds opened this issue Jun 4, 2020 · 20 comments · Fixed by #40221
Closed

ConsoleLogger output is garbled with color codes when redirected #37421

tmds opened this issue Jun 4, 2020 · 20 comments · Fixed by #40221
Labels
api-approved API was approved in API review, it can be implemented area-Extensions-Logging breaking-change Issue or PR that represents a breaking API or functional change over a prerelease. enhancement Product code improvement that does NOT require public API changes/additions
Milestone

Comments

@tmds
Copy link
Member

tmds commented Jun 4, 2020

On Kubernetes, logs from ASP.NET Core apps are garbled with color codes:

�[40m�[1m�[33mwarn�[39m�[22m�[49m: Microsoft.AspNetCore.DataProtection.Repositories.FileSystemXmlRepository[60]
      Storing keys in a directory '/opt/app-root/.aspnet/DataProtection-Keys' that may not be persisted outside of the container. Protected data will be unavailable when container is destroyed.
�[40m�[1m�[33mwarn�[39m�[22m�[49m: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[35]
      No XML encryptor configured. Key {2c2776a6-be46-4719-9275-b7baed6ebc3f} may be persisted to storage in unencrypted form.
�[40m�[32minfo�[39m�[22m�[49m: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://[::]:8080
�[40m�[32minfo�[39m�[22m�[49m: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
�[40m�[32minfo�[39m�[22m�[49m: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
�[40m�[32minfo�[39m�[22m�[49m: Microsoft.Hosting.Lifetime[0]
      Content root path: /opt/app-root/app

.NET System.Console will not output colors when it is not connected to a terminal. This is the case on Kubernetes, where Console.IsOutputRedirected returns true.

ConsoleLogger doesn't consider IsOutputRedirected and outputs colors regardless.

Behaving like Console would produce cleaner logs when running ASP.NET Core applications on Kubernetes (and other redirected environments).

I read through dotnet/extensions#673. There is a ConsoleLogger.DisableColors. I'm not sure why it does not default to true when Console.IsOutputRedirected is true?

cc @rynowak @glennc

@Dotnet-GitSync-Bot Dotnet-GitSync-Bot added area-System.Console untriaged New issue has not been triaged by the area owner labels Jun 4, 2020
@ghost
Copy link

ghost commented Jun 4, 2020

Tagging subscribers to this area: @eiriktsarpalis
Notify danmosemsft if you want to be subscribed.

@stephentoub
Copy link
Member

(FYI, there's a semi-related discussion at #33980, which I still need to follow-up on.)

@tmds
Copy link
Member Author

tmds commented Jun 17, 2020

@rynowak @glennc any thoughts on this? Probably you have noticed these escape sequences also?

@adamsitnik
Copy link
Member

I've changed the are from System.Console to Extensions-Logging. If there is a bug somewhere in System.Console that blocks this issue please let me know what exactly needs to be fixed or how to reproduce the problem.

@maryamariyan maryamariyan added this to the 5.0.0 milestone Jul 9, 2020
@maryamariyan maryamariyan removed the untriaged New issue has not been triaged by the area owner label Jul 9, 2020
@ericstj ericstj added the breaking-change Issue or PR that represents a breaking API or functional change over a prerelease. label Jul 9, 2020
@maryamariyan
Copy link
Member

/cc: @shirhatti

@ericstj ericstj added the enhancement Product code improvement that does NOT require public API changes/additions label Jul 9, 2020
@maryamariyan
Copy link
Member

This would not occur on a windows OS machine currently but with the new changes coming in for #34742 we would basically embed ANSI codes even on windows machines for the Default consoles which uses DisableColors.

@tmds
Copy link
Member Author

tmds commented Jul 14, 2020

@maryamariyan can you look into this issue as part of the ConsoleLogger changes you are making for .NET 5?

@maryamariyan
Copy link
Member

maryamariyan commented Jul 14, 2020

For sure. The PR would also fix this.


UPDATE: #38616 (comment)

@ericstj
Copy link
Member

ericstj commented Jul 23, 2020

Is this fixed now that ConsoleLogger changes are in?

@maryamariyan
Copy link
Member

maryamariyan commented Jul 29, 2020

@tmds @ericstj

@eerhardt recommended earlier in my linked PR that we could choose to strip out the color codes (by using AnsiParsingLogConsole) when the output is redirected and could be solution for fixing the current issue.

But I have postponed this fix for now because of the following two talking points:

cc: @tarekgh

@maryamariyan maryamariyan modified the milestones: 5.0.0, 6.0.0 Jul 29, 2020
@omajid
Copy link
Member

omajid commented Jul 29, 2020

Is it correct to assume that no redirected output supports colors?

It's very much possible for the software "reading" the redirected output to parse and display colours.

A related conversation thread is happening in #33980 which is aimed for 6.0 it might be worth waiting to see what APIs would get added to System.Console first before working on the current issue.

Please consider this:

  • In the current behaviour, there's two possibilities: you get colours, or you get garbage output
  • In the proposed behaviour: you get no colours, but never any garbage in the output either

To me, it seems like the safer option is to remove colours for now. Producing colours is a nice to have, but producing garbage makes us look bad.

When we have a better mechanism to detect and enable colours, we should do that.

@maryamariyan maryamariyan modified the milestones: 6.0.0, 5.0.0 Jul 29, 2020
@eerhardt
Copy link
Member

Would a reasonable fix here be:

  1. Update SimpleConsoleFormatterOptions.DisableColors to be public bool? DisableColors. The default is null.
  2. When DisableColors == null, its behavior gets defaulted to Console.IsOutputRedirected. So if no one sets DisableColors explicitly, and output is redirected, we don't get any colors. If output isn't redirected, we get the current behavior.
  3. When someone doesn't like this behavior, they can explicitly set DisableColors=true|false and they will get that behavior. So even if output is redirected, they can still get color if they care about it.

We can make an API change here because we just introduced this API in 5.0, so we still have time to change it.

Thoughts?

@ericstj
Copy link
Member

ericstj commented Jul 29, 2020

Nullable bool named with a negative is a little confusing for an API. Maybe an enum would be clearer (or at least another option to consider). enum LoggerColorBehavior { DisabledWhenRedirected, Disabled, Enabled }

@eerhardt
Copy link
Member

As long as we can set enums through configuration that would be fine with me.

DisabledWhenRedirected

How about just Default? We may want to add more policy to this in the future beyond just "redirected".

@maryamariyan
Copy link
Member

maryamariyan commented Jul 29, 2020

How about just Default? We may want to add more policy to this in the future beyond just "redirected".

I think I remember in an API review there was a guideline to avoid using Default for enums. First bulletpoint in #34305 (comment), or maybe I misunderstood. I think that was another reason we switched from using Default formatter to simple too.

As long as we can set enums through configuration that would be fine with me.

enums should also be possible to be set in configuration. ConsoleLoggerFormat enum (now deprecated) could be set in configuration before.

@maryamariyan
Copy link
Member

maryamariyan commented Jul 29, 2020

namespace Microsoft.Extensions.Logging.Console
{
+    /// <summary>
+    /// Flags to help determine whether or not logs should contain color.
+    /// </summary>
+    public enum LoggerColorBehavior
+    {
+        /// <summary>
+        /// Disabled when output is redirected
+        /// </summary>
+        Default = 0,
+
+        /// <summary>
+        /// Enable color for logging
+        /// </summary>
+        Enabled = 1,
+
+        /// <summary>
+        /// Disable color for logging.
+        /// </summary>
+        Disabled = 2,
+    }

    /// <summary>
    /// Options for the built-in default console log formatter.
    /// </summary>
    public class SimpleConsoleFormatterOptions : ConsoleFormatterOptions
    {
        public SimpleConsoleFormatterOptions() { }

-        /// <summary>
-        /// Disables colors when <see langword="true" />.
+        /// Determines whether or not to provide color for console logs />.
-        /// </summary>
-        public bool DisableColors { get; set; }
+        public LoggerColorBehavior ColorBehavior { get; set; }

        /// <summary>
        /// When <see langword="false" />, the entire message gets logged in a single line.
        /// </summary>
        public bool SingleLine { get; set; }
    }
}

Motivation:

As showcased in the description of this issue, the existing mechanism we have in place does not allow to properly decide what to do for embedding colors when output is getting redirected elsewhere. In cases where the redirected output does not support ANSI color codes, the output gets polluted with unwanted string produced by the logger.

Usage:

With:

    using var loggerFactory = LoggerFactory.Create(builder =>
    {
         builder.AddSimpleConsole(o => o.ColorBehavior = LoggerColorBehavior.Default);
    });
    var logger = loggerFactory.CreateLogger<Program>();

Then in the console formatter checks for Console.IsOutputRedirected and when true, acts as if color is disabled and would not embed color.

Instead, LoggerColorBehavior.Enabled/LoggerColorBehavior.Disabled translate into colors being enabled/disabled respectively.

@eerhardt
Copy link
Member

  1. I don't believe this should be a Flags enum. What does Enabled | Disabled mean?
  2. DisabledWhenOutputRedirected needs to be the default value.
  3. I don't like the name DisabledWhenOutputRedirected because it locks us in to a default behavior that I think we will want to change over time. For example, we may want to respect some environment variable by default as well. (i.e. NO_COLOR as discussed in Implement a way to enable color in console even when the output is redirected #33980)

@maryamariyan
Copy link
Member

maryamariyan commented Jul 29, 2020

@eerhardt updated. Changed DisabledWhenOutputRedirected to Default. I was also thinking perhaps Default could change to something along the lines of Varied, Variable, Conditioned or Conditional, etc. Keeping as Default for now.

@maryamariyan maryamariyan added api-ready-for-review API is ready for review, it is NOT ready for implementation blocking Marks issues that we want to fast track in order to unblock other important work labels Jul 29, 2020
@maryamariyan
Copy link
Member

cc: @davidfowl

@terrajobst terrajobst added api-approved API was approved in API review, it can be implemented and removed api-ready-for-review API is ready for review, it is NOT ready for implementation blocking Marks issues that we want to fast track in order to unblock other important work labels Jul 31, 2020
@terrajobst
Copy link
Member

terrajobst commented Jul 31, 2020

Video

  • Looks good as proposed
  • We considered exposing a setting on System.Console instead but we want a setting that can be configured via the configuration system of Microsoft.Extensions.
 namespace Microsoft.Extensions.Logging.Console
 {
+    public enum LoggerColorBehavior
+    {
+        Default = 0,
+        Enabled = 1,
+        Disabled = 2,
+    }
     public class SimpleConsoleFormatterOptions : ConsoleFormatterOptions
     {
         public SimpleConsoleFormatterOptions();
-        public bool DisableColors { get; set; }
+        public LoggerColorBehavior ColorBehavior { get; set; }
         public bool SingleLine { get; set; }
     }
 }

@maryamariyan maryamariyan moved this from C5.0 to In progress in ML, Extensions, Globalization, etc, POD. Aug 1, 2020
@maryamariyan maryamariyan moved this from In progress to Done in ML, Extensions, Globalization, etc, POD. Aug 5, 2020
@dotnet dotnet locked as resolved and limited conversation to collaborators Dec 8, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
api-approved API was approved in API review, it can be implemented area-Extensions-Logging breaking-change Issue or PR that represents a breaking API or functional change over a prerelease. enhancement Product code improvement that does NOT require public API changes/additions
Projects
None yet
Development

Successfully merging a pull request may close this issue.

9 participants