New panic with env_logger and with #[windows_subsystem = "windows"]

[parasyte]

This was initially reported in rust-cli/env_logger#214, but I'm adding it here for additional eyes and because this issue doesn't occur on stable Rust. I could be wrong but this looks like this is caused by #87329 ... cc @sunfishcode ?

---

I spent an hour trying to reduce a minimal test case for this error I started experiencing with my app. So far I have produced the following:

[package]
name = "windows_explodey"
version = "0.1.0"
edition = "2018"
resolver = "2"

[dependencies]
env_logger = "0.9"

[profile.release]
panic = "abort"

#![windows_subsystem = "windows"]

fn main() {
    env_logger::init();

    println!("Hello, world!");
}

When running this on any nightly compiler since nightly-2021-08-21, I get an error like this:

$ cargo +nightly-2021-08-21 run
    Finished dev [unoptimized + debuginfo] target(s) in 0.03s
     Running `target\debug\windows_explodey.exe`
error: process didn't exit successfully: `target\debug\windows_explodey.exe` (exit code: 101)

Adjusting the profile to panic = "abort" causes an even more ominous error:

$ cargo +nightly-2021-08-21 run --release
    Finished release [optimized] target(s) in 0.03s
     Running `target\release\windows_explodey.exe`
error: process didn't exit successfully: `target\release\windows_explodey.exe` (exit code: 0xc0000409, STATUS_STACK_BUFFER_OVERRUN)

Here's a stack trace from windbg:

[0x0]   windows_explodey!panic_abort::__rust_start_panic::abort + 0x5   
[0x1]   windows_explodey!panic_abort::__rust_start_panic + 0x6   
[0x2]   windows_explodey!std::panicking::rust_panic + 0x1b   
[0x3]   windows_explodey!std::panicking::rust_panic_with_hook + 0x297   
[0x4]   windows_explodey!std::panicking::begin_panic_handler::closure$0 + 0x6f   
[0x5]   windows_explodey!std::sys_common::backtrace::__rust_end_short_backtrace<std::panicking::begin_panic_handler::closure$0,never$> + 0x17   
[0x6]   windows_explodey!std::panicking::begin_panic_handler + 0x49   
[0x7]   windows_explodey!core::panicking::panic_fmt + 0x30   
[0x8]   windows_explodey!core::panicking::panic + 0x4c   
[0x9]   windows_explodey!std::os::imp::windows::io::handle::impl$11::from_raw_handle + 0x4c   
[0xa]   windows_explodey!std::os::imp::windows::io::raw::impl$7::from_raw_handle + 0x13   
[0xb]   windows_explodey!winapi_util::win::HandleRef::from_raw_handle + 0xe   
[0xc]   windows_explodey!winapi_util::win::HandleRef::stderr + 0x27   
[0xd]   windows_explodey!winapi_util::console::HandleKind::handle + 0x27   
[0xe]   windows_explodey!winapi_util::console::Console::create_for_stream + 0x22   
[0xf]   windows_explodey!winapi_util::console::Console::stderr + 0x1d   
[0x10]   windows_explodey!termcolor::BufferWriter::create + 0x59   
[0x11]   windows_explodey!termcolor::BufferWriter::stderr + 0x22   
[0x12]   windows_explodey!env_logger::fmt::writer::termcolor::imp::BufferWriter::stderr + 0x49   
[0x13]   windows_explodey!env_logger::fmt::writer::Builder::build + 0x133   
[0x14]   windows_explodey!env_logger::Builder::build + 0x46   
[0x15]   windows_explodey!env_logger::Builder::try_init + 0x1c   
[0x16]   windows_explodey!env_logger::try_init_from_env<env_logger::Env> + 0x39   
[0x17]   windows_explodey!env_logger::try_init + 0x1b   
[0x18]   windows_explodey!env_logger::init + 0x9   
[0x19]   windows_explodey!windows_explodey::main + 0x9   

If I'm reading this correctly, the panic is from this assertion:

rust/library/std/src/os/windows/io/handle.rs

Line 183 in 50171c3

assert!(!handle.is_null());

[ChrisDenton]

Likely cause is that when the "windows" subsystem is used, the std handles will all be null (i.e. they don't exist). From the backtrace it looks like something is expecting them to always be a valid handle value.

EDIT: Oh wait, that's probably termcolor not checking for null before making a BufferWriter?

[parasyte]

termcolor just does this: https://github.com/BurntSushi/termcolor/blob/dc7e7b93830579716fc180925a17551dee5cfddc/src/lib.rs#L893-L899

It expects a Result.

[sunfishcode]

winapi-util does this: https://github.com/BurntSushi/winapi-util/blob/master/src/win.rs#L139

It assumes it can call as_raw_handle and get something it can pass to from_raw_handle. as_raw_handle calls GetStdHandle which returns NULL if there are no handles, as in "windows" subsystem mode, and then the new from_raw_handle code asserts that its argument is non-null.

[sunfishcode]

The crash goes away if I change the env_logger dependency in Cargo.toml to disable the "termcolor" and "atty" features:

env_logger = { version = "0.9", default-features = false, features = ["humantime", "regex"] }

As such, one option here would be to say that io::stderr() shouldn't be called in #![windows_subsystem = "windows"] mode, and have it panic with a descriptive panic message. There's a logic to that, since there seems to be no point in linking in and calling termcolor or other stdio-using things if there's no terminal to talk to. However, that's not backwards compatible.

Another option would be to say that OwnedHandle::from_raw_handle has to be able to accept NULL handles. That's doable, though if we want to preserve the FFI use case, that would mean introducing another struct like HandleOrInvalid, this time for NULL instead of INVALID_HANDLE_VALUE.

[sunfishcode]

cc the io_safety tracking issue

[parasyte]

Maybe it would be worthwhile to get BurntSushi's thoughts, since this affects winapi_util?

Personally I would be ok with "just update your dependencies" as a solution, but maintaining backward compatibility might be more important for the libraries team...

[ChrisDenton]

As such, one option here would be to say that io::stderr() shouldn't be called in #![windows_subsystem = "windows"] mode, and have it panic with a descriptive panic message. There's a logic to that, since there seems to be no point in linking in and calling termcolor or other stdio-using things if there's no terminal to talk to. However, that's not backwards compatible.

In any case this would cause other problems. Windows processes can be freely attached or detached from consoles no mater which windows_subsystem they're using so we can't really make assumptions based on that.

[sunfishcode]

In any case this would cause other problems. Windows processes can be freely attached or detached from consoles no mater which windows_subsystem they're using so we can't really make assumptions based on that.

In that case, it seems like the best option is to change OwnedHandle to accept null. And for the FFI use case, introduce a new HandleOrNull struct similar to HandleOrInvalid but for functions that use NULL to indicate an error.

[ChrisDenton]

Hm, GetStdHandle uses INVALID_HANDLE_VALUE to indicate an error and NULL to indicate there's no associated handle.

[sunfishcode]

Good catch; HandleOrInvalid will also need to be changed to accept NULL handles.

[sunfishcode]

This is now implemented in #88798.

[joshtriplett]

@sunfishcode Would it make sense to just use Option<HandleOrInvalid> for that?