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

Error message colouring broken (on Windows) with 1.74 #13104

Closed
StevePitts opened this issue Dec 1, 2023 · 20 comments · Fixed by #13140
Closed

Error message colouring broken (on Windows) with 1.74 #13104

StevePitts opened this issue Dec 1, 2023 · 20 comments · Fixed by #13140
Labels
A-console-output Area: Terminal output, colors, progress bar, etc. C-bug Category: bug O-windows OS: Windows regression-from-stable-to-stable Regression in stable that worked in a previous stable release. S-triage Status: This issue is waiting on initial triage.

Comments

@StevePitts
Copy link

After upgrading to Rust 1.74.0 some of the message colouring and highlighting disappears when cargo or rustc are used in a Windows 10 console session (Take Command, cmd.exe and Powershell all exhibit the same behaviour):

image

As the above image demonstrates this was working fine with 1.73.0

@StevePitts StevePitts added the C-bug Category: bug label Dec 1, 2023
@StevePitts
Copy link
Author

It is so old that I don't see that it can be relevant, but this existing issue: rust-lang/rust#49322 was similar

@Noratrieb
Copy link
Member

Thanks for the report! It would be super useful if you could bisect this regression using the cargo-bisect-rustc tool!

@StevePitts
Copy link
Author

StevePitts commented Dec 2, 2023

It would be super useful if you could bisect this regression

That was relatively painless, once I'd figured out the Windows specific nuances and turned off AVG!?

searched nightlies: from nightly-2023-08-20 to nightly-2023-10-01
regressed nightly: nightly-2023-10-01
searched commit range: rust-lang/rust@8ce4540...ca62d2c
552
regressed commit: rust-lang/rust@1770912

bisected with cargo-bisect-rustc v0.6.7

Host triple: x86_64-pc-windows-msvc
Reproduce with:

cargo bisect-rustc --start=1.73.0 --end=1.74.0

It might be worth noting that the output from the bisect tool was littered with ANSI control sequences so it looks like anstream doesn't work as intended on my Windows 10.

@Noratrieb
Copy link
Member

thank you very much! this looks like a cargo issue then, @weihanglo could you move the issue?

@weihanglo weihanglo transferred this issue from rust-lang/rust Dec 2, 2023
@weihanglo weihanglo added O-windows OS: Windows A-console-output Area: Terminal output, colors, progress bar, etc. S-triage Status: This issue is waiting on initial triage. labels Dec 2, 2023
@weihanglo
Copy link
Member

Transferred.

Haven't yet investigated but is very like due to this PR #12751.

@weihanglo weihanglo added the regression-from-stable-to-stable Regression in stable that worked in a previous stable release. label Dec 2, 2023
@epage
Copy link
Contributor

epage commented Dec 3, 2023

So if I understood this correctly, cargo is correctly colored when it is directly printing something but not when its taking the colored output from rustc and printing that.

... that is odd because it should all be going through the same code path. I'll likely not be able to dig into this until monday

@StevePitts
Copy link
Author

I can confirm that if I use rustc directly then the output is correctly coloured

@epage
Copy link
Contributor

epage commented Dec 4, 2023

I tested cargo 1.74.0 within cmd on Windows 10.0.19045 and cannot reproduce this.

From wikipedia, it sounds like Windows 10 version 1511 is the first version with ANSI escape codes. Huh, for some reason I thought this was back in the Windows 8 days

Can you confirm what version of Windows you are using? To better understand the scope of the problem, how come you are on such an old build of Windows 10?

If this is a pre-1511 build of Windows, then that means wincon is being used. By the output, cargo is doing things correctly but we aren't telling rustc to do things correctly.

@epage
Copy link
Contributor

epage commented Dec 4, 2023

@StevePitts could you run the following and report the results?

$ git clone https://github.com/rust-cli/anstyle.git
$ cd anstyle
$ cargo run -p anstyle-query --example query
$ cargo run -p anstyle-wincon --example dump-wincon
$ cargo run -p anstream --example query-stream
$ cargo run -p anstream --example dump-stream

@epage
Copy link
Contributor

epage commented Dec 4, 2023

For example, on my Windows 10 machine

$ cargo run -p anstyle-query --example query
clicolor: None
clicolor_force: false
no_color: false
term_supports_ansi_color: false
term_supports_color: true
truecolor: false
enable_ansi_colors: Some(true)
is_ci: false
$ cargo run -p anstyle-wincon --example dump-wincon
... first two rows are colored, rest are not
$ cargo run -p anstream --example query-stream
stdout:
  choice: Always
  choice: AlwaysAnsi
stderr:
  choice: Always
  choice: AlwaysAnsi
$ cargo run -p anstream --example dump-stream
... all rows colored

@StevePitts
Copy link
Author

Sorry for the delayed response folks but I've been in Zurich for work since Sunday night with no access to my home development box.

According to Take Command my Windows is:

Windows 10 [Version 10.0.19045.3693]

and as far as I'm concerned is bang up to date.

Results from a Take Command window:

image

Results from a cmd.exe window:

image

I hope this helps but I'm unlikely to be of much help for a few days as I'm returned from Zurich and tested positive for COVID

@epage
Copy link
Contributor

epage commented Dec 7, 2023

@StevePitts

I hope this helps but I'm unlikely to be of much help for a few days as I'm returned from Zurich and tested positive for COVID

Hope you get better quickly!

@epage
Copy link
Contributor

epage commented Dec 8, 2023

There are two questions here

  • Why can't we enable ENABLE_VIRTUAL_TERMINAL_PROCESSING?
    • 19045 is the latest so it should be supported
    • I've updated cargo run -p anstyle-query --example query to report the underlying error (though it might be ambiguous on which stream it errored). If you could git pull and run again, that'd be great
  • Why are we not showing colors just for rustc?
    • At least for this, hacking out ENABLE_VIRTUAL_TERMINAL_PROCESSING at least reproduces it.

@epage
Copy link
Contributor

epage commented Dec 8, 2023

In debugging this, I found that rustc is correctly emitting the escape codes. Most likely what is happening is that anstyle-wincon, for some reason, can't understand the escape codes and so it prints nothing.

Example of escape codes it can handle

\u{1b}[1m\u{1b}[36m    Building\u{1b}[0m

Example of escape codes it can't handle

\u{1b}[0m\u{1b}[1m\u{1b}[38;5;11mwarning\u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;15m: the `dbg!` macro is intended as a debugging tool\u{1b}[0m\n\u{1b}[0m   \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m--> \u{1b}[0m\u{1b}[0msrc/cargo\\core\\shell.rs:419:9\u{1b}[0m\n\u{1b}[0m    \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m|\u{1b}[0m\n\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m419\u{1b}[0m\u{1b}[0m \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m|\u{1b}[0m\u{1b}[0m \u{1b}[0m\u{1b}[0m        dbg!(String::from_utf8_lossy(message));\u{1b}[0m\n\u{1b}[0m    \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m| \u{1b}[0m\u{1b}[0m        \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;11m^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\u{1b}[0m\n\u{1b}[0m    \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m|\u{1b}[0m\n\u{1b}[0m    \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m= \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;15mhelp\u{1b}[0m\u{1b}[0m: for further information visit https://rust-lang.github.io/rust-clippy/master/index.html#dbg_macro\u{1b}[0m\n\u{1b}[0m    \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m= \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;15mnote\u{1b}[0m\u{1b}[0m: requested on the command line with `-W clippy::dbg-macro`\u{1b}[0m\n\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14mhelp\u{1b}[0m\u{1b}[0m: remove the invocation before committing it to a version control system\u{1b}[0m\n\u{1b}[0m    \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m|\u{1b}[0m\n\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m419\u{1b}[0m\u{1b}[0m \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m| \u{1b}[0m\u{1b}[0m        \u{1b}[0m\u{1b}[0m\u{1b}[38;5;10mString::from_utf8_lossy(message)\u{1b}[0m\u{1b}[0m;\u{1b}[0m\n\u{1b}[0m    \u{1b}[0m\u{1b}[0m\u{1b}[1m\u{1b}[38;5;14m|\u{1b}[0m\u{1b}[0m         \u{1b}[0m\u{1b}[0m\u{1b}[38;5;10m~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~\u{1b}[0m\n"

@epage
Copy link
Contributor

epage commented Dec 8, 2023

termcolor only supports outputting "bright" colors via Ansi256 escape codes. It seems anstreams wincon adapter doesn't support those.

---- adapter::wincon::test::termcolor stdout ----
thread 'adapter::wincon::test::termcolor' panicked at crates/anstream/src/adapter/wincon.rs:313:9:
assertion `left == right` failed: "Hello \u{1b}[0m\u{1b}[1m\u{1b}[38;5;11mworld\u{1b}[0m!"
  left: [(Style { fg: None, bg: None, underline: None, effects: Effects() }, "Hello "), (Style { fg: Some(Ansi(Green))
, bg: None, underline: None, effects: Effects() }, "world"), (Style { fg: None, bg: None, underline: None, effects: Ef
fects() }, "!")]
 right: [(Style { fg: None, bg: None, underline: None, effects: Effects() }, "Hello "), (Style { fg: None, bg: None, u
nderline: None, effects: Effects(BOLD) }, "world"), (Style { fg: None, bg: None, underline: None, effects: Effects() }
, "!")]

@epage
Copy link
Contributor

epage commented Dec 8, 2023

@StevePitts

In addition to re-running cargo run -p anstyle-query --example query after a git pull, could you also run rg with --color ansi? That would show whether termcolor is also able to enable ANSI escape code support which would show whether its a difference in how we interact with windows.

bors added a commit that referenced this issue Dec 8, 2023
fix: Print rustc messages colored on wincon

### What does this PR try to resolve?

The real fix is over in rust-cli/anstyle#150; this just upgrades to it

Fixes #13104

### How should we test and review this PR?

I hacked vt console support off, ran a build before and rustc messages weren't colored.  Now with this change, rustc messages are colored.

### Additional information

This still doesn't address why wincon is being used on their system
@bors bors closed this as completed in ad2643d Dec 8, 2023
@StevePitts
Copy link
Author

In addition to re-running cargo run -p anstyle-query --example query after a git pull, could you also run rg with --color ansi?

@epage not sure if this is still required given that the issue has been closed but:
image

HTH

@epage
Copy link
Contributor

epage commented Dec 11, 2023

Thanks @StevePitts !

Basically, this bug is actually two and we solved the more immediate one but it would also be good to figure out why we have to fallback to wincon on your system. The running assumption has been that wincon support is only needed for legacy Win8 systems and there has been discussion on whether it should be removed.

Understanding why cargo is falling back to wincon on your system can help us withe either

  • Undersanding if we need to maintain wincon support longer than we expected
  • Fixing the bug which will let cargo use more advanced terminal styling features.

So ripgrep is running into the same problem with its different ENABLE_VIRTUAL_TERMINAL_PROCESSING code. Unfortunately, I don't have much in the way of ideas and worry that sending a lot of one off, incremental debugging steps will be a slow, frustrating, and fruitless process. If you would be willing to dig into this some (figuring out the exact call that is failing, etc) that would be a big help. Thankfully anstyle-query is all you need for that and is relatively small.

Some random notes

The docs for ENABLE_VIRTUAL_TERMINAL_PROCESSING say

Ensure ENABLE_PROCESSED_OUTPUT is set when using this flag.

but we only | in ENABLE_VIRTUAL_TERMINAL_PROCESSING to the existing mode. No idea if ENABLE_PROCESSED_OUTPUT is set...

Though the example doesn't do anything with this.


The error being returned is ERROR_INVALID_PARAMETER

The docs say:

Checking whether SetConsoleMode returns 0 and GetLastError returns ERROR_INVALID_PARAMETER is the current mechanism to determine when running on a down-level system. An application receiving ERROR_INVALID_PARAMETER with one of the newer console mode flags in the bit field should gracefully degrade behavior and try again.

A stackoverflow post references "legacy console". It looks like this is a "Properties" setting.

Can you check if "legacy console" is enabled?

  1. Open cmd
  2. Click the cmd icon in top left
  3. Click "Properties"
  4. On the "Options" tab at the bottom is a checkbox for "Use legacy console (requires relaunch; affects all consoles)"

@StevePitts
Copy link
Author

A few things of note:

  1. the legacy console was indeed enabled on this system, although I have no particular recollection of doing so
  2. this system used to run Windows 8.1 (and 8 before that, which was installed on delivery) and was upgraded to 10 in place just before end of support for 8.1
  3. unchecking the legacy console makes the cargo issue go away with the 1.74.0 release version and also enables rg with --color ansi to work properly
  4. I spend a lot of time at the command line so it is possible that legacy console was enabled to resolve an issue with the output from some tool or other, so I will keep an eye out over the next few weeks and might have to re-enable it if the tool concerned turns out be fundamental

On the basis of the above is there anything more you'd like me to investigate here?

@epage
Copy link
Contributor

epage commented Dec 12, 2023

Thats it; thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-console-output Area: Terminal output, colors, progress bar, etc. C-bug Category: bug O-windows OS: Windows regression-from-stable-to-stable Regression in stable that worked in a previous stable release. S-triage Status: This issue is waiting on initial triage.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants