Rapier Physics example blocks runtime init

[Meziu]

Continuing off #56 discussions.
@ian-h-chamberlain @AzureMarker

The new example in the test/rapier-physics branch doesn’t run correctly.

While the actual panic (which catches a potential ARM Exception) is situated in the thread_info::set function in std, the actual problem is only present when a specific function call from the rapier2d crate is present, and only at opt-level = 0, in either release or debug mode.

We can thus speculate it’s either an issue with optimisations during the compilation process, a stack fault, or an overflow in the thread_local storage.

[Meziu]

@ian-h-chamberlain about the last message you sent in #56, I want to say it actually would cause a segmentation fault if it weren’t for a check in the code (rtassert!) that, seeing the bad initialisation, panics the program. I’ve tried removing the check and it does throw an ARM Exception just the line after, so it doesn’t have a “different nature” as an error itself.

[AzureMarker]

I don't think it's possible for it to be a stack issue, right? This is happening before the stack even reaches main (and the stack at that point shouldn't be affected by anything main and beyond does).

[Meziu]

I don't think it's possible for it to be a stack issue, right? This is happening before the stack even reaches main (and the stack at that point shouldn't be affected by anything main and beyond does).

Yeah, but I have no idea how a non-executed line could propagate an error all the way to the std, so I just made hypotheses.

[ian-h-chamberlain]

Just for everyone's reference, I made a repo for the method I used to debug the regex case: https://github.com/ian-h-chamberlain/3ds-codegen-crash-repro

It's kind of a brain dump of notes but maybe you'll find it useful. I'm going to see if I can reuse it on this example as well.

Edit: also, I'm running on macOS so it's possible some parts of the bisect script aren't 100% portable, and it also relies on a prebuild std for the 3DS instead of -Zbuild-std.

[ian-h-chamberlain]

Okay, I was able to bisect down to a single optimization pass on my system, using this code:

use std::time::Duration;

use ctru::console::Console;
use ctru::gfx::Gfx;

use rapier2d::prelude::*;

fn main() {
    ctru::init();

    let gfx = Gfx::init().expect("Couldn't obtain GFX controller");
    let _console = Console::init(gfx.top_screen.borrow_mut());

    let mut collider_set = ColliderSet::new();

    /* Create the ground. */
    let collider = ColliderBuilder::cuboid(100.0, 0.1).build();
    collider_set.insert(collider);

    println!("Done!");
    gfx.flush_buffers();
    gfx.swap_buffers();

    // So we can see the program got past the crash
    std::thread::sleep(Duration::from_secs(2));
}

Attempting 37953 passes
+ RUSTFLAGS='-C opt-level=1 -C debuginfo=0 -C codegen-units=1 -C lto=off -C llvm-args=-opt-bisect-limit=37953'
+ cargo -v rustc --target armv6k-nintendo-3ds --target-dir=target-repro
Sending crash-repro.3dsx, 567352 bytes
266001 sent (46.88%), 24 blocks
Did it crash? [y/n] n
Attempting 37952 passes
+ RUSTFLAGS='-C opt-level=1 -C debuginfo=0 -C codegen-units=1 -C lto=off -C llvm-args=-opt-bisect-limit=37952'
+ cargo -v rustc --target armv6k-nintendo-3ds --target-dir=target-repro
Sending crash-repro.3dsx, 588584 bytes
275711 sent (46.84%), 24 blocks
Did it crash? [y/n] y
Final pass was: 37952

These are the candidate passes that actually had that number associated with them:

BISECT: running pass (37953) ARM Instruction Selection on function (<alloc::sync::Weak<T> as core::ops::drop::Drop>::drop)
BISECT: running pass (37953) SCCPPass on core::mem::manually_drop::ManuallyDrop<T>::into_inner
BISECT: running pass (37953) SROAPass on core::ptr::const_ptr::<impl *const T>::offset
BISECT: running pass (37953) Simplify the CFG on function (core::ptr::drop_in_place<std::ffi::os_str::OsString>)
BISECT: running pass (37953) Machine Copy Propagation Pass on function (<num_rational::Ratio<isize> as num_traits::cast::FromPrimitive>::from_u64)
BISECT: running pass (37953) SROAPass on <I as core::iter::traits::collect::IntoIterator>::into_iter
BISECT: running pass (37953) IPSCCPPass on [module]
BISECT: running pass (37953) SimplifyCFGPass on rapier2d::counters::Counters::set_nconstraints

Anything look suspicious on first glance? My first though is maybe something to do with the drop impls, or perhaps the IPSCCPPass on [module] since that could theoretically affect the whole program? I don't see anything do with threads unfortunately, which would probably make it more obvious.

The next step, I suppose, would be to try and look at the LLVM IR before + after this pass for each of those affected functions, and try to see if any of them look like they might be related to the crash.

[AzureMarker]

Thanks for taking a look at this. I'm interested in exploring another thread, which is if the static memory for the thread info gets set correctly. Last I looked at the LLVM IR, it was set correctly, but wasn't set correctly by the time of the crash (it was zeroed out, but it should have a non-zero byte to indicate the Option is None).

[AzureMarker]

After rebasing the std and threads PR, updating dependencies, and merging master into test/rapier-physics, I now see a full ARM exception when running the example in debug mode:

This failure happens a little earlier than thread::set:

[AzureMarker]

Actually, this may just be an issue in the new std changes or pthread_3ds:

[AzureMarker]

Pushed a fix in rust-lang/rust@836146c. Now it's back to the original issue.

[Meziu]

@ian-h-chamberlain are you sure those are the correct opt passes to cause the crash? Using your same parameters the app did’t crash to me…

[ian-h-chamberlain]

@ian-h-chamberlain are you sure those are the correct opt passes to cause the crash? Using your same parameters the app did’t crash to me…

@Meziu the exact number will probably depend on your rustc + std (I had a prebuilt std in my case). You might be able to find the pass number on your setup by setting the same RUSTFLAGS but use -opt-bisect-limit=-1 and grep the output for the pass descriptions I posted above, then try again with the number you end up with.

Also make sure you cargo clean before the build, otherwise only the "changed" crates will be optimized and the pass numbers will look different as well.

If none of that works, you could always try the bisect-repro.sh script from my repo https://github.com/ian-h-chamberlain/3ds-codegen-crash-repro – but be aware it takes a while, I think ~18 builds from scratch are needed to bisect the issue (and you have to manually reset the 3DS and provide input to the script 😔).

[Meziu]

I absolutely cannot check this issue the way @ian-h-chamberlain did. It is great how much effort you've put, but sadly my cpu is just way too slow for the building process (build and rebuild on an Intel i5 M520) (yes i live in 2010).

I'm not even sure how to tackle the problem honestly. Looking at the whole "idea" of an optimization pass and how they are handled it makes little sense to me the presence of one function changes the machine code of another. Maybe we still aren't understanding this problem correctly, just as the regex was linked to something different (stack size) that was masked only when a specific amount of optimizations were done, maybe something similar is linked to our issue.

[Meziu]

I've just done a simple test I couldn't do before (especially for @AzureMarker). I've tried running the main directly without any of the rt::lang_start code. While I had to remove the ctru::panic_handler since ThreadLocals weren't accessible anymore, the rest of the code (especially rapier2d) works fine, so I can confirm that crate doesn't use ThreadLocals at any point. This also implies I have no idea why this whole problem even exists.

[Meziu]

I’ve started looking into the rapier2d code that caused the problem, and the issue seems to go and come if I just cut out some function calls.

E.G.
Removing the call to SharedShape::cuboid (inside the ColliderBuilder code) actually solves the issue, yet it looks like removing the actual code inside SharedShape::cuboid doesn’t change anything.

I am still confused and unsure. It is a bit irrational so I don’t know if I checked everything, but it looks to be that way. @ian-h-chamberlain how did you check the stack in the regex example?

[ian-h-chamberlain]

I am still confused and unsure. It is a bit irrational so I don’t know if I checked everything, but it looks to be that way. @ian-h-chamberlain how did you check the stack in the regex example?

The biggest clue I noticed was using gdb and seeing that &self was set to 0x0, e.g. what I wrote in #56 (comment)
Also, when I got Luma3ds crash dumps, the Stack dump: section would always be empty, and the crash would be an invalid write to the stack.

The crash in that case occurred immediately afterwards, since I think it was attempting to dereference the null frame pointer. I don't fully understand how that would happen, but those were some of the signs of a corrupt / invalid stack.

Removing the call to SharedShape::cuboid (inside the ColliderBuilder code) actually solves the issue, yet it looks like removing the actual code inside SharedShape::cuboid doesn’t change anything.

This is pretty interesting, it would seem to suggest that simply calling the function (modifying the stack pointer, I guess) is the cause of the problem, rather than any specific code in the function? How deep is the call stack if you put a breakpoint there?