rust icon indicating copy to clipboard operation
rust copied to clipboard

Even nicer errors from assert_unsafe_precondition

Open saethlin opened this issue 1 year ago • 13 comments

For example, now running cargo test with this patch I get things like:

$ cargo +stage1 test
    Finished test [unoptimized + debuginfo] target(s) in 0.01s
     Running unittests src/lib.rs (target/debug/deps/malloc_buf-9d105ddf86862995)

running 5 tests
thread 'tests::test_null_buf' panicked at 'unsafe precondition violated: is_aligned_and_not_null(data) &&
    crate::mem::size_of::<T>().saturating_mul(len) <= isize::MAX as usize', /home/ben/rust/library/core/src/slice/raw.rs:93:9
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread panicked while panicking. aborting.
error: test failed, to rerun pass `--lib`

Caused by:
  process didn't exit successfully: `/tmp/malloc_buf-1.0.0/target/debug/deps/malloc_buf-9d105ddf86862995` (signal: 6, SIGABRT: process abort signal)

This is still not perfect, but these are better for another PR:

  • stringify! is trying to do clever pretty-printing on the expr inside assert_unsafe_precondition and can even add a newline.
  • It would be nice to print a bit more information about where the problem is. Perhaps this is cfg_attr(debug_assertions, track_caller), or perhaps it the function name added to Location.

cc @RalfJung this is what I was thinking of for https://github.com/rust-lang/rust/pull/102732#discussion_r989068907

saethlin avatar Oct 14 '22 04:10 saethlin

I'm showing this with nextest because the default test runner in combination with libtest swallows the error message.

Maybe libtest should force all captured test output to be written in case of an aborting panic?

bjorn3 avatar Oct 14 '22 13:10 bjorn3

With a SIGABRT handler? Or do you have something more portable/graceful in mind?

saethlin avatar Oct 14 '22 14:10 saethlin

No, libtest registers a panic handler which normally only records the panic info and marks the test as failed. My suggestion is that in the case of an aborting panic it should flush all captured output including panic message before it actually aborts.

bjorn3 avatar Oct 14 '22 15:10 bjorn3

I'm trying to implement this, and I can't seem to generate the desired effect. Are panic handlers even called in the double-panic situation we're creating?

saethlin avatar Oct 15 '22 02:10 saethlin

This shouldn't be a double panic but a panic where the PanicInfo returns false from can_unwind(). I think you have to flush the captured stdout/stderr to the real stdout/stderr and at the same time remove the capturing right at the start of the panic hook set by libtest. Or at least before calling the original panic hook.

bjorn3 avatar Oct 15 '22 08:10 bjorn3

The job x86_64-gnu-llvm-13 failed! Check out the build log: (web) (plain)

Click to see the possible cause of the failure (guessed by this bot)
---- [ui] src/test/ui/process/process-panic-after-fork.rs stdout ----

error: test run failed!
status: exit status: 101
command: "/checkout/obj/build/x86_64-unknown-linux-gnu/test/ui/process/process-panic-after-fork/a"
stdout: none
--- stderr -------------------------------
engaging allocator trap, parent pid=81651
panicked after panic::always_abort(), aborting.
panicked after panic::always_abort(), aborting.
[/checkout/src/test/ui/process/process-panic-after-fork.rs:79] status = ExitStatus(
    unix_wait_status(
    ),
)
panicked at /checkout/src/test/ui/process/process-panic-after-fork.rs:150:13
panicked after panic::always_abort(), aborting.
panicked after panic::always_abort(), aborting.
[/checkout/src/test/ui/process/process-panic-after-fork.rs:79] status = ExitStatus(
    unix_wait_status(
    ),
)
)
[/checkout/src/test/ui/process/process-panic-after-fork.rs:79] status = ExitStatus(
    unix_wait_status(
    ),
)
)
thread 'main' panicked at 'assertion failed: signal == libc::SIGABRT || signal == libc::SIGILL || signal == libc::SIGTRAP', /checkout/src/test/ui/process/process-panic-after-fork.rs:83:5
------------------------------------------

Some tests failed in compiletest suite=ui mode=ui host=x86_64-unknown-linux-gnu target=x86_64-unknown-linux-gnu

rust-log-analyzer avatar Oct 15 '22 19:10 rust-log-analyzer

Hey! It looks like you've submitted a new PR for the library teams!

If this PR contains changes to any rust-lang/rust public library APIs then please comment with @rustbot label +T-libs-api -T-libs to tag it appropriately. If this PR contains changes to any unstable APIs please edit the PR description to add a link to the relevant API Change Proposal or create one if you haven't already. If you're unsure where your change falls no worries, just leave it as is and the reviewer will take a look and make a decision to forward on if necessary.

Examples of T-libs-api changes:

  • Stabilizing library features
  • Introducing insta-stable changes such as new implementations of existing stable traits on existing stable types
  • Introducing new or changing existing unstable library APIs (excluding permanently unstable features / features without a tracking issue)
  • Changing public documentation in ways that create new stability guarantees
  • Changing observable runtime behavior of library APIs

rustbot avatar Oct 16 '22 02:10 rustbot

r? @thomcc You asked a while ago to review such a PR

saethlin avatar Oct 16 '22 02:10 saethlin

@rustbot ready

saethlin avatar Oct 16 '22 02:10 saethlin

much cleaner than I expected

Might have gotten messy if not for @bjorn3's advice :smile:

saethlin avatar Oct 16 '22 02:10 saethlin

@bors r+

thomcc avatar Oct 16 '22 04:10 thomcc

:pushpin: Commit 764b5f3c400feb8f34ec6dd34dd9541b23590c0c has been approved by thomcc

It is now in the queue for this repository.

bors avatar Oct 16 '22 04:10 bors

@bors r-

RalfJung avatar Oct 16 '22 07:10 RalfJung

@RalfJung While those are more helpful error messages, I think these suggestions are probably pushing this over the line of too annoying to maintain. Given that this can be used to get a backtrace, I suspect that's enough in practice...

thomcc avatar Oct 19 '22 21:10 thomcc

@thomcc what is the maintenance issue here? It's not like these functions are suddenly going to get new safety preconditions.

RalfJung avatar Oct 19 '22 21:10 RalfJung

In the very recent past, the code here has grown from 2 or 3 of these checks, to 34 checks with a macro, to a macro which takes a bespoke syntax.

I can very easily imagine a contributor who encounters these having a gripe with the wording we choose, or wanting to decompose some of these into multiple calls (so they can see which of the 3 preconditions to slice::from_raw_parts they tripped over), or wanting to print the invalid values they passed.

The amount of code here has grown a lot, so I sympathize with anyone who thinks now is the time to slow down scope creep. Maybe this should be nominated for discussion?

  • There are perf concerns here- code size and possibly runtime. Should/can we track those? Should we get feedback from users? (I can probably get in touch with one or two)
  • How much implementation is libs willing to accept here: Per-site error messages? Multiple assert_unsafe_precondition calls per unsafe fn? Pending the other point, an error message which incorporates the invalid value(s)?

saethlin avatar Oct 19 '22 22:10 saethlin

@rustbot label +I-libs-nominated

saethlin avatar Oct 20 '22 22:10 saethlin

:shrug: sure if you both think that we should just stringify the expression, we can also go for that. I don't really understand the concerns but I also don't care enough to fight for the human-readable messages.

Regarding the code size concerns, that's just something that was brought up when we added the first of these -- I'm not an expert for the domains where those concerns come up so all I can really do here is try to be careful.

RalfJung avatar Oct 21 '22 15:10 RalfJung

I just remembered that I have a conflict with the libs meeting, so I'm writing a lot more here. This is not so much directed at you, as it is my effort to make sure these points come up at/before a meeting.

The best user experience here involves displaying the invalid values alongside the location of the bug in the user's code, as we do in panic messages for things like array index out of bounds. Certainly I would like to have that kind of behavior because it would let me debug the code of others directly from the error message, as I often do with Miri diagnostics.

I have no idea if that is a possibility though, because of a concern about code size. But we already substantially regressed code size in https://github.com/rust-lang/rust/pull/102732, the failure branch for one of these assertions is now (on x86_64):

    cc79:       50                      push   %rax
    cc7a:       48 8d 3d 7f 53 04 00    lea    0x4537f(%rip),%rdi        # 52000 <anon.0248cb95e8b925b4d7128f8507660a7d.0.llvm.3434341789188788945>
    cc81:       be 1c 00 00 00          mov    $0x1c,%esi
    cc86:       ff 15 1c 4f 06 00       call   *0x64f1c(%rip)        # 71ba8 <_GLOBAL_OFFSET_TABLE_+0x2a0>
    cc8c:       0f 0b                   ud2

The previous failure path was just a 2-byte ud2, but now we are 21 bytes if I'm reading that right. The code size implications of passing the arguments to these unsafe fn to a diverging function are hard for me to speculate about because that call may interfere with other optimizations.

There are other strategies for producing a static but human-readable error message here; for example we could have every invocation of assert_unsafe_precondition! expand to a #[cold] function which takes no explicit parameters and just dispatches to panic_str_nounwind. From our current state, that would reduce code size where we use assert_unsafe_precondition!, but it's not clear to me that it couldn't grow the size of executables.

Recently, I tried profiling these checks and I identified two micro-optimizations for the two hottest checks: https://github.com/rust-lang/rust/pull/103287 https://github.com/rust-lang/rust/issues/103285 I suspect both of those have code size implications, but exactly what they are is not at all straightforward, because LLVM can (and as best I can tell by squinting at assembly, actually does) optimize away parts of these checks, for some callers. The implications of those optimizations on code size are entirely unclear to me, for example do the code size savings there open up the possibility to spend a code size budget elsewhere?

So I think if we're going to keep making decision on the basis of code size here, I want to do that with data. I know that Oxide has at least in the past compiled and run a bootloader with these debug assertions enabled, and found UB that way: https://github.com/japaric/heapless/pull/280 so I'm sure they care about code size at some level. And of course there are plenty of other embedded Rust users who may have even more stringent code size requirements. Are those users even enabling debug assertions? Embedded users of debug assertions may be able to at least provide an example codebase whose size they care about, and some context about what kinds of regressions would be concerning; we could keep an eye on that to at least have some idea.

In terms of concrete maintenance burden, we have had https://github.com/rust-lang/rust/pull/100759 which touched every use of this macro, and I expect we will have the occasional PR along the lines of https://github.com/rust-lang/rust/pull/103329 to add these assertions for unsafe fn that we forgot about or only recently decided to do assertions for, or new API additions such as https://github.com/rust-lang/rust/pull/99136.

saethlin avatar Oct 21 '22 18:10 saethlin

:umbrella: The latest upstream changes (presumably #103562) made this pull request unmergeable. Please resolve the merge conflicts.

bors avatar Oct 26 '22 12:10 bors

The job x86_64-gnu-llvm-13 failed! Check out the build log: (web) (plain)

Click to see the possible cause of the failure (guessed by this bot)
   Compiling cc v1.0.73
   Compiling memchr v2.5.0
   Compiling std v0.0.0 (/checkout/library/std)
   Compiling unwind v0.0.0 (/checkout/library/unwind)
error: no rules expected the token `=>`
     |
     |
200  |             assert_unsafe_precondition!([T: ?Sized](ptr: *mut T) => !ptr.is_null());
     |                                                                  ^^ no rules expected this token in macro call
    ::: library/core/src/intrinsics.rs:2205:1
     |
2205 | macro_rules! assert_unsafe_precondition {
     | --------------------------------------- when calling this macro

rust-log-analyzer avatar Oct 26 '22 13:10 rust-log-analyzer

We discussed this in the t-libs meeting, and are okay with these changes (including the ones proposed by @RalfJung to add descriptive messages). Feel free to make those changes when convenient.

@rustbot author

thomcc avatar Oct 26 '22 20:10 thomcc

Brace yourselves, I'm going to click the button on all the suggestions then squash them down.

saethlin avatar Oct 26 '22 21:10 saethlin

Github supports committing multiple suggestions at once. :) You have to be on the 'diff' view for that.

RalfJung avatar Oct 26 '22 22:10 RalfJung

I assume this is ready for review? LGTM.

RalfJung avatar Oct 26 '22 22:10 RalfJung

LGTM

@bors r+

thomcc avatar Oct 27 '22 03:10 thomcc

:pushpin: Commit 458aaa5a2343a58d169c21e90101376b83fd9fdc has been approved by thomcc

It is now in the queue for this repository.

bors avatar Oct 27 '22 03:10 bors