lto = "thin" causes doctest to generate invalid code on rust-1.57

[trofi]

It's a senf-contained example extracted from rayon-rs/rayon#911 where doctest tests mysteriously crash rav1e. This is what crashes for me:

// cat src/lib.rs
thread_local! {
    static THREAD_LOCAL_GLOBAL: std::cell::Cell<usize> = std::cell::Cell::new(0);
}

#[inline(never)]
fn set_state_func(t: &std::cell::Cell<usize>) {
    t.set(42);
}

#[inline(never)]
fn thread_func() {
    THREAD_LOCAL_GLOBAL.with(set_state_func);
}

/// # Examples
///
/// ```
/// use bug::do_bug;
///
/// # fn main() {
/// bug::do_bug()
/// # }
/// ```
#[inline(never)]
pub fn do_bug() {
  // to ease catching the test with gdb
  //std::thread::sleep(std::time::Duration::from_secs(10));

  for _ in 0..128 {
    std::thread::spawn(thread_func).join().unwrap();
  }
}

It needs the following Cargo.toml:

# cat Cargo.toml
[package]
name = "bug"
version = "0.1.0"
edition = "2018"

[profile.dev]
debug = true
incremental = true
lto = "thin"
opt-level = 2
debug-assertions = false
overflow-checks = false
codegen-units = 256

Running the test:

$ cargo test --doc --verbose
   Compiling bug v0.1.0 (/home/slyfox/dev/git/rav1e)
     Running `rustc --crate-name bug --edition=2018 src/lib.rs --error-format=json --json=diagnostic-rendered-ansi --crate-type lib --emit=dep-info,metadata,link -C opt-level=2 -C linker-plugin-lto -C codegen-units=256 -C debuginfo=2 -C metadata=08626d1130101a14 -C extra-filename=-08626d1130101a14 --out-dir /home/slyfox/dev/git/rav1e/target/debug/deps -C incremental=/home/slyfox/dev/git/rav1e/target/debug/incremental -L dependency=/home/slyfox/dev/git/rav1e/target/debug/deps`
    Finished test [optimized + debuginfo] target(s) in 0.15s
   Doc-tests bug
     Running `rustdoc --edition=2018 --crate-type lib --crate-name bug --test /home/slyfox/dev/git/rav1e/src/lib.rs -L dependency=/home/slyfox/dev/git/rav1e/target/debug/deps -L dependency=/home/slyfox/dev/git/rav1e/target/debug/deps --extern bug=/home/slyfox/dev/git/rav1e/target/debug/deps/libbug-08626d1130101a14.rlib -C lto=thin --error-format human`

running 1 test
test src/lib.rs - do_bug (line 17) ... FAILED

failures:

---- src/lib.rs - do_bug (line 17) stdout ----
Test executable failed (terminated by signal).


failures:
    src/lib.rs - do_bug (line 17)

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.35s

error: test failed, to rerun pass '--doc'

I expected to see this happen: test should pass and not crash.

Instead, this happened: test crashes mysteriously.

Meta

rustc --version --verbose:

rustc --version --verbose
rustc 1.57.0
binary: rustc
commit-hash: unknown
commit-date: unknown
host: x86_64-unknown-linux-gnu
release: 1.57.0
LLVM version: 13.0.0

Backtrace

Thread 2 "rust_out" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ff5caf23640 (LWP 2280238)]
0x0000000000000000 in ?? ()
(gdb) bt
#0  0x0000000000000000 in ?? ()
#1  0x00007ff5caf235f8 in ?? ()
#2  0x000000008498015f in ?? ()
#3  0x0000559d328efdd6 in core::ops::function::FnOnce::call_once<fn(), ()> ()
    at /build/rustc-1.57.0-src/library/core/src/ops/function.rs:227
#4  std::sys_common::backtrace::__rust_begin_short_backtrace<fn(), ()> (f=<optimized out>)
    at /build/rustc-1.57.0-src/library/std/src/sys_common/backtrace.rs:123
#5  0x0000559d328efe40 in std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked::{closure#1}::{closure#0}>, ()> (data=<optimized out>) at /build/rustc-1.57.0-src/library/std/src/panicking.rs:403
#6  std::panicking::try<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked::{closure#1}::{closure#0}>> (f=...) at /build/rustc-1.57.0-src/library/std/src/panicking.rs:367
#7  0x0000559d328efa11 in std::thread::{impl#0}::spawn_unchecked::{closure#1}<fn(), ()> ()
    at /build/rustc-1.57.0-src/library/std/src/thread/mod.rs:482
#8  core::ops::function::FnOnce::call_once<std::thread::{impl#0}::spawn_unchecked::{closure#1}, ()> ()
    at /build/rustc-1.57.0-src/library/core/src/ops/function.rs:227
#9  0x0000559d329603d5 in std::sys::unix::thread::Thread::new::thread_start ()
#10 0x00007ff5cb0fbd40 in start_thread () from /nix/store/s9qbqh7gzacs7h68b2jfmn9l6q4jwfjz-glibc-2.33-59/lib/libpthread.so.0
#11 0x00007ff5cb02343f in clone () from /nix/store/s9qbqh7gzacs7h68b2jfmn9l6q4jwfjz-glibc-2.33-59/lib/libc.so.6

[trofi]

Also tried rust nightly on Ubuntu 21.10. Same crash.

rustc 1.60.0-nightly (1bd4fdc94 2022-01-12)
binary: rustc
commit-hash: 1bd4fdc943513e1004f498bbf289279c9784fc6f
commit-date: 2022-01-12
host: x86_64-unknown-linux-gnu
release: 1.60.0-nightly
LLVM version: 13.0.0

[Patrick-Poitras]

Can replicate on windows-msvc

rustc 1.60.0-nightly (1bd4fdc94 2022-01-12)
binary: rustc
commit-hash: 1bd4fdc943513e1004f498bbf289279c9784fc6f
commit-date: 2022-01-12
host: x86_64-pc-windows-msvc
release: 1.60.0-nightly
LLVM version: 13.0.0

[Patrick-Poitras]

Regression in a16f686e4a0ea15dcd3b5aa3db7b1cba27bb9453 according to bisect-rustc.

[cuviper]

Bisect is pointing you to #89802, but the similar #91671 found that this was because Cargo changed whether LTO is applied to doctests. The actual compiler issue is probably a more general LTO thing, not Cargo's fault.

On the rayon issue I supposed that this might have the same root cause as #91671, but the symptoms are different.

[cuviper]

Here's the codegen I get:

0000000000007010 <std::thread::local::LocalKey<T>::with>:
    7010:	48 83 ec 18          	sub    $0x18,%rsp
    7014:	ff 17                	call   *(%rdi)
    7016:	48 89 44 24 08       	mov    %rax,0x8(%rsp)
    701b:	48 83 f8 00          	cmp    $0x0,%rax
    701f:	75 2a                	jne    704b <std::thread::local::LocalKey<T>::with+0x3b>
    7021:	48 8d 3d 2c 50 08 00 	lea    0x8502c(%rip),%rdi        # 8c054 <anon.dda6e9c32c792d26f11e51339977f165.0.llvm.9859745662360967200>
    7028:	48 8d 0d 21 04 09 00 	lea    0x90421(%rip),%rcx        # 97450 <anon.dda6e9c32c792d26f11e51339977f165.3.llvm.9859745662360967200>
    702f:	4c 8d 05 02 04 09 00 	lea    0x90402(%rip),%r8        # 97438 <anon.dda6e9c32c792d26f11e51339977f165.2.llvm.9859745662360967200>
    7036:	48 8d 05 33 2f 00 00 	lea    0x2f33(%rip),%rax        # 9f70 <core::result::unwrap_failed>
    703d:	be 46 00 00 00       	mov    $0x46,%esi
    7042:	48 8d 54 24 10       	lea    0x10(%rsp),%rdx
    7047:	ff d0                	call   *%rax
    7049:	0f 0b                	ud2    
    704b:	48 8b 7c 24 08       	mov    0x8(%rsp),%rdi

0000000000007050 <alloc::raw_vec::RawVec<T,A>::current_memory>:
[...]

0000000000007980 <bug::thread_func>:
    7980:	48 8d 3d e9 fa 08 00 	lea    0x8fae9(%rip),%rdi        # 97470 <anon.dda6e9c32c792d26f11e51339977f165.3.llvm.9859745662360967200+0x20>
    7987:	e9 84 f6 ff ff       	jmp    7010 <std::thread::local::LocalKey<T>::with>
    798c:	0f 1f 40 00          	nopl   0x0(%rax)

So thread_func does a tail-call jump to LocalKey::with, then that jumps over the unwrap_failed code to 704b where it falls into the following unrelated function.

[filip-hejsek]

The crate is compiled with -C opt-level=2 but the doctest is compiled with no optimization. Compiling the doctest with -C opt-level=2 fixes the problem. Is mixing optimization levels in a single LTO build supposed to work?

[trofi]

Fixing option mismatch between doctest and cargo test would certainly help in debugging similar failures in downstream packages. So far people frequently attribute failures to doctest itself. I don't know if option mismatch is intentional or accidental.

Generally I would expect LTO to allow mixing different but ABI-compatible optimization levels. I don't know what docs say to guarantee.

[filip-hejsek]

Here is a simpler program (no real thread locals) which also reproduces the issue:

mod fake_thread_local {
    pub struct LocalKey<T: 'static> {
        pub get_value: fn() -> Option<&'static T>,
    }
    impl<T: 'static> LocalKey<T> {
        pub fn with<F, R>(&'static self, f: F) -> R
        where
            F: FnOnce(&T) -> R,
        {
            self.try_with(f).expect("")
        }

        #[inline]
        pub fn try_with<F, R>(&'static self, f: F) -> Option<R>
        where
            F: FnOnce(&T) -> R,
        {
            let fake_thread_local = (self.get_value)()?;
            Some(f(fake_thread_local))
        }
    }
}

fn get_value() -> Option<&'static ()> {
    Some(&())
}

const THREAD_LOCAL_GLOBAL: fake_thread_local::LocalKey<()> = fake_thread_local::LocalKey { get_value };

#[inline(never)]
fn set_state_func(_: &()) {
}


/// # Examples
///
/// ```
/// # fn main() {
/// bug::do_bug()
/// # }
/// ```
#[inline(never)]
pub fn do_bug() {
    THREAD_LOCAL_GLOBAL.with(set_state_func);
}

rustc 1.60.0-nightly (ec4bcaac4 2022-01-15)
binary: rustc
commit-hash: ec4bcaac450279b029f3480b8b8f1b82ab36a5eb
commit-date: 2022-01-15
host: x86_64-unknown-linux-gnu
release: 1.60.0-nightly
LLVM version: 13.0.0

[cuviper]

Is mixing optimization levels in a single LTO build supposed to work?

I think that has to be supported, because the prebuilt standard library may already have different options than your project.

[filip-hejsek]

I think i narrowed down the problem to a llvm codegen issue. The problem can be reproduced with this file: bug.ll.gz. Compiling with llc bug.ll -filetype=obj -O=0 results in wrong assembly:

0000000000000000 <_ZN3bug17fake_thread_local17LocalKey$LT$T$GT$4with17hc98bdf741300d0b2E>:
   0:	50                   	push   %rax
   1:	ff 17                	call   *(%rdi)
   3:	48 89 04 24          	mov    %rax,(%rsp)
   7:	48 83 f8 00          	cmp    $0x0,%rax
   b:	75 1e                	jne    2b <_ZN3bug17fake_thread_local17LocalKey$LT$T$GT$4with17hc98bdf741300d0b2E+0x2b>
   d:	48 bf 00 00 00 00 00 	movabs $0x0,%rdi
  14:	00 00 00 
  17:	31 c0                	xor    %eax,%eax
  19:	89 c6                	mov    %eax,%esi
  1b:	48 ba 00 00 00 00 00 	movabs $0x0,%rdx
  22:	00 00 00 
  25:	ff 15 00 00 00 00    	call   *0x0(%rip)        # 2b <_ZN3bug17fake_thread_local17LocalKey$LT$T$GT$4with17hc98bdf741300d0b2E+0x2b>
  2b:	48 8b 3c 24          	mov    (%rsp),%rdi

[nikic]

Further reduced: https://gist.github.com/nikic/b6c45e5eeac03ef1fd842353815ceba4

It seems like all this takes is the combination of a tail call followed by dbg.value and FastISel :/

[nikic]

Filed llvm/llvm-project#53243.

[apiraino]

Assigning priority as discussed in the Zulip thread of the Prioritization Working Group.

@rustbot label -I-prioritize +P-high

[nikic]

The fix has been pulled in by the LLVM 14 upgrade. I've verified this works on beta.

[trofi]

Would it be fair to say it's a cargo bug that doctest and standard cargo test binaries use different optimization options and make this bug somewhat unique to doctest?