Rustc compiler panic prints to stdout - breaks RLS comms

[alexheretic]

With this bug I'm less interested in the rustc bugs themselves rather that they can cause output to stdout. Doing so is unacceptable for the Rls as it breaks jsonrpc, and in a way that is not currently recoverable by vscode-jsonrpc library (used by atom & vscode RLS clients).

Is there any way we can minimise the possibility of rustc printing stdout in RLS usage?

Rustc stdout after panic

Usage: rustc [OPTIONS] INPUT
Options:
     -h, --help          Display this message
...etc...

For example, printing the help instead to stderr would be enough to prevent jsonrpc abuse in RLS.

Atom console

[nrc]

This looks like we're printing the --help message after a panic, which is kind of weird. @rust-lang/compiler any idea why that would happen? @alexheretic does that look like what is happening?

[alexheretic]

@nrc that's exactly what it looks like. I'm getting this consistently too, with the stdout each panic now requires an Rls & Rls client restart :(. The panic themselves seem to occur at certain situations when the code won't compile, ie I encounter it eventually by editing code.

[michaelwoerister]

This looks like we're printing the --help message after a panic

Weird indeed :)

@alexheretic, maybe the full stack trace of the panic might help diagnose the problem. Can you provide a screenshot showing the stack frames above 12?

[alexheretic]

The traces themselves seemed very similar to those reported in rust-lang/rls#754. I'll add my trace next time I encounter one.

[nikomatsakis]

(What is a "RI"?)

[oli-obk]

rls 😆 I wondered the same thing when I first saw the title

[alexheretic]

That is something I can clarify easily.

[nikomatsakis]

Can we reproduce this running from the command line?

[nikomatsakis]

Should be plenty of ICEs to pick from in the repo :)

[alexheretic]

Here's the output of one from just now

19:05:10.870 /home/alex/project/atom-ide-rust/node_modules/atom-languageclient/build/lib/logger.js:9 Rust (RLS) stderr thread 'rustc' panicked at 'Box<Any>', librustc_errors/lib.rs:482:9
19:05:10.870 /home/alex/project/atom-ide-rust/node_modules/atom-languageclient/build/lib/logger.js:9 Rust (RLS) stderr note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
19:05:10.870 /home/alex/project/atom-ide-rust/node_modules/atom-languageclient/build/lib/logger.js:9 Rust (RLS) stderr stack backtrace:
19:05:10.870 /home/alex/project/atom-ide-rust/node_modules/atom-languageclient/build/lib/logger.js:9 Rust (RLS) stderr    0: std::sys::unix::backtrace::tracing::imp::unwind_backtrace
19:05:10.870 /home/alex/project/atom-ide-rust/node_modules/atom-languageclient/build/lib/logger.js:9 Rust (RLS) stderr              at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
19:05:10.870 /home/alex/project/atom-ide-rust/node_modules/atom-languageclient/build/lib/logger.js:9 Rust (RLS) stderr    1: std::sys_common::backtrace::_print
19:05:10.870 /home/alex/project/atom-ide-rust/node_modules/atom-languageclient/build/lib/logger.js:9 Rust (RLS) stderr              at libstd/sys_common/backtrace.rs:71
19:05:10.870 /home/alex/project/atom-ide-rust/node_modules/atom-languageclient/build/lib/logger.js:9 Rust (RLS) stderr    2: std::panicking::default_hook::{{closure}}
stderr              at libstd/sys_common/backtrace.rs:59
stderr              at libstd/panicking.rs:207
stderr    3: std::panicking::default_hook
stderr              at libstd/panicking.rs:223
stderr    4: core::ops::function::Fn::call
stderr    5: std::panicking::rust_panic_with_hook
stderr              at libstd/panicking.rs:403
stderr    6: std::panicking::begin_panic
stderr    7: rustc_errors::Handler::span_bug
stderr    8: rustc::session::opt_span_bug_fmt::{{closure}}
stderr    
stderr 9: rustc::ty::context::tls::with_opt::{{closure}}
stderr   10: <std::thread::local::LocalKey<T>>::try_with
stderr   11: <std::thread::local::LocalKey<T>>::with
stderr   12: rustc::ty::context::tls::with
stderr   13: rustc::ty::context::tls::with_opt
stderr   14: rustc::session::opt_span_bug_fmt
stderr   15: rustc::session::span_bug_fmt
stderr   16: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O> as syntax::visit::Visitor<'l>>::visit_expr
stderr   17: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O> as syntax::visit::Visitor<'l>>::visit_expr
stderr   18: syntax::visit::walk_expr
stderr   19: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O> as syntax::visit::Visitor<'l>>::visit_expr
stderr   20: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O>>::process_method
stderr   21: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O>>::process_impl_item
stderr   22: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O> as syntax::visit::Visitor<'l>>
stderr ::visit_item
stderr   23: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O> as syntax::visit::Visitor<'l>>::visit_item
stderr   24: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O> as syntax::visit::Visitor<'l>>::visit_item
stderr   25: <rustc_save_analysis::dump_visitor::DumpVisitor<'l, 'tcx, 'll, O> as syntax::visit::Visitor<'l>>::visit_mod
stderr   26: <rustc_save_analysis::CallbackHandler<'b> as rustc_save_analysis::SaveHandler>::save
stderr   27: <rls::build::rustc::RlsRustcCalls as rustc_driver::CompilerCalls<'a>>::build_controller::{{closure}}
stderr   28: rustc_driver::driver::compile_input::{{closure}}
stderr   29: rustc::ty::context::TyCtxt::create_and_enter
stderr   30: rustc_driver::driver::compile_input
stderr   31: rustc_driver::run_compiler
stderr note: the compiler unexpectedly panicked. this is a bug.
stderr note: we would appreciate a bug report: https://github.com/rust-lang/rust/blob/master/CONTRIBUTING.md#bug-reports
stderr note: rustc 1.26.0-nightly (2789b067d 2018-03-06) running on x86_64-unknown-linux-gnu

And the stdout

19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout: Usage: rustc [OPTIONS] INPUT
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout: Options:
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -h, --help          Display this message
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --cfg SPEC      Configure the compilation environment
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -L [KIND=]PATH      Add a directory to the library search path. The
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         optional KIND can be one of dependency, crate, native,
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         framework or all (the default).
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -l [KIND=]NAME      Link the generated crate(s) to the specified native
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         library NAME. The optional KIND can be one of static,
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         dylib, or framework. If omitted, dylib is assumed.
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --crate-type [bin|lib|rlib|dylib|cdylib|staticlib|proc-macro]
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         Comma separated list of types of crates for the
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         compiler to emit
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --crate-name NAME
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         Specify the name of the crate being built
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --emit [asm|llvm-bc|llvm-ir|obj|metadata|link|dep-info|mir]
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         Comma separated list of types of output for the
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         compiler to emit
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --print [crate-name|file-names|sysroot|cfg|target-list|target-cpus|target-features|relocation-models|code-models|tls-models|target-spec-json|native-static-libs]
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         Comma separated list of compiler information to print
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         on stdout
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -g                  Equivalent to -C debuginfo=2
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -O                  Equivalent to -C opt-level=2
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -o FILENAME         Write output to <filename>
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --out-dir DIR   Write output to compiler-chosen filename in <dir>
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --explain OPT   Provide a detailed explanation of an error message
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --test          Build a test harness
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --target TARGET Target triple for which the code is compiled
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -W, --warn OPT      Set lint warnings
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -A, --allow OPT     Set lint allowed
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -D, --deny OPT      Set lint denied
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -F, --forbid OPT    Set lint forbidden
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:         --cap-lints LEVEL
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         Set the most restrictive lint level. More restrictive
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         lints are capped at this level
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -C, --codegen OPT[=VALUE]
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:                         Set a codegen option
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -V, --version       Print version info and exit
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -v, --verbose       Use verbose output
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout: Additional help:
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -C help             Print codegen options
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -W help             Print 'lint' options and default settings
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     -Z help             Print internal options for debugging rustc
19:05:10.952 /home/alex/project/atom-ide-rust/lib/index.js:187 Rust (RLS) suspicious stdout:     --help -v           Print the full set of options rustc accepts

[alexheretic]

Could rls be executing rustc after a panic in such a way to cause stdout? Though I don't imagine it's running rustc --help...

[alexheretic]

Ok clearly the panic comes from rustc_driver::run_compiler called by Rls. By looking at librustc_driver/lib.rs I can see the usage function is the cause of the offending stdout.

usage is called by handle_options which prints this when the args are empty. Rls does not call run_compiler without arguments.

However, added a couple of weeks ago by #48266 is what strongly seems to be source of this issue:

// librustc_driver/lib.rs
...
/// Get a list of extra command-line flags provided by the user, as strings.
///
/// This function is used during ICEs to show more information useful for
/// debugging, since some ICEs only happens with non-default compiler flags
/// (and the users don't always report them).
fn extra_compiler_flags() -> Option<(Vec<String>, bool)> {
    let mut args = Vec::new();
    for arg in env::args_os() {
        args.push(arg.to_string_lossy().to_string());
    }

    let matches = if let Some(matches) = handle_options(&args) { ...

As this code uses env::args_os() it is assuming the compiler is the program. Whereas in this case Rls has been started without arguments.

It makes sense to return None from this function in the case there are no arguments, printing help at this stage isn't intended I imagine.

[michaelwoerister]

@pietroalbini, it seems that the ICE message PR had some unintended side-effects :)