`rustc -C help` panics (ICEs) when piped to a closed stdout

[CAD97]

Code

rustc -C help | cmd /c exit

After more testing, this only reproduces consistently under cmd, as other Windows shells have diverging behavior about what it means to close a pipe via program termination 🙃

rustc --help | cmd /c exit does not panic, but this appears to be not because of rustc doing anything different, but because rustc finishes writing to stdout before it is closed.

Meta

Note: never occurs under #[cfg(unix)], as rustc sets SIGPIPE to SIG_DFL.

rustc_driver::set_sigpipe_handler

rust/compiler/rustc_driver/src/lib.rs

Lines 433 to 440 in 7f08d04

	#[cfg(unix)]
	pub fn set_sigpipe_handler() {
	unsafe {
	// Set the SIGPIPE signal handler, so that an EPIPE
	// will cause rustc to terminate, as expected.
	assert_ne!(libc::signal(libc::SIGPIPE, libc::SIG_DFL), libc::SIG_ERR);
	}
	}

rustc --version --verbose:

rustc 1.63.0-nightly (dc80ca78b 2022-06-21)
binary: rustc
commit-hash: dc80ca78b6ec2b6bba02560470347433bcd0bb3c
commit-date: 2022-06-21
host: x86_64-pc-windows-msvc
release: 1.63.0-nightly
LLVM version: 14.0.5

Error output

thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9

error: internal compiler error: unexpected panic

note: the compiler unexpectedly panicked. this is a bug.

note: we would appreciate a bug report: https://github.com/rust-lang/rust/issues/new?labels=C-bug%2C+I-ICE%2C+T-compiler&template=ice.md

note: rustc 1.63.0-nightly (dc80ca78b 2022-06-21) running on x86_64-pc-windows-msvc

note: compiler flags: -C help

query stack during panic:
end of query stack

Backtrace

stack backtrace:
   0:     0x7ffecbca9dff - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h46bec461e9e7ac22
   1:     0x7ffecbce4a4a - core::fmt::write::h2cf2927a9deb2e17
   2:     0x7ffecbc9c2e9 - <std::io::IoSliceMut as core::fmt::Debug>::fmt::hfd12a4a4f03cb21d
   3:     0x7ffecbcad6eb - std::panicking::default_hook::h22600ff9cff4f04f
   4:     0x7ffecbcad36b - std::panicking::default_hook::h22600ff9cff4f04f
   5:     0x7ffe8f597f06 - rustc_driver[9e128b4dc2b1f3f4]::pretty::print_after_hir_lowering
   6:     0x7ffecbcade92 - std::panicking::rust_panic_with_hook::hf01515033fcb4adb
   7:     0x7ffecbcadc2d - <std::panicking::begin_panic_handler::StrPanicPayload as core::panic::BoxMeUp>::get::h8d0ff84b444c4809
   8:     0x7ffecbcaaa37 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h46bec461e9e7ac22
   9:     0x7ffecbcad909 - rust_begin_unwind
  11:     0x7ffecbc9a185 - std::io::stdio::_print::heedac1eb9faaac98
  12:     0x7ffe8f5a34b3 - rustc_driver[9e128b4dc2b1f3f4]::handle_options
  13:     0x7ffe8f598e68 - <rustc_driver[9e128b4dc2b1f3f4]::RunCompiler>::run
  14:     0x7ffe8f5203be - <rustc_ast_passes[ccae167a3a40ca07]::node_count::NodeCounter as rustc_ast[f496af66d74beb8c]::visit::Visitor>::visit_attribute
  15:     0x7ffe8f5a54fb - rustc_driver[9e128b4dc2b1f3f4]::main
  16:     0x7ff7e017100e - <unknown>
  17:     0x7ff7e0171076 - <unknown>
  18:     0x7ff7e017105c - <unknown>
  19:     0x7ffecbc8c0b1 - std::rt::lang_start_internal::h562b7c63b69fd4a3
  20:     0x7ff7e0171037 - <unknown>
  21:     0x7ff7e0171284 - <unknown>
  22:     0x7fff0f1b54e0 - BaseThreadInitThunk
  23:     0x7fff1130485b - RtlUserThreadStart

[CAD97]

@rustbot label +O-Windows

[ChrisDenton]

This is a consequence of using the print series of macros. They ignore ERROR_INVALID_HANDLE errors but otherwise they're designed to panic on I/O errors.

The panic could be handled in a global catch_unwind. Or by using writeln! and handling the error in place.

[CAD97]

rustc explicitly chooses to override the startup code (which installs a SIGPIPE handler of SIG_IGN) and reinstall a handler of SIG_DFL:

rust/compiler/rustc_driver/src/lib.rs

Lines 433 to 440 in 7f08d04

	#[cfg(unix)]
	pub fn set_sigpipe_handler() {
	unsafe {
	// Set the SIGPIPE signal handler, so that an EPIPE
	// will cause rustc to terminate, as expected.
	assert_ne!(libc::signal(libc::SIGPIPE, libc::SIG_DFL), libc::SIG_ERR);
	}
	}

This means that rustc halts via SIGPIPE on POSIXy platforms and a broken pipe. To match this behavior on non-POSIX platforms, rustc should probably avoid the [e]print[ln]! family of macros, and use a custom version which process::exits on io::ErrorKind::BrokenPipe.

What makes this interesting to me is that rustc --help does terminate quietly on Windows in the face of a broken pipe; it's only -C help style help printing which ICEs.

The Zulip thread about the SIGPIPE situation is highly relevant here. The current PR provides a platform-specific #[unix_sigpipe] (a la #[windows_subsystem]) to choose the SIGPIPE behavior between inherit/SIG_DFL/SIG_IGN.

[ChrisDenton]

What makes this interesting to me is that rustc --help does terminate quietly on Windows in the face of a broken pipe; it's only -C help style help printing which ICEs.

Oh, that is interesting and a bit of an odd difference. Should be easily fixed though? I mean if rustc already has code to print without ICEs.

[CAD97]

What makes this interesting to me is that rustc --help does terminate quietly on Windows in the face of a broken pipe; it's only -C help style help printing which ICEs.

--help

rust/compiler/rustc_driver/src/lib.rs

Lines 1020 to 1026 in 7425fb2

	if matches.opt_present("h") || matches.opt_present("help") {
	// Only show unstable options in --help if we accept unstable options.
	let unstable_enabled = nightly_options::is_unstable_enabled(&matches);
	let nightly_build = nightly_options::match_is_nightly_build(&matches);
	usage(matches.opt_present("verbose"), unstable_enabled, nightly_build);
	return None;
	}

rust/compiler/rustc_driver/src/lib.rs

Lines 759 to 791 in 7425fb2

	fn usage(verbose: bool, include_unstable_options: bool, nightly_build: bool) {
	let groups = if verbose { config::rustc_optgroups() } else { config::rustc_short_optgroups() };
	let mut options = getopts::Options::new();
	for option in groups.iter().filter(|x| include_unstable_options || x.is_stable()) {
	(option.apply)(&mut options);
	}
	let message = "Usage: rustc [OPTIONS] INPUT";
	let nightly_help = if nightly_build {
	"\n -Z help Print unstable compiler options"
	} else {
	""
	};
	let verbose_help = if verbose {
	""
	} else {
	"\n --help -v Print the full set of options rustc accepts"
	};
	let at_path = if verbose {
	" @path Read newline separated options from `path`\n"
	} else {
	""
	};
	println!(
	"{options}{at_path}\nAdditional help:
	-C help Print codegen options
	-W help \
	Print 'lint' options and default settings{nightly}{verbose}\n",
	options = options.usage(message),
	at_path = at_path,
	nightly = nightly_help,
	verbose = verbose_help
	);
	}

https://github.com/rust-lang/getopts/blob/c11eb65097d0dc9fe9ceb351d63c3ac8b5f05e0b/src/lib.rs#L586-L594

-C help

rust/compiler/rustc_driver/src/lib.rs

Lines 1042 to 1047 in 7425fb2

	let cg_flags = matches.opt_strs("C");
	if cg_flags.iter().any(|x| *x == "help") {
	describe_codegen_flags();
	return None;
	}

rust/compiler/rustc_driver/src/lib.rs

Lines 931 to 932 in 7425fb2

	println!("\nAvailable codegen options:\n");
	print_flag_list("-C", config::CG_OPTIONS);

rust/compiler/rustc_driver/src/lib.rs

Lines 935 to 950 in 7425fb2

	pub fn print_flag_list<T>(
	cmdline_opt: &str,
	flag_list: &[(&'static str, T, &'static str, &'static str)],
	) {
	let max_len = flag_list.iter().map(|&(name, _, _, _)| name.chars().count()).max().unwrap_or(0);
	for &(name, _, _, desc) in flag_list {
	println!(
	" {} {:>width$}=val -- {}",
	cmdline_opt,
	name.replace('_', "-"),
	desc,
	width = max_len
	);
	}
	}

There's nothing different going on here; println! is used in both paths.

Instead, what I think is happening is buffering. I wrote a little test program:

fn main() {
    for i in 0.. {
        dbg!(i);
        println!("Hello, world!");
    }
}

And running it I get

(All runs here are done in the Windows Terminal terminal emulator with a shell of nushell, which as of 0.64.0 is using cmd to run non-builtin commands. I did a smaller number of tests directly in cmd when I realized that this may be impacting the results, and observed equivalent behavior.)

❯ cargo build --release; ^'D:\.rust\target\release\playground.exe' | cmd /c 'exit'
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 12
[src\main.rs:3] i = 13
[src\main.rs:3] i = 16
[src\main.rs:3] i = 17
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

The number of dbg!s I get is variable, though: I've seen as low as i = 10 and as high as i = 19. (I even saw i = 26 with this-command-does-not-exist in nushell...)

Some other runs with interesting qualities

❯ cargo build --release; ^'D:\.rust\target\release\playground.exe' | cmd /c 'exit'
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 12
[src\main.rs:3] i = 13
[src\main.rs:3] i = 16
[src\main.rs:3] i = 17
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
❯ ^'D:\.rust\target\release\playground.exe' | cmd /c 'exit'
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 14
[src\main.rs:3] i = 15
[src\main.rs:3] i = 16
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
❯ cargo build --release; ^'D:\.rust\target\release\playground.exe' | cmd /c 'exit'
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 12
[src\main.rs:3] i = 13
[src\main.rs:3] i = 16
[src\main.rs:3] i = 17
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
❯ cargo build --release; ^'D:\.rust\target\release\playground.exe' | cmd /c 'exit'
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 12
[src\main.rs:3] i = 13
[src\main.rs:3] i = 14
[src\main.rs:3] i = 15
[src\main.rs:3] i = 18
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
❯ cargo build --release; ^'D:\.rust\target\release\playground.exe' | cmd /c 'exit'
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
                      [src\main.rs:3] i = 12
[src\main.rs:3] i = 13
[src\main.rs:3] i = 14
[src\main.rs:3] i = 15
[src\main.rs:3] i = 16
[src\main.rs:3] i = 17
[src\main.rs:3] i = 18
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
❯ cargo build --release; ^'D:\.rust\target\release\playground.exe' | cmd /c 'exit'
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 12
[src\main.rs:3] i = 13
[src\main.rs:3] i = 14
[src\main.rs:3] i = 15
[src\main.rs:3] i = 16
[src\main.rs:3] i = 17
[src\main.rs:3] i = 19
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

These commands were run directly into a cmd shell, still with Windows Terminal as the terminal emulator:

D:\git\cad97\playground>cargo build --release && "D:\.rust\target\release\playground.exe" | cmd /c "exit"
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
                     [src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

D:\git\cad97\playground>cargo build --release && "D:\.rust\target\release\playground.exe" | cmd /c "exit"
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
                     [src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 12
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

D:\git\cad97\playground>cargo build --release && "D:\.rust\target\release\playground.exe" | cmd /c "exit"
    Finished release [optimized] target(s) in 0.00s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
                     [src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 12
[src\main.rs:3] i = 13
[src\main.rs:3] i = 14
thread 'main' panicked at 'failed printing to stdout: The pipe is being closed. (os error 232)', library\std\src\io\stdio.rs:1015:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

In the limited trials I did, I didn't see any skipped iterations directly in cmd.

Something interesting is going on here: if you'll note, the highlighted example is missing i = 14 and i = 15, despite stderr locking saying that this shouldn't be possible. This isn't a one-off error or just copy/paste error, either; this kind of data loss happened multiple times (see above dropdown for some cherry-picked trial runs).

In any case, changing the loop to 0..10 results in a quiet exit every time. The reason rustc --help exits quietly thus seems to be not because that code path is handling ErrorKind::BrokenPipe, but because Windows isn't returning a broken pipe error quickly.

Now, I realized after collecting most of the above data that the shell may be impacting the result... Observed differences:

• nushell turns ^'D:\.rust\target\release\playground.exe' | extern-command into roughly cmd /c "D:\.rust\target\release\playground.exe" | cmd /c extern-command. This is why ^'D:\.rust\target\release\playground.exe' | this-command-does-not-exist results in a broken pipe.
• cmd and pwsh parse and do command lookup before executing the first part of a pipeline. This means e.g. &'D:\.rust\target\release\playground.exe' | this-command-does-not-exist_pwsh fails before calling playground.exe at all.
• pwsh is really an odd one out here...

❯ cargo build --release; &'D:\.rust\target\release\playground.exe' | cmd /c 'exit'
   Compiling playground v0.1.0 (D:\git\cad97\playground)
    Finished release [optimized] target(s) in 0.46s
[src\main.rs:3] i = 0
[src\main.rs:3] i = 1
[src\main.rs:3] i = 2
[src\main.rs:3] i = 3
[src\main.rs:3] i = 4
[src\main.rs:3] i = 5
[src\main.rs:3] i = 6
[src\main.rs:3] i = 7
[src\main.rs:3] i = 8
[src\main.rs:3] i = 9
[src\main.rs:3] i = 10
[src\main.rs:3] i = 11
[src\main.rs:3] i = 12
[src\main.rs:3] i = 13
[src\main.rs:3] i = 14
[src\main.rs:3] i = 15
[src\main.rs:3] i = 16
[src\main.rs:3] i = 17
[src\main.rs:3] i = 18
[src\main.rs:3] i = 19
[src\main.rs:3] i = 20
[src\main.rs:3] i = 21
[src\main.rs:3] i = 22
[src\main.rs:3] i = 23
[src\main.rs:3] i = 24

(this continues infinitely.)

Eerily, it seems that pwsh treats a pipe-to-finished-program as an infinite sink, not a broken pipe! This means that in pwsh, &"D:\.rust\target\release\playground.exe" | more and inputting q will hang until you CTRL-C the pipeline. In cmd, nushell-on-cmd, and Git Bash

For completeness sake, under Git Bash (a MINGW64), "D:\.rust\target\release\playground.exe" | sh -c 'exit' consistently gives fatal runtime error: I/O error: operation failed to complete synchronously. Additionally, under all tested shells (Git Bash, pwsh, cmd, nushell-on-cmd), doing the equivalent of > /dev/null and CTRL-Cing the pipeline exited without a panic, as did the equivalent of | more > /dev/null¹. (As opposed to on a properly POSIX shell with SIGPIPE, where AIUI non-final entries in the pipeline get SIGPIPE and continue running if they SIG_IGN it, rather than receiving SIGINT? Leading to panics?)

Footnotes

1. New info! Most of the time "D:\.rust\target\release\playground.exe" | less > /dev/null in Git Bash hangs until CTRL-C exits without a panic. (q is not accepted by this pipeline.) But sometimes when I've just run with | sh -c 'exit' piping to less (with or without > /dev/null) will result in fatal runtime error: I/O error: operation failed to complete synchronously, and once I even just got fatal runtime error: with no more info. (I'm still running the same pc-windows-msvc build from MINGW.) ↩