Rustup #329

oli-obk · 2017-09-04T14:03:42Z

With full mir and on master rustc miri fails with

error: new Write lock at MemoryPointer { alloc_id: Runtime(2511), offset: 0 }, size 2, is in conflict with lock WriteLock(DynamicLifetime { frame: 9, region: None })
    --> /home/ws/ca8159/Projects/rust/rust/src/libcore/cell.rs:1239:9
     |
1239 |         &self.value as *const T as *mut T
     |         ^^^^^^^^^^^
     |
note: inside call to <std::cell::UnsafeCell<T>><libc::unix::notbsd::linux::pthread_mutex_t>::get
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/sys/unix/mutex.rs:67:42
     |
67   |         let r = libc::pthread_mutex_lock(self.inner.get());
     |                                          ^^^^^^^^^^^^^^^^
note: inside call to std::sys::imp::mutex::Mutex::lock
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/sys_common/mutex.rs:40:33
     |
40   |     pub unsafe fn lock(&self) { self.0.lock() }
     |                                 ^^^^^^^^^^^^^
note: inside call to std::sys_common::mutex::Mutex::lock
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/sys_common/at_exit_imp.rs:49:13
     |
49   |             LOCK.lock();
     |             ^^^^^^^^^^^
note: inside call to std::sys_common::at_exit_imp::cleanup
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/sys_common/mod.rs:109:9
     |
109  |         at_exit_imp::cleanup();
     |         ^^^^^^^^^^^^^^^^^^^^^^
note: inside call to closure
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/sync/once.rs:227:41
     |
227  |         self.call_inner(false, &mut |_| f.take().unwrap()());
     |                                         ^^^^^^^^^^^^^^^^^^^
note: inside call to closure
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/sync/once.rs:307:21
     |
307  |                     init(state == POISONED);
     |                     ^^^^^^^^^^^^^^^^^^^^^^^
note: inside call to std::sync::Once::call_inner
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/sync/once.rs:227:9
     |
227  |         self.call_inner(false, &mut |_| f.take().unwrap()());
     |         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
note: inside call to std::sync::Once::call_once::<[closure@DefId { krate: CrateNum(1), node: DefIndex(2147489922) => std/fc99636::sys_common[0]::cleanup[0]::{{closure}}[0] }]>
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/sys_common/mod.rs:106:5
     |
106  | /     CLEANUP.call_once(|| unsafe {
107  | |         sys::args::cleanup();
108  | |         sys::stack_overflow::cleanup();
109  | |         at_exit_imp::cleanup();
110  | |     });
     | |______^
note: inside call to std::sys_common::cleanup
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:64:9
     |
64   |         sys_common::cleanup();
     |         ^^^^^^^^^^^^^^^^^^^^^
note: inside call to std::rt::lang_start
    --> /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:32:1
     |
32   | / fn lang_start(main: fn(), argc: isize, argv: *const *const u8) -> isize {
33   | |     use panic;
34   | |     use sys;
35   | |     use sys_common;
...    |
72   | |     }
73   | | }
     | |_^

RalfJung · 2017-09-04T18:31:25Z

Makes me wonder what changed to make this fail now.

oli-obk · 2017-09-04T20:28:28Z

Let's see if it's in tomorrow's nightly. If not, it's related to the build system. I might have screwed up something, not sure.

oli-obk · 2017-09-05T11:22:12Z

I cannot reproduce on today's nightly. That's weird. Rustc master must be doing something different from nightly + xargo

RalfJung · 2017-09-05T16:13:31Z

So if you remove those "disable validation" flags again, do things still work on the CI?

oli-obk · 2017-09-05T16:37:37Z

Probably. But we need them for the rustc integration.

I need to test miri locally in release mode. Maybe that's it. It's the only difference I can see between this and rustc master

RalfJung · 2017-09-05T16:50:49Z

Probably. But we need them for the rustc integration.

That's not really sustainable, is it? When I go about revisiting these disabled tests, if they work locally (which so far has always agreed with CI...), I will enable them again.

I will try to reproduce this.

RalfJung · 2017-09-05T19:44:59Z

I just tried this with latest rustc master (and the patch to make miri compile again):

MIRI_SYSROOT=~/.xargo/HOST cargo run --bin miri -- -Zmir-emit-validate=1 tests/run-pass-fullmir/u128.rs

This works just fine.

EDIT: Same for pointers.rs and unsized-tuple-impls.rs. So, I don't think these new flags should be merged.

oli-obk · 2017-09-05T20:51:41Z

I'll check what's going on. Possible differences:

rustc libs and exe are built with full Mir and validate
miri is built in release mode

Either of these should not make any functional difference in the runtime of miri.

I'll investigate tomorrow

RalfJung · 2017-09-06T08:11:18Z

I built miri in debug mode, so that's not it.

Anyway, until then I will make a PR with just our last commit so that we can get master green again. :)

oli-obk · 2017-09-06T08:17:08Z

I built miri in debug mode, so that's not it.

That's what I meant. rustc builds it in release mode. Anyway, I'm investigating now.

RalfJung · 2017-09-06T08:21:58Z

rustc builds it in release mode.

Ah. Well, but so does our CI.

oli-obk · 2017-09-06T08:22:49Z

Maybe rustc optimizes and thus inlines its MIR?

Edit: fun fact: validation statements increase the inlining cost

oli-obk · 2017-09-06T13:42:56Z

Ok. So I made a diff of the runtime output between nightly and rustc master. The difference is that the rustc master version has way more validation statements. Running on nightly does not produce a single reference to WriteLock in the MIRI_LOG=trace, while on rustc master there are a lot.

~~The diff is not readable due to many reasons, but that was part of what I got from it. I'll need to have a look at why we see different allocation ids.~~

~~Note: there are Validate statements, just not a single rustc_miri::validation trace.~~

Nevermind, I just forgot the -Zmir-emit-validate=1

RalfJung · 2017-09-06T13:49:18Z

Can you get hold of the executed MIR? Are there any differences there?

oli-obk · 2017-09-06T14:37:20Z

The first difference after erasing all hashes and allocids is

< TRACE:rustc_miri::interpret::step:  _ = _
---
> TRACE:rustc_miri::interpret::step:  _ = &_

Where the latter is what happens on rustc master and the first is the nightly version.

I have no clue where in the code that is, since the diff is quite verbose. But we can at least narrow it down to the fact that we are interpreting different MIR.

oli-obk · 2017-09-06T14:44:13Z

Can you get hold of the executed MIR?

Here's all the mir: https://send.firefox.com/download/b2c91e78e1/#sV7oV2sdglrpmvRyi9T_XQ (one time link)

oli-obk · 2017-09-07T13:35:59Z

So the MIR of the program itself doesn't differ. It must be in the libstd.

If I generate libstd via xargo on a stage1 compiler, everything works just like on nightly.
If I use the libstd from the stage1 compiler, I get the failure.

Both times miri was built with the stage1 compiler.

It also only happens if I build the stage1 compiler with the test-miri setting, which doesn't do anything but turn on -Zalways-encode-mir and -Zmir-emit-validate=1.

Any ideas how our libstd build differs from the stage1 libstd build?

RalfJung · 2017-09-07T13:44:10Z

Can you find out which libstd function this first difference you mentioned above is in?

oli-obk · 2017-09-07T13:55:12Z

lang_start https://github.com/rust-lang/rust/blob/master/src/libstd/rt.rs#L57 (just before the catch_unwind call)

RalfJung · 2017-09-07T13:58:34Z

So the MIR of lang_start is different? That should be short enough to have a readable diff, or is it completely different? Then I could also check if I see the same effect.

I am slightly surprised you are getting anywhere with stage 1 compilers; they never worked well for me with miri. Does anything change if you use stage 2?

oli-obk · 2017-09-07T14:35:36Z

Minimal repro:

fn one_line_ref() -> i16 {
    *&1
}

fn main() {
    one_line_ref();
}

Without the one_line_ref call there's no crash

The mir of lang_start in the crashing run is

crashing_mir.txt

The regular mir is

mir_dump_start.txt

The diff is

<         StorageLive(_22);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:13: 59:16
<         StorageLive(_23);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:39: 61:10
<         StorageLive(_24);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:39: 61:10
<         _24 = &_4;                       // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:39: 61:10
<         _23 = [closure];                 // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:39: 61:10
<         StorageDead(_24);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:61:10: 61:10
<         _22 = const std::panic::catch_unwind(_23) -> [return: bb9, unwind: bb10]; // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:19: 61:11
---
>         StorageLive(_22);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:13: 63:16
>         StorageLive(_23);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:39: 63:70
>         StorageLive(_24);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:65: 63:69
>         _24 = _4;                        // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:65: 63:69
>         _23 = const std::intrinsics::transmute(_24) -> bb9; // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:39: 63:70
93,97c91,94
<         Validate(Acquire, [_22: std::result::Result<(), std::boxed::Box<std::any::Any + std::marker::Send + 'static>>]); // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:19: 61:11
<         Validate(Release, [_22: std::result::Result<(), std::boxed::Box<std::any::Any + std::marker::Send + 'static>>]); // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:19: 61:11
<         StorageDead(_23);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:61:11: 61:11
<         EndRegion();                     // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:19: 61:11
<         _25 = const std::sys_common::cleanup() -> [return: bb11, unwind: bb12]; // scope 5 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:64:9: 64:30
---
>         Validate(Acquire, [_23: fn()]);  // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:39: 63:70
>         Validate(Release, [_23: fn()]);  // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:39: 63:70
>         StorageDead(_24);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:70: 63:70
>         _22 = const std::panic::catch_unwind(_23) -> bb10; // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:19: 63:71
101,102c98,101
<         EndRegion();                     // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:19: 61:11
<         goto -> bb5;                     // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:59:19: 61:11
---
>         Validate(Acquire, [_22: std::result::Result<(), std::boxed::Box<std::any::Any + std::marker::Send + 'static>>]); // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:19: 63:71
>         Validate(Release, [_22: std::result::Result<(), std::boxed::Box<std::any::Any + std::marker::Send + 'static>>]); // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:19: 63:71
>         StorageDead(_23);                // scope 4 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:63:71: 63:71
>         _25 = const std::sys_common::cleanup() -> [return: bb11, unwind: bb12]; // scope 5 at /home/ws/ca8159/Projects/rust/rust/src/libstd/rt.rs:64:9: 64:30

oli-obk · 2017-09-07T14:39:59Z

The working version seems to be a horribly old version: rust-lang/rust@ca8b754 (note the transmute in the working version)

Is rustup somehow distributing old sources?

oli-obk · 2017-09-07T14:41:44Z

Nevermind I'm stupid: https://github.com/rust-lang/rust/blame/master/src/libstd/rt.rs#L63

The backtrace features seems to be the difference... Checking what it does if given to xargo...

oli-obk · 2017-09-07T14:46:50Z

@RalfJung That's it! We are reproducible now!

oli-obk · 2017-09-07T15:27:04Z

@RalfJung thanks for being so patient with me on this PR.

Are you ok with merging the test disabling now that it's reproducible?

RalfJung · 2017-09-08T07:40:14Z

This looks good! Thanks for digging to the bottom of this :)

This makes me wonder if there are other features we should enable...

oli-obk changed the title ~~Update pointers.rs~~ Rustup Sep 5, 2017

Make our build work just like the rustc build

79f90d1

oli-obk force-pushed the oli-obk-patch-2 branch from 92a4333 to 79f90d1 Compare September 7, 2017 14:48

Disable validation for some tests

5570a78

RalfJung merged commit 2c4fcd8 into master Sep 8, 2017

RalfJung deleted the oli-obk-patch-2 branch July 16, 2018 07:13

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Rustup #329

Rustup #329

oli-obk commented Sep 4, 2017

RalfJung commented Sep 4, 2017

oli-obk commented Sep 4, 2017

oli-obk commented Sep 5, 2017

RalfJung commented Sep 5, 2017

oli-obk commented Sep 5, 2017

RalfJung commented Sep 5, 2017

RalfJung commented Sep 5, 2017 •

edited

Loading

oli-obk commented Sep 5, 2017

RalfJung commented Sep 6, 2017

oli-obk commented Sep 6, 2017

RalfJung commented Sep 6, 2017

oli-obk commented Sep 6, 2017 •

edited

Loading

oli-obk commented Sep 6, 2017 •

edited

Loading

RalfJung commented Sep 6, 2017

oli-obk commented Sep 6, 2017

oli-obk commented Sep 6, 2017

oli-obk commented Sep 7, 2017

RalfJung commented Sep 7, 2017

oli-obk commented Sep 7, 2017

RalfJung commented Sep 7, 2017 •

edited

Loading

oli-obk commented Sep 7, 2017 •

edited

Loading

oli-obk commented Sep 7, 2017 •

edited

Loading

oli-obk commented Sep 7, 2017

oli-obk commented Sep 7, 2017

oli-obk commented Sep 7, 2017

RalfJung commented Sep 8, 2017

Rustup #329

Rustup #329

Conversation

oli-obk commented Sep 4, 2017

RalfJung commented Sep 4, 2017

oli-obk commented Sep 4, 2017

oli-obk commented Sep 5, 2017

RalfJung commented Sep 5, 2017

oli-obk commented Sep 5, 2017

RalfJung commented Sep 5, 2017

RalfJung commented Sep 5, 2017 • edited Loading

oli-obk commented Sep 5, 2017

RalfJung commented Sep 6, 2017

oli-obk commented Sep 6, 2017

RalfJung commented Sep 6, 2017

oli-obk commented Sep 6, 2017 • edited Loading

oli-obk commented Sep 6, 2017 • edited Loading

RalfJung commented Sep 6, 2017

oli-obk commented Sep 6, 2017

oli-obk commented Sep 6, 2017

oli-obk commented Sep 7, 2017

RalfJung commented Sep 7, 2017

oli-obk commented Sep 7, 2017

RalfJung commented Sep 7, 2017 • edited Loading

oli-obk commented Sep 7, 2017 • edited Loading

oli-obk commented Sep 7, 2017 • edited Loading

oli-obk commented Sep 7, 2017

oli-obk commented Sep 7, 2017

oli-obk commented Sep 7, 2017

RalfJung commented Sep 8, 2017

RalfJung commented Sep 5, 2017 •

edited

Loading

oli-obk commented Sep 6, 2017 •

edited

Loading

oli-obk commented Sep 6, 2017 •

edited

Loading

RalfJung commented Sep 7, 2017 •

edited

Loading

oli-obk commented Sep 7, 2017 •

edited

Loading

oli-obk commented Sep 7, 2017 •

edited

Loading