Tests fail under Cygwin/ConEmu due to ANSI in output

[dwalluck]

Some of these failures may be related to #581. Many tests fail string comparison under Windows (Cygwin) due to ANSI in output. I assume that the tests are meant to disable ANSI, but it's not working. I didn't quite find where this is in the code.

I can force ANSI off with

$ NO_COLOR=1 ./gradlew test

Then, only 5 tests fail.

These are due to trying to turn ANSI on and off. There are other tests that fail try to use stty. The /dev/tty device shouldn't be used under Cygwin, I think. It just responds stty: /dev/tty: No such device or address.

HelpAnsiTest. testAnsiAutoIfSystemPropertyPicocliAnsiCleared
HelpAnsiTest. testAnsiAutoIfSystemPropertyPicocliAnsiIsAuto
HelpAnsiTest. testAnsiEnabled

And

CommandLineTest. testDebugOutputForDoubleDashSeparatesPositionalParameters
CommandLineTest. testTracingDebugWithSubCommands

fail with

org.junit.ComparisonFailure: expected:<...NSI is disabled ...)[]
[picocli DEBUG] In...> but was:<...NSI is disabled ...)[, ConEmuANSI=ON, NO_COLOR=1, CLICOLOR=null, CLICOLOR_FORCE=null)]

[dwalluck]

I should mention that HelpAnsiTest actually passes with NO_COLOR unset, but then the following tests fail due to ANSI codes in the program output:

AbbreviationMatcherTest. testAbbrevOptions
AbbreviationMatcherTest. testAbbrevSubcommands
AbbreviationMatcherTest. testCaseInsensitiveAbbrevSubcommands
ModelUsageMessageSpecTest. testUsageMessageSpec_showAtFileInUsageHelp
ModelUsageMessageSpecTest. testUsageMessageSpec_showEndOfOptionsDelimiterInUsageHelp
ModelUsageMessageSpecTest. testUsageMessageSpec_synopsisSubcommandLabelSetter
ResourceBundlePropagationTest. testPropagation
UnmatchedArgumentExceptionTest. testHiddenCommandsNotSuggested
UnmatchedArgumentExceptionTest. testUnmatchedArgumentDoesNotSuggestOptionsIfNoMatch
UnmatchedArgumentExceptionTest. testUnmatchedArgumentSuggestsOptions
UnmatchedArgumentExceptionTest. testUnmatchedArgumentSuggestsSubcommands
UnmatchedArgumentExceptionTest. testUnmatchedArgumentSuggestsSubcommands2

[dwalluck]

Tests may want to verify that none of these color options are set before running, or the tests become unrepeatable.

[remkop]

Thank you for raising this!
I still need to set up a Cygwin environment to run the tests, but I went ahead and made sure that all tests now have these rules:

@Rule
public final TestRule restoreSystemProperties = new RestoreSystemProperties();

@Rule
public final ProvideSystemProperty ansiOFF = new ProvideSystemProperty("picocli.ansi", "false");

This should make the tests much more reproducible in various environments.

Does the same problem still occur with the latest from master?

[dwalluck]

It seems much better now as it is down to only two failures:

picocli.CommandLineTest > testTracingDebugWithSubCommands FAILED
    org.junit.ComparisonFailure at CommandLineTest.java:2111

picocli.CommandLineTest > testDebugOutputForDoubleDashSeparatesPositionalParameters FAILED
    org.junit.ComparisonFailure at CommandLineTest.java:1116
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address

Are we sure this test was passing?

It seems to look for text

test/java/picocli/CommandLineTest.java:1072:                        "[picocli DEBUG] (ANSI is disabled by default: ...)%n" +
test/java/picocli/CommandLineTest.java:2046:                        "[picocli DEBUG] (ANSI is disabled by default: ...)%n" +

but the text in main/java/picocli/CommandLine.java:12189 is

main/java/picocli/CommandLine.java:12189:            if (tracer.isDebug()){tracer.debug("(ANSI is %s by default: systemproperty[picocli.ansi]=%s, isatty=%s, TERM=%s, OSTYPE=%s, isWindows=%s, JansiConsoleInstalled=%s, ANSICON=%s, ConEmuANSI=%s, NO_COLOR=%s, CLICOLOR=%s, CLICOLOR_FORCE=%s)%n",

[remkop]

Yes, these tests pass on Windows and on Linux at least.

The test does not look for the exact text generated by main/java/picocli/CommandLine.java:12189 because everything that follows "[picocli DEBUG] (ANSI is disabled by default:" is too environment-specific. For that reason, the test uses the TestUtil::stripAnsiTrace method to remove environment-specific values from both the expected and the actual trace text.

I am not sure what the exact mismatch is between the expected and actual text on Cygwin. Does the prefix not match (so the actual trace text contains "ANSI is enabled by default")? Can you post details about the diff?

[dwalluck]

I am not sure what the exact mismatch is between the expected and actual text on Cygwin. Does the prefix not match (so the actual trace text contains "ANSI is enabled by default")? Can you post details about the diff?

It correctly contains everything up to ANSI is disabled by default:, but contains extra text ConEmuANSI=ON, NO_COLOR=1, CLICOLOR=null, CLICOLOR_FORCE=null).

I already gave the error above:

org.junit.ComparisonFailure: expected:<...NSI is disabled ...)[]
[picocli DEBUG] In...> but was:<...NSI is disabled ...)[, ConEmuANSI=ON, NO_COLOR=1, CLICOLOR=null, CLICOLOR_FORCE=null)]

The prefix matches. It is the suffix that causes the problem.

It looks like ANSICON is set to something like 80x1000 (80x25) so that it matches that ) instead of the one in CLICOLOR_FORCE=null). So, you see it correctly strips out everything up that first ), but in this case there a two ).

Therefore, if any of these environment variables contains a ) so that there is more than one ) in the original text, then the replacement will fail.

Also, that do...while loop in stripAnsiTrace is fragile. If it doesn't find the text, it will become an infinite loop.

[remkop]

Thanks for helping figure out why these tests failed!

I've fixed the stripAnsiTrace method to only look for a closing brace after CLICOLOR_FORCE=.
Now any closing brackets in the environment variables won't cause spurious failures.

that do...while loop in stripAnsiTrace is fragile. If it doesn't find the text, it will become an infinite loop.

That is certainly not the intention. The intention is that the loop will stop when no more replacements were made. (This allows replacing multiple occurrences of "Creating CommandSpec for object" in the trace text.)
The loop looks ok to me. Did I miss something?

[dwalluck]

That is certainly not the intention. The intention is that the loop will stop when no more replacements were made. (This allows replacing multiple occurrences of "Creating CommandSpec for object" in the trace text.)
The loop looks ok to me. Did I miss something?

The way it's currently used, it's OK. It's theoretically possible that it doesn't find the search string, doesn't do the replacement, and just loops forever. I thought it would probably be simpler if you could just use a regex and replaceAll prefix.*suffix with replacement.

[dwalluck]

I've fixed the stripAnsiTrace method to only look for a closing brace after CLICOLOR_FORCE=.
Now any closing brackets in the environment variables won't cause spurious failures.

It's not working. Now it ends up with:

org.junit.ComparisonFailure: expected:<...NSI is disabled ...)[]
[picocli DEBUG] In...> but was:<...NSI is disabled ...)[, ConEmuANSI=ON, NO_COLOR=null, CLICOLOR=null, (ANSI is disabled ...)]

Looks like it has now also added (ANSI is disabled ...) to the end.

[remkop]

It's not working. Now it ends up with: (...) Looks like it has now also added (ANSI is disabled ...) to the end.

Ouch! I added a test for TestUtil.stripAnsiTrace and fixed the issue I introduced...
Thank you very much for helping!
I believe that should fix the spurious test failures.

About the do..while loop:

It's theoretically possible that it doesn't find the search string, doesn't do the replacement, and just loops forever.

No, that is not true. It may go through the loop many times finding the search string, but there is always a final iteration where it goes through that loop without finding the search string (so it is not just theoretically possible, it should always happen by design). Then, when the search string is not found, the original String and the result String are the same object, and that is the condition for the loop to exit.
I thought I was missing something but I just went through it in a debugger and confirmed. Could this be a misunderstanding?

[dwalluck]

It's not working. Now it ends up with: (...) Looks like it has now also added (ANSI is disabled ...) to the end.

Ouch! I added a test for TestUtil.stripAnsiTrace and fixed the issue I introduced...
Thank you very much for helping!
I believe that should fix the spurious test failures.

Yes, everything seems to pass except for these messages:

stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address
stty: /dev/tty: No such device or address

It's not causing the test to fail. but maybe under Cygwin it shouldn't try this. I am not sure.

About the do..while loop:

It's theoretically possible that it doesn't find the search string, doesn't do the replacement, and just loops forever.

No, that is not true. It may go through the loop many times finding the search string, but there is always a final iteration where it goes through that loop without finding the search string (so it is not just theoretically possible, it should always happen by design). Then, when the search string is not found, the original String and the result String are the same object, and that is the condition for the loop to exit.
I thought I was missing something but I just went through it in a debugger and confirmed. Could this be a misunderstanding?

I changed something and caused the loop to get stuck, but maybe it was my fault. I no longer have the code, so let's assume it was my fault.

[remkop]

Thanks for the confirmation!

I tried to find the cause of the stty: /dev/tty: No such device or address output, but did not make much progress yet.

In an interactive session, when I run the command that picocli uses internally to figure out the terminal windows width (stty -a -F /dev/tty), I get normal output in Cygwin, not that error.

Perhaps we should avoid calling stty in non-interactive sessions. The problem is, that from Java, the only way to detect whether the process is connected to a terminal is to see if System.console() returns null, and since Cygwin and MSYS use a pseudo-tty, the console is always null in these environments...

So there may be no way to check in advance whether stty -a -F /dev/tty will succeed or fail under Cygwin/MSYS. I am tempted to leave this as it is unless someone has any idea for improving this...

[remkop]

And thank you again for helping improve the quality of the tests. Much appreciated!

[dwalluck]

In an interactive session, when I run the command that picocli uses internally to figure out the terminal windows width (stty -a -F /dev/tty), I get normal output in Cygwin, not that error.

Same here. It works for me in an interactive session, but not the test. There may be an alternate way. At least under ConEmu, it will set the environment variable ANSICON = "WxH (wxh), where W,H
is the size of the buffer, and w,h is the size of the window.

[remkop]

Interesting! I created #1104 as a follow-up ticket.

[dwalluck]

Interesting! I created #1104 as a follow-up ticket.

Thanks for your responsiveness.