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

When there is an ICE in the tests, the output is unreadable #3052

Closed
RalfJung opened this issue Sep 5, 2023 · 0 comments · Fixed by #3008
Closed

When there is an ICE in the tests, the output is unreadable #3052

RalfJung opened this issue Sep 5, 2023 · 0 comments · Fixed by #3008

Comments

@RalfJung
Copy link
Member

RalfJung commented Sep 5, 2023

This can be easily reproduced by making some shim ICE and running ./miri test. It leads to output like

pass test got exit status: 101, but expected 0

A bug in `ui_test` occurred: test panicked: stderr:
thread 'rustc' panicked at src/shims/panic.rs:132:9:
not yet implemented
stack backtrace:
   0:     0x7f367a563dec - std::backtrace_rs::backtrace::libunwind::trace::h4b664a9a7853e75c
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
   1:     0x7f367a563dec - std::backtrace_rs::backtrace::trace_unsynchronized::h93aa5c3a7318d076
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x7f367a563dec - std::sys_common::backtrace::_print_fmt::h2f8987280a2d968f
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/sys_common/backtrace.rs:67:5
   3:     0x7f367a563dec - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h105ce4d686fff802
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/sys_common/backtrace.rs:44:22
   4:     0x7f367a5ca05c - core::fmt::rt::Argument::fmt::hb779957f0b55f469
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/core/src/fmt/rt.rs:138:9
   5:     0x7f367a5ca05c - core::fmt::write::hbaebfa7aeff4d564
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/core/src/fmt/mod.rs:1094:21
   6:     0x7f367a5568fe - std::io::Write::write_fmt::h1aac7745b5ca625f
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/io/mod.rs:1714:15
   7:     0x7f367a563bd4 - std::sys_common::backtrace::_print::h1b05691ed6dfdd5d
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/sys_common/backtrace.rs:47:5
   8:     0x7f367a563bd4 - std::sys_common::backtrace::print::h59d8584ac40b66e8
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/sys_common/backtrace.rs:34:9
   9:     0x7f367a566cea - std::panicking::panic_hook_with_disk_dump::{{closure}}::h3d9014002f8cd732
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/panicking.rs:280:22
  10:     0x7f367a5669e5 - std::panicking::panic_hook_with_disk_dump::ha9bd9f0c11eb0ef4
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/panicking.rs:314:9
  11:     0x7f367d751de9 - rustc_driver_impl[d85fae848861c4cc]::install_ice_hook::{closure#0}
  12:     0x7f367a5675a3 - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::h9b6c3254e69f7b38
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/alloc/src/boxed.rs:2021:9
  13:     0x7f367a5675a3 - std::panicking::rust_panic_with_hook::hb1a71452160738b5
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/panicking.rs:757:13
  14:     0x7f367a5672d6 - std::panicking::begin_panic_handler::{{closure}}::h61afee132e3dfffd
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/panicking.rs:623:13
  15:     0x7f367a564316 - std::sys_common::backtrace::__rust_end_short_backtrace::h444631489abc9ff7
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/sys_common/backtrace.rs:170:18
  16:     0x7f367a567062 - rust_begin_unwind
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/panicking.rs:619:5
  17:     0x7f367a5c6405 - core::panicking::panic_fmt::h6ebb53beffd55382
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/core/src/panicking.rs:72:14
  18:     0x7f367a5c64a3 - core::panicking::panic::h77aa768aea1111af
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/core/src/panicking.rs:127:5
  19:     0x55bdf313d280 - miri::shims::panic::EvalContextExt::handle_stack_pop_unwind::h8816ea6b4ffbf1ab
                               at /home/r/src/rust/miri/src/shims/panic.rs:132:9
  20:     0x55bdf313d280 - <miri::machine::MiriMachine as rustc_const_eval::interpret::machine::Machine>::after_stack_pop::h254e95757ad775ba
                               at /home/r/src/rust/miri/src/machine.rs:1405:19
  21:     0x55bdf313d280 - rustc_const_eval::interpret::eval_context::InterpCx<M>::pop_stack_frame::h88cf71fb86a95642
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/compiler/rustc_const_eval/src/interpret/eval_context.rs:868:12
  22:     0x55bdf316ae56 - rustc_const_eval::interpret::terminator::<impl rustc_const_eval::interpret::eval_context::InterpCx<M>>::eval_terminator::hb5ab54be79b5d5fc
  23:     0x55bdf316ae56 - rustc_const_eval::interpret::step::<impl rustc_const_eval::interpret::eval_context::InterpCx<M>>::terminator::h352b0ad1d5d06d97
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/compiler/rustc_const_eval/src/interpret/step.rs:317:9
  24:     0x55bdf316ae56 - rustc_const_eval::interpret::step::<impl rustc_const_eval::interpret::eval_context::InterpCx<M>>::step::h4646f33e925f5fbd
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/compiler/rustc_const_eval/src/interpret/step.rs:48:9
  25:     0x55bdf316ae56 - miri::concurrency::thread::EvalContextExt::run_threads::hb9b0ec506dd885bf
                               at /home/r/src/rust/miri/src/concurrency/thread.rs:1043:25
  26:     0x55bdf30c3dac - miri::eval::eval_entry::{{closure}}::hb0729c385c251d06
                               at /home/r/src/rust/miri/src/eval.rs:446:49
  27:     0x55bdf30c3dac - core::ops::function::FnOnce::call_once::h30a5dfbc51033d29
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/core/src/ops/function.rs:250:5
  28:     0x55bdf30c3dac - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::hded092bd1920cfd0
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/core/src/panic/unwind_safe.rs:271:9
  29:     0x55bdf30c3dac - std::panicking::try::do_call::ha267ef4f3a8e9753
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/panicking.rs:526:40
  30:     0x55bdf30c3dac - std::panicking::try::he6d5145c92826396
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/panicking.rs:490:19
  31:     0x55bdf30c3dac - std::panic::catch_unwind::h0ba7bc5a12cf3d0a
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/panic.rs:142:14
  32:     0x55bdf30c3dac - miri::eval::eval_entry::h6a4a2c6bb6f993f6
                               at /home/r/src/rust/miri/src/eval.rs:446:9
  33:     0x55bdf302b14c - <miri::MiriCompilerCalls as rustc_driver_impl::Callbacks>::after_analysis::{{closure}}::h14dcc27ccfd19476
                               at /home/r/src/rust/miri/src/bin/miri.rs:106:40
  34:     0x55bdf302b14c - rustc_middle::ty::context::GlobalCtxt::enter::{{closure}}::hefa188aa9cce1a8c
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/compiler/rustc_middle/src/ty/context.rs:593:37
  35:     0x55bdf302b14c - rustc_middle::ty::context::tls::enter_context::{{closure}}::h38294d9618d19063
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/compiler/rustc_middle/src/ty/context/tls.rs:82:9
  36:     0x55bdf302b14c - std::thread::local::LocalKey<T>::try_with::h3ad36c6fce68b6c9
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/thread/local.rs:270:16
  37:     0x55bdf302b14c - std::thread::local::LocalKey<T>::with::hc489a096e9f1fb25
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/thread/local.rs:246:9
  38:     0x55bdf302b14c - rustc_middle::ty::context::tls::enter_context::hf678fdc99c5bc317
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/compiler/rustc_middle/src/ty/context/tls.rs:79:9
  39:     0x55bdf302b14c - rustc_middle::ty::context::GlobalCtxt::enter::h05b8b7ae207f80a4
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/compiler/rustc_middle/src/ty/context.rs:593:9
  40:     0x55bdf302796d - rustc_interface::queries::QueryResult<&rustc_middle::ty::context::GlobalCtxt>::enter::h4bc4565053936a1b
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/compiler/rustc_interface/src/queries.rs:69:9
  41:     0x55bdf302796d - <miri::MiriCompilerCalls as rustc_driver_impl::Callbacks>::after_analysis::h7ae9bc11b35dfea7
                               at /home/r/src/rust/miri/src/bin/miri.rs:66:9
  42:     0x7f367c9b291c - <rustc_interface[8a6f8ad1c34a5f70]::interface::Compiler>::enter::<rustc_driver_impl[d85fae848861c4cc]::run_compiler::{closure#1}::{closure#2}, core[d800f448664a514]::result::Result<core[d800f448664a514]::option::Option<rustc_interface[8a6f8ad1c34a5f70]::queries::Linker>, rustc_span[5837f1b58b81b15d]::ErrorGuaranteed>>
  43:     0x7f367c9aa0f8 - std[b009c5d90180bac5]::sys_common::backtrace::__rust_begin_short_backtrace::<rustc_interface[8a6f8ad1c34a5f70]::util::run_in_thread_with_globals<rustc_interface[8a6f8ad1c34a5f70]::interface::run_compiler<core[d800f448664a514]::result::Result<(), rustc_span[5837f1b58b81b15d]::ErrorGuaranteed>, rustc_driver_impl[d85fae848861c4cc]::run_compiler::{closure#1}>::{closure#0}, core[d800f448664a514]::result::Result<(), rustc_span[5837f1b58b81b15d]::ErrorGuaranteed>>::{closure#0}::{closure#0}, core[d800f448664a514]::result::Result<(), rustc_span[5837f1b58b81b15d]::ErrorGuaranteed>>
  44:     0x7f367c9a986e - <<std[b009c5d90180bac5]::thread::Builder>::spawn_unchecked_<rustc_interface[8a6f8ad1c34a5f70]::util::run_in_thread_with_globals<rustc_interface[8a6f8ad1c34a5f70]::interface::run_compiler<core[d800f448664a514]::result::Result<(), rustc_span[5837f1b58b81b15d]::ErrorGuaranteed>, rustc_driver_impl[d85fae848861c4cc]::run_compiler::{closure#1}>::{closure#0}, core[d800f448664a514]::result::Result<(), rustc_span[5837f1b58b81b15d]::ErrorGuaranteed>>::{closure#0}::{closure#0}, core[d800f448664a514]::result::Result<(), rustc_span[5837f1b58b81b15d]::ErrorGuaranteed>>::{closure#1} as core[d800f448664a514]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
  45:     0x7f367a572015 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h7d9536b59d7c2183
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/alloc/src/boxed.rs:2007:9
  46:     0x7f367a572015 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hdfad988db41bfee4
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/alloc/src/boxed.rs:2007:9
  47:     0x7f367a572015 - std::sys::unix::thread::Thread::new::thread_start::hb811e169405d44af
                               at /rustc/a989e25f1b87949a886eab3da10324d14189fe95/library/std/src/sys/unix/thread.rs:108:17
  48:     0x7f367a30c3ec - start_thread
                               at ./nptl/pthread_create.c:444:8
  49:     0x7f367a38ca1c - __GI___clone3
                               at ./misc/../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
  50:                0x0 - <unknown>

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

note: we would appreciate a bug report: https://github.com/rust-lang/miri/issues/new

note: rustc 1.74.0-nightly (a989e25f1 2023-09-03) running on x86_64-unknown-linux-gnu

note: compiler flags: -Z ui-testing -Z miri-unique-is-unique -Z miri-tree-borrows

query stack during panic:
end of query stack

Miri caused an ICE during evaluation. Here's the interpreter backtrace at the time of the panic:
{"message":"the place in the program where the ICE was triggered","code":null,"level":"note","spans":[{"file_name":"/home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panicking.rs","byte_start":16646,"byte_end":16666,"line_start":477,"line_end":477,"column_start":30,"column_end":50,"is_primary":true,"text":[{"text":"    let mut data = Data { f: ManuallyDrop::new(f) };","highlight_start":30,"highlight_end":50}],"label":null,"suggested_replacement":null,"suggestion_applicability":null,"expansion":null}],"children":[{"message":"inside `std::panicking::r#try::<(), [closure@std::rt::lang_start_internal::{closure#1}]>` at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panicking.rs:477:30: 477:50","code":null,"level":"note","spans":[],"children":[],"rendered":null},{"message":"inside `std::panic::catch_unwind::<[closure@std::rt::lang_start_internal::{closure#1}], ()>` at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panic.rs:142:14: 142:33","code":null,"level":"note","spans":[],"children":[],"rendered":null},{"message":"inside `std::rt::lang_start_internal` at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/rt.rs:147:5: 147:70","code":null,"level":"note","spans":[],"children":[],"rendered":null},{"message":"inside `std::rt::lang_start::<()>` at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/rt.rs:165:17: 170:6","code":null,"level":"note","spans":[],"children":[],"rendered":null}],"rendered":"note: the place in the program where the ICE was triggered\n  --> /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panicking.rs:477:30\n   |\nLL |     let mut data = Data { f: ManuallyDrop::new(f) };\n   |                              ^^^^^^^^^^^^^^^^^^^^\n   |\n   = note: inside `std::panicking::r#try::<(), [closure@std::rt::lang_start_internal::{closure#1}]>` at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panicking.rs:477:30: 477:50\n   = note: inside `std::panic::catch_unwind::<[closure@std::rt::lang_start_internal::{closure#1}], ()>` at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/panic.rs:142:14: 142:33\n   = note: inside `std::rt::lang_start_internal` at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/rt.rs:147:5: 147:70\n   = note: inside `std::rt::lang_start::<()>` at /home/r/.rustup/toolchains/miri/lib/rustlib/src/rust/library/std/src/rt.rs:165:17: 170:6\n\n"}

In particular note the unreadable junk of JSON at the end.

Seems to be some ui-test problem? Cc @oli-obk

@bors bors closed this as completed in c004fc1 Sep 25, 2023
RalfJung pushed a commit to RalfJung/rust that referenced this issue Sep 28, 2023
bump ui test crate

The recommended way to run tests locally is `./miri bless -- -- --quiet`, which will show

* progress bars
* the currently running tests (allowing you to see which ones are still running towards the end of the test suite)
* the output of the currently running tests (if they are slow). This means slow running tests can output lines to `stderr` and the last line will be shown after the test name and updated every few hundred milliseconds.

As a side effect this PR also fixes rust-lang#2998 and only builds dependencies if any tests actually need them (this means that with the next ui_test update we'll be able to merge all our test suites).

Also fixes rust-lang/miri#3052.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant