Quarkus: Windows - console (cmd/powershell) polluted with escape characters for color output

[rsvoboda]

Windows - console (cmd/powershell) polluted with escape characters for color output

I don't think cmd supports colors. Cmd supports colors too, e.g. maven output is colored
PowerShell supports colors, but probably needs its own way.

Workaround on Windows could be to use consoles with color support - e.g. https://cmder.net/

Example:

java -jar .\target\demo-1.0-SNAPSHOT-runner.jar
2019-02-23 09:43:45,028 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [i.s.f.HystrixInitializer] (main) ### Init Hystrix ###
2019-02-23 09:43:45,060 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [i.s.f.DefaultHystrixConcurrencyStrategy] (main) ### Privilleged Thread Factory used ###
2019-02-23 09:43:45,060 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [i.s.f.HystrixInitializer] (main) Hystrix concurrency strategy used: DefaultHystrixConcurrencyStrategy
2019-02-23 09:43:45,107 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] WARN  [c.n.c.s.URLConfigurationSource] (main) No URLs will be polled as dynamic configuration sources.
2019-02-23 09:43:45,107 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [c.n.c.s.URLConfigurationSource] (main) To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.
2019-02-23 09:43:45,122 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [o.j.s.metrics] (main) Creating registries
2019-02-23 09:43:45,388 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [o.j.r.r.i18n] (main) RESTEASY002225: Deploying javax.ws.rs.core.Application: class com.example.demo.DemoRestApplication
2019-02-23 09:43:45,513 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [o.xnio] (main) XNIO version 3.6.5.Final
2019-02-23 09:43:45,544 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [o.x.nio] (main) XNIO NIO Implementation Version 3.6.5.Final
2019-02-23 09:43:45,639 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [o.j.threads] (main) JBoss Threads version 3.0.0.Alpha4
2019-02-23 09:43:45,701 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [o.j.shamrock] (main) Shamrock 1.0.0.Alpha1-SNAPSHOT started in 1.226s. Listening on: http://localhost:8080
2019-02-23 09:43:45,701 desktop-agm44t8 demo-1.0-SNAPSHOT-runner.jar[8068] INFO  [o.j.shamrock] (main) Installed features: [cdi, resteasy, smallrye-fault-tolerance, smallrye-health, smallrye-metrics]


[rsvoboda]

VS Code on Windows looks bad too.

[gsmet]

@rsvoboda we had a new report of this. Any chance you could take a look at how it's done in Maven? If they get it right, we can probably get it right too.

[rsvoboda]

I think this might be related to:

log output uses absolute RGB value and not plain ANSI colors, which could be adapted and configured by the terminal adapter

Info from https://github.com/quarkusio/quarkus/issues/1378#issuecomment-475193932

[rsvoboda]

https://stackoverflow.com/questions/2048509/how-to-echo-with-different-colors-in-the-windows-command-line

Windows before 10 - console doesn't support output coloring by default.

Starting from Windows 10 the Windows console support ANSI Escape Sequences.
The feature shipped with the Threshold 2 Update in Nov 2015.

Details on MSDN - https://docs.microsoft.com/en-us/windows/console/console-virtual-terminal-sequences

[kenduraghav]

Had the same issue in my terminal as well.

[swiss-chris]

I have the same problem using quarkus-maven-plugin on windows 10. Any solutions for this ?

[hantsy]

@swiss-chris

I had the same problem When I wrote my Helloworld Quarkus application with Apache Maven.

But it works well in Cygwin prompt.

[maxandersen]

for those looking for a quick fix you can add -D quarkus.log.console.color=false

./mvnw -D quarkus.log.console.color=false quarkus:dev

That at least works around the issue.

[gsmet]

Would someone having the issue be interested in having a look at how Maven does it and what we do wrong? That could be an interesting detective project :).

[rsvoboda]

MVN is using https://github.com/fusesource/jansi - Jansi is a small java library that allows you to use ANSI escape sequences to format your console output which works even on windows.

mvn -X clean
...
[DEBUG]   Imported: org.fusesource.jansi.* < plexus.core
...

Starting from Windows 10 the Windows console support ANSI Escape Sequences.

I think Quarkus coloring stuff done via specifying RGB, but that would be probably for @dmlloyd to confirm.

[rsvoboda]

https://issues.apache.org/jira/browse/MNG-3507 - ANSI color logging for improved output visibility

[maxandersen]

code for handling the coloring seem to come from https://github.com/dmlloyd/jboss-logmanager-embedded/blob/3d27632c40a9cb9c7c16f365d2e31d5390d67d68/src/main/java/org/jboss/logmanager/formatters/ColorPatternFormatter.java#L76

Which yes, seem to use RGB values rather than ansi.

A first fix is to have coloring be disabled when not running in a capable terminal.

[dmlloyd]

OK I feel like everybody is getting off course here :) I'll do a quick rundown of the facts.

Here is where we set up the logic for determining if we use color: https://github.com/quarkusio/quarkus/blob/master/core/runtime/src/main/java/io/quarkus/runtime/logging/LoggingSetupRecorder.java#L76-L99

Here is where we decide whether or not the ANSI terminal supports 24-bit RGB color: https://github.com/dmlloyd/jboss-logmanager-embedded/blob/3d27632c40a9cb9c7c16f365d2e31d5390d67d68/src/main/java/org/jboss/logmanager/formatters/ColorPatternFormatter.java#L59-L66

The Windows 10 terminal is in fact capable of ANSI color, including RGB (truecolor) sequences in most versions: https://devblogs.microsoft.com/commandline/24-bit-color-in-the-windows-console/

So the question is not about what the terminal can handle, period. Let's put that to rest!

Here's an excerpt from chat:

David Lloyd: in the logging recorder, it makes a determination about how to configure the console for color

David Lloyd: the test is pretty much what other unix programs do: if there is a console then it assumes you have a tty

David Lloyd: if the process is part of a pipeline then there is no tty, thus no console, thus no color

David Lloyd: unfortunately windows isn't unix :slight_smile:

David Lloyd: so the child process thinks it has a terminal window for some reason

David Lloyd: now iirc cmd.exe supports ansi sequences...

David Lloyd: so you might look at the problem in one of two possible ways

David Lloyd: 1. what is absorbing the ESC characters before cmd.exe can handle them?

David Lloyd: -or-

David Lloyd: 2. how can we detect whether our output is to a pipe on windows?

In other words, something is eating ESC characters and it's not the terminal. The process output in dev mode is going to Maven. On UNIXes this would happen via a pipe, but on Windows it happens via something else - something that is indistinguishable from a TTY from the perspective of Java and therefore Quarkus.

So the problem can be solved either in terms of 1 above or 2. But 2 will give the more correct result. The question is, how can we detect that our output is a pipe on Windows? Quick! To StackOverflow!

[maxandersen]

Won't colours completely disappear if we do 2 ? Thought finding what munges the output while in mvn sounded better to me. What am I missing ?

[dmlloyd]

Well, ultimately we'll want to do both, I think; however, in general if the output is going through a pipe, it's probably getting piped into something like a log analyzer or collector or viewer, which 9 times out of 10 won't handle the ANSI codes. So we definitely want to be detecting the pipe more correctly than we are, because we want those cases to work.

That said, if we want to support color logging in dev mode, then we need the Maven process to ask "do I have a console?" (for the same reason) and then pass that answer on to the child process (by way of a config property, one way or another). In other words, if Maven has color output then we can assume that dev mode can as well. And that leads to number 1, where we have to figure out what the heck is going on with the process output.

[dmlloyd]

I wrote this test program to run on Windows, which might be of use for experimentation:

import java.io.*;


public class Test {

public static void main(String[] args) throws Exception {
    if (args[0].equals("child")) {
        System.out.printf("Console is %s%n", System.console());
    } else if (args[0].equals("parent")) {
        Process p = new ProcessBuilder(java.util.Arrays.copyOfRange(args, 1, args.length))
            .start();
        try (InputStream is = p.getInputStream()) {
            try (InputStreamReader r = new InputStreamReader(is)) {
                try (BufferedReader br = new BufferedReader(r)) {
                    String s;
                    while ((s = br.readLine()) != null) {
                        System.out.print(s);
                        System.out.flush();
                    }
                }
            }
        }
        System.exit(p.waitFor());
        for (;;) Thread.sleep(10000L);
    }
}

}

You can run it by passing child as an argument, which will print the console object if there is one, or by passing parent, which will just execute the command given in the subsequent arguments and print the output (you might miss the last line if there is no EOL; I wrote this in Notepad!).

[maxandersen]

so, I wanted to check that normal console for quarkus works and afaics it does not.
Here is what I get running java -jar .\target\getting-started-1.0-SNAPSHOT-runner.jar:

java -jar .\target\getting-started-1.0-SNAPSHOT-runner.jar
2019-09-17 21:45:46,617 INFO  [io.quarkus] (main) Quarkus 0.22.0 started in 0.820s. Listening on: http://[::]:8080
2019-09-17 21:45:46,633 INFO  [io.quarkus] (main) Installed features: [cdi, resteasy]
java -jar .\target\getting-started-1.0-SNAPSHOT-runner.jar
2019-09-17 21:45:46,617 INFO  [io.quarkus] (main) Quarkus 0.22.0 started in 0.820s. Listening on: http://[::]:8080
2019-09-17 21:45:46,633 INFO  [io.quarkus] (main) Installed features: [cdi, resteasy]


so it does not seem like it is a devmode only issue.

[dmlloyd]

What version of Windows are you using? AFAIK we only support an updated Windows 10.

[maxandersen]

What version of Windows are you using? AFAIK we only support an updated Windows 10.

This is a windows 10 I installed within the last week.

[dmlloyd]

Looks like the situation is more complex than I thought:

• There might be a dependent package involved: https://devblogs.microsoft.com/commandline/24-bit-color-in-the-windows-console/#comment-3999
• There might be a registry key involved: https://github.com/ytdl-org/youtube-dl/issues/15758
• You might have to enable it via a win32 call: https://docs.microsoft.com/en-us/windows/console/setconsolemode#ENABLE_VIRTUAL_TERMINAL_PROCESSING

So the question is - how can we detect whether it's available, and/or force it on if color logging is enabled (from JVM mode obviously)?

[maxandersen]

1903 is the latest version and after updating latest version of fixes windows the same issue still occurs.

[maxandersen]

@dmlloyd I'll try those out and see if I can get it to fix it - but is there a way to avoid use of RGB but instead us "pure old" ANSI color codes as color formatter ? Then at least have that as a fallback ?

[dmlloyd]

The output you pasted is using "pure old" ANSI already.

[maxandersen]

Okey, so colors are NOT enabled by default. Setting that registry flag works.

for both plain quarkus and mvn.

[maxandersen]

The output you pasted is using "pure old" ANSI already.

hmm - so what vooodoo is maven doing since it works there ?

[rsvoboda]

cmd coloring is not enabled by default, registry hack needs to be performed or SetConsoleMode API must be used - use ENABLE_VIRTUAL_TERMINAL_PROCESSING (0x0400) flag. Jansi uses this option.
Details in https://stackoverflow.com/a/54291292 and https://docs.microsoft.com/en-us/windows/console/setconsolemode

I think Maven / Gradle go via Jansi, I found https://github.com/gradle/gradle/blob/master/subprojects/logging/src/main/java/org/gradle/internal/logging/sink/AnsiConsoleUtil.java#L75

[maxandersen]

A workaround available now to users are to set that key and enable it globally.

We can also go for trying to detect that setting, possibly using something from https://stackoverflow.com/questions/62289/read-write-to-windows-registry-using-java#6163701 to read the values.

[maxandersen]

I think Maven / Gradle go via Jansi, I found

If they use jansi to set that flag how come it is not affecting our output when run inside mvn ?

[rsvoboda]

I think we fork, but just guessing ... @stuartwdouglas ?

[maxandersen]

I think we fork, but just guessing ... @stuartwdouglas ?
hmm - I thought the streams were sent back through maven and printed there.

But yes, if we are truly forking it would not.

[maxandersen]

for those who hate regedit use this to enable it globally on windows:

 reg add HKEY_CURRENT_USER\Console /v VirtualTerminalLevel /t REG_DWORD /d 1

if you already have the key it will ask confirmation before overwriting.

[maxandersen]

found this code/change in jline https://github.com/jline/jline3/pull/280/files#diff-41eb681bf4c48dc67c42f75a806e12efR43

But this is still only done to enable more advanced coloring. Basic ANSI coloring as done by jansi and others should work pre-Windows 10...

[maxandersen]

In jansi they still have this open issue https://github.com/fusesource/jansi/issues/63 and so far I haven't found code in their repo that refer to setconsolemode.

I did find picocli talk about Windows 10 and jansi having a way to enable it:
https://github.com/remkop/picocli/wiki/Manual-(4.0-SNAPSHOT)#1152-windows

[maxandersen]

Also checked if by any chance windows environment variables are different but no - they are exactly equivalent.

could also run reg query HKEY_CURRENT_USER\Console /v VirtualTerminalLevel from java but I reckon that would add a bit too much overhead...

[dmlloyd]

JDK 11 does seem to have a jline impl hidden inside of it... with a JNA bridge to SetConsoleMode...

https://github.com/unofficial-openjdk/openjdk/blob/jdk/jdk/src/jdk.internal.le/windows/classes/jdk/internal/org/jline/terminal/impl/jna/win/Kernel32.java#L217-L222

[maxandersen]

hmm - so how does one go about calling that optionally under Java11 if no reflection allowed ?

[dmlloyd]

I guess you'd have to launch with a bunch of JDK options turned on. Not a great option...

[maxandersen]

This is now improved in #4076 so on windows default cmd.exe/powershell won't enable colors.
You can also now force control the use of color using -Dquarkus.log.console.color=<true|false>.

In #4095 we'll see if we can at least in native mode be better by activating windows 10 built-in support for ansi terminals