wasm32-wasip2 spins on pthread_key_delete

[Mark-Simulacrum]

I'm working on the wasm proc macros (so it's possible I messed something up in wasmtime bindings or similar), and I'm encountering an infinite loop on some of the wasm executions with this stack:

__pthread_key_delete
<std::sys::thread_local::key::racy::LazyKey>::lazy_init
std::sys::thread_local::destructors::list::register
<std::sys::thread_local::native::lazy::Storage<core::cell::RefCell<proc_macro::bridge::symbol::Interner>, ()>>::get_or_init_slow::<proc_macro::bridge::symbol::INTERNER::__rust_std_internal>
<proc_macro::bridge::symbol::Symbol>::new

After inserting some dbg! into the std thread local implementation it looks like we're seeing this sequence:

• lazy_init()
• pthread_key_create() = 0
• pthread_key_create() = 1, called because 0 is the sentinel value (

  rust/library/std/src/sys/thread_local/key/racy.rs

  Line 25 in 969b803

  const KEY_SENTVAL: usize = 0;

  )
• pthread_key_delete(0), which appears to spin (~100% CPU in wasmtime, although I'm having trouble debugging why)

Unfortunately I can't seem to reproduce this outside of my proc macro setting... in a standalone program a thread local seems to register just fine. Maybe it has to do with the number of thread locals or something like that? The proc macro spinning appears fixed if I revert #159733, however, so I suspect there's some kind of bug here. At minimum, it seems like we might want to redefine SENTVAL since it looks like the wasi libc does return 0 -- that I can reproduce in and out of proc macro setting.

I think we are in this loop: https://github.com/WebAssembly/wasi-libc/blob/8d8348ec24253d0638a693b8af82445c13d92d32/libc-top-half/musl/src/thread/common/pthread_key_create.c#L69-L70, here is the assembly (generated by wasmtime at runtime) I've managed to collect by single-stepping in gdb (my gdb has a tendency to segfault though when trying to do anything too advanced in this code, but I think this is an accurate trace, and it seems to reproduce across multiple compilations):

=> 0x7f6d861f5e16 <__pthread_key_delete+86>:    mov    eax,esi
=> 0x7f6d861f5e18 <__pthread_key_delete+88>:    lea    rcx,[r12+rax*1]
=> 0x7f6d861f5e1c <__pthread_key_delete+92>:    mov    rdx,r13
=> 0x7f6d861f5e1f <__pthread_key_delete+95>:    add    edx,DWORD PTR [rcx+0x44]
=> 0x7f6d861f5e22 <__pthread_key_delete+98>:    mov    DWORD PTR [r12+rdx*1],0x0
=> 0x7f6d861f5e2a <__pthread_key_delete+106>:   mov    esi,DWORD PTR [r12+rax*1+0x8]
=> 0x7f6d861f5e2f <__pthread_key_delete+111>:   cmp    esi,0x104ae0
=> 0x7f6d861f5e35 <__pthread_key_delete+117>:   jne    0x7f6d861f5e16 <__pthread_key_delete+86>

cc @alexcrichton as you filed the PR seemingly introducing this in case you have any ideas. I think I'm building against wasi-sdk 33, which appears to be the same as the CI SDK.

[Mark-Simulacrum]

Cutting this so we have a record of it, I'll try to debug some more to figure out how to work around it / fix it, but seems useful to have an issue in case others hit the same problem.

[bjorn3]

I hit what seems to be the same bug on wasm32-wasip1 with my rebase of #157709. (backtrace is after switching to wasmtime and enabling dwarf debuginfo generation)

(gdb) bt
#0  __pthread_key_delete (k=<optimized out>) at wasisdk://v33.0+m/src/wasi-libc/libc-top-half/musl/src/thread/common/pthread_key_create.c:70
#1  0x00007fffd001c77c in lazy_init () at library/std/src/sys/thread_local/key/unix.rs:48
#2  0x00007fffd001cace in register () at library/std/src/sys/thread_local/key/racy.rs:40
#3  0x00007fffd000f5a3 in get_or_init_slow<core::cell::RefCell<proc_macro::bridge::symbol::Interner>, (), fn() -> core::cell::RefCell<proc_macro::bridge::symbol::Interner>> ()
    at library/std/src/sys/thread_local/native/lazy.rs:17
#4  0x00007fffd00113f8 in invalidate_all () at library/std/src/sys/thread_local/native/lazy.rs:62
#5  0x00007fffd000bb71 in _RNCINvNtNtCsIYBRbPrXGT_10proc_macro6bridge6client10run_clientNtB8_11TokenStreamNvCsjMYHx84ouer_8rust_out3fooE0B1h_ (
    var0=<error reading variable: Could not find the frame base for "_RNCINvNtNtCsIYBRbPrXGT_10proc_macro6bridge6client10run_clientNtB8_11TokenStreamNvCsjMYHx84ouer_8rust_out3fooE0B1h_".>)
    at rust_out.wasm:5115
#6  0x00007fffd000b9a4 in _RNvXsl_NtNtCsiEGvr444x80_4core5panic11unwind_safeINtB5_16AssertUnwindSafeNCINvNtNtCsIYBRbPrXGT_10proc_macro6bridge6client10run_clientNtB1i_11TokenStreamNvCsjMYHx84ouer_8rust_out3fooE0EINtNtNtB9_3ops8function6FnOnceuE9call_onceB2s_ (var0=<optimized out>) at rust_out.wasm:4936
#7  0x00007fffd000abe1 in _RINvNvNtCs5YHrBOQRldh_3std9panicking12catch_unwind7do_callINtNtNtCsiEGvr444x80_4core5panic11unwind_safe16AssertUnwindSafeNCINvNtNtCsIYBRbPrXGT_10proc_macro6bridge6client10run_clientNtB24_11TokenStreamNvCsjMYHx84ouer_8rust_out3fooE0EB2T_EB3e_ (var0=1048304) at rust_out.wasm:2893
#8  0x00007fffd000aaba in _RINvNtCs5YHrBOQRldh_3std9panicking12catch_unwindNtCsIYBRbPrXGT_10proc_macro11TokenStreamINtNtNtCsiEGvr444x80_4core5panic11unwind_safe16AssertUnwindSafeNCINvNtNtBM_6bridge6client10run_clientBK_NvCsjMYHx84ouer_8rust_out3fooE0EEB36_ (var0=1048392, var1=<optimized out>) at rust_out.wasm:2657
#9  0x00007fffd000b2e4 in _RINvNtNtCsIYBRbPrXGT_10proc_macro6bridge6client10run_clientNtB6_11TokenStreamNvCsjMYHx84ouer_8rust_out3fooEB1f_ (var0=1048524, var1=<optimized out>)
    at rust_out.wasm:3657
#10 0x00007fffd000bacf in _RNCINvMsg_NtNtCsIYBRbPrXGT_10proc_macro6bridge6clientNtB8_6Client7expand1NvCsjMYHx84ouer_8rust_out3fooE0B1b_ (var0=0, var2=-1107296256) at rust_out.wasm:5065
#11 0x00007fffd000ba61 in _RINvNvNtNtCsIYBRbPrXGT_10proc_macro6bridge14selfless_reify31reify_to_extern_c_fn_hrt_bridge7wrapperNtNtB6_6buffer6BufferNCINvMsg_NtB6_6clientNtB23_6Client7expand1NvCsjMYHx84ouer_8rust_out3fooE0EB2C_ (var0=0, var1=<optimized out>) at rust_out.wasm:5040
#12 0x00007fffd0018457 in __rustc_proc_macro_call_client () at library/proc_macro/src/bridge/client.rs:347
#13 0x00007fffd0033311 in __rustc_proc_macro_call_client.command_export (var0=0, var1=-1107296256) at rust_out.wasm:95246

[bjorn3]

cc @alexcrichton

[alexcrichton]

I can reproduce this with:

#[unsafe(no_mangle)]
pub extern "C" fn foo() {
    unsafe {
        let mut a = 0;
        assert_eq!(libc::pthread_key_create(&mut a, Some(dtor)), 0);
        let mut b = 0;
        assert_eq!(libc::pthread_key_create(&mut b, Some(dtor)), 0);
        assert_eq!(libc::pthread_key_delete(a), 0);
    }
}

extern "C" fn dtor(_ptr: *mut libc::c_void) {}

and

$ cargo build --target wasm32-wasip1 && wasmtime --invoke foo ./target/wasm32-wasip1/debug/wat.wasm

Definitely ok to revert #159733 for now for your PR @Mark-Simulacrum, and once I figure out what's going on I'll figure out if a revert on main is also needed.

[alexcrichton]

Ok this bug is already fixed in upstream wasi-libc which will get published as wasi-sdk-34. I've added a regression test upstream as part of WebAssembly/wasi-libc#863, and confirmed that the test fails with wasi-sdk-33 sources (which is what rust-lang/rust is using).

I've pushed up #160868 to fix this for rust-lang/rust, effectively reverting the original change for wasip1/wasip2 targets.