Actions
Bug #20243
open
M:N threading VM_ASSERT failure in rb_current_execution_context with clang 17 (on Linux)
Description
When building with Clang 17 and -DVM_CHECK_MODE=1 (with the following configure)
optflags="-ggdb3 -fno-omit-frame-pointer -fno-optimize-sibling-calls -O3" cflags="-DVM_CHECK_MODE=1" CC=clang ../configure --prefix=/home/kj/ruby/installed --enable-yjit=dev --disable-install-doc
And then running the following script with the built ./miniruby (which is actually from bootstraptest/test_ractor.rb):
counts = []
counts << Ractor.count
ractors = (1..3).map { Ractor.new { Ractor.receive } }
counts << Ractor.count
ractors[0].send('End 0').take
sleep 0.1 until ractors[0].inspect =~ /terminated/
counts << Ractor.count
ractors[1].send('End 1').take
sleep 0.1 until ractors[1].inspect =~ /terminated/
counts << Ractor.count
ractors[2].send('End 2').take
sleep 0.1 until ractors[2].inspect =~ /terminated/
counts << Ractor.count
counts.inspect
I get the following crash:
Assertion Failed: ../vm_core.h:1957:rb_current_execution_context:ec == rb_current_ec_noinline()
ruby 3.4.0dev (2024-02-07T07:52:06Z ktsanaktsidis/igno.. 5cc6d944c2) [x86_64-linux]
-- Control frame information -----------------------------------------------
c:0003 p:0003 s:0010 e:000009 METHOD <internal:ractor>:431
c:0002 p:0004 s:0006 e:000005 BLOCK ractor_crash.rb:3 [FINISH]
c:0001 p:---- s:0003 e:000002 DUMMY [FINISH]
-- Ruby level backtrace information ----------------------------------------
ractor_crash.rb:3:in `block (2 levels) in <main>'
<internal:ractor>:431:in `receive'
-- Threading information ---------------------------------------------------
Total ractor count: 2
Ruby thread count for this ractor: 1
-- C level backtrace information -------------------------------------------
/home/kj/ruby/build/miniruby(rb_print_backtrace+0x14) [0x55faa97a4ebd] ../vm_dump.c:820
/home/kj/ruby/build/miniruby(rb_vm_bugreport) ../vm_dump.c:1151
/home/kj/ruby/build/miniruby(rb_assert_failure+0x81) [0x55faa94d2719] ../error.c:1131
./miniruby(thread_sched_wait_running_turn+0x2e9) [0x55faa9726f59]
/home/kj/ruby/build/miniruby(rb_ractor_sched_sleep+0x10b) [0x55faa972687b] ../thread_pthread.c:1348
/home/kj/ruby/build/miniruby(ractor_check_ints+0x0) [0x55faa968b328] ../ractor.c:683
/home/kj/ruby/build/miniruby(ractor_sleep_with_cleanup) ../ractor.c:684
/home/kj/ruby/build/miniruby(ractor_sleep+0x15) [0x55faa968adf4] ../ractor.c:701
/home/kj/ruby/build/miniruby(ractor_wait_receive) ../ractor.c:748
/home/kj/ruby/build/miniruby(ractor_receive+0x1f) [0x55faa968768e] ../ractor.c:762
/home/kj/ruby/build/miniruby(builtin_inline_class_431) ../ractor.rb:432
/home/kj/ruby/build/miniruby(builtin_invoker0+0x6) [0x55faa978fc66] ../vm_insnhelper.c:6746
/home/kj/ruby/build/miniruby(invoke_bf+0x39) [0x55faa979816e] ../vm_insnhelper.c:6886
/home/kj/ruby/build/miniruby(vm_invoke_builtin_delegate) ../vm_insnhelper.c:6909
/home/kj/ruby/build/miniruby(rb_vm_check_ints+0x0) [0x55faa9771fac] ../insns.def:1533
/home/kj/ruby/build/miniruby(vm_pop_frame) ../vm_insnhelper.c:419
/home/kj/ruby/build/miniruby(vm_exec_core) ../insns.def:1537
/home/kj/ruby/build/miniruby(vm_exec_loop+0x0) [0x55faa9767f02] ../vm.c:2489
/home/kj/ruby/build/miniruby(rb_vm_exec) ../vm.c:2492
/home/kj/ruby/build/miniruby(invoke_block+0x6f) [0x55faa9781a58] ../vm.c:1512
/home/kj/ruby/build/miniruby(invoke_iseq_block_from_c) ../vm.c:1582
/home/kj/ruby/build/miniruby(invoke_block_from_c_proc) ../vm.c:1680
/home/kj/ruby/build/miniruby(vm_invoke_proc) ../vm.c:1710
/home/kj/ruby/build/miniruby(rb_vm_invoke_proc_with_self+0x5a) [0x55faa9781eaa] ../vm.c:1745
/home/kj/ruby/build/miniruby(thread_do_start_proc+0x199) [0x55faa9739e19] ../thread.c:574
/home/kj/ruby/build/miniruby(thread_do_start+0x6c) [0x55faa973933f] ../thread.c:618
/home/kj/ruby/build/miniruby(thread_start_func_2) ../thread.c:668
/home/kj/ruby/build/miniruby(rb_native_mutex_lock+0x0) [0x55faa973a141] ../thread_pthread.c:2234
/home/kj/ruby/build/miniruby(thread_sched_lock_) ../thread_pthread.c:387
/home/kj/ruby/build/miniruby(call_thread_start_func_2) ../thread_pthread_mn.c:436
/home/kj/ruby/build/miniruby(co_start) ../thread_pthread_mn.c:434
The failing assertion is this one in vm_core.h: https://github.com/ruby/ruby/blob/42c36269403baac67b0d5dc1d6d6e31168cf6a1f/vm_core.h#L1957. It actually has a very helpful comment.
/* On the shared objects, `__tls_get_addr()` is used to access the TLS
* and the address of the `ruby_current_ec` can be stored on a function
* frame. However, this address can be mis-used after native thread
* migration of a coroutine.
* 1) Get `ptr =&ruby_current_ec` op NT1 and store it on the frame.
* 2) Context switch and resume it on the NT2.
* 3) `ptr` is used on NT2 but it accesses to the TLS on NT1.
* This assertion checks such misusage.
*
* To avoid accidents, `GET_EC()` should be called once on the frame.
* Note that inlining can produce the problem.
*/
VM_ASSERT(ec == rb_current_ec_noinline());
What seems to be happening is exactly that. This is a disassembly of the relevant bits of thread_sched_wait_running_turn:
........
# This is the only bits of the entire function which access the TLS base register %fs.
# It seems to have spilled the value of ruby_current_ec into %r13.
0x000055603d2e1cf8 <+136>: mov $0xffffffffffffff90,%rax
0x000055603d2e1cff <+143>: mov %fs:0x0,%r12
0x000055603d2e1d08 <+152>: add %rax,%r12
0x000055603d2e1d0b <+155>: mov %fs:(%rax),%r13
........
# There's a call to coroutine_transfer, so after this point we're returned to on a
# different thread
0x000055603d2e1e90 <+544>: call 0x55603d7fce84 <coroutine_transfer>
# But nothing ever loads the address of ruby_current_ec from %fs again (i didn't trace
# exactly the data flow from %r13 at 0x000055603d2e1d0b to here, but i assume it spilled
# somewhere and now got loaded back into %r15 here). In any case, that means %r15 here
# contains the value of ruby_current_ec from the _old_ thread, not the current one.
0x000055603d2e1e95 <+549>: mov %rbx,0x28(%r14)
0x000055603d2e1e99 <+553>: mov (%r12),%r15
0x000055603d2e1e9d <+557>: call 0x55603d33a010 <rb_current_ec_noinline>
0x000055603d2e1ea2 <+562>: cmp %rax,%r15
=> 0x000055603d2e1ea5 <+565>: jne 0x55603d2e1f3a <thread_sched_wait_running_turn+714>
........
# assertion failure code path.
0x000055603d2e1f3a <+714>: lea 0x542c0c(%rip),%rdi # 0x55603d824b4d
0x000055603d2e1f41 <+721>: lea 0x542c12(%rip),%rdx # 0x55603d824b5a
0x000055603d2e1f48 <+728>: lea 0x542c28(%rip),%rcx # 0x55603d824b77
0x000055603d2e1f4f <+735>: mov $0x7a5,%esi
0x000055603d2e1f54 <+740>: call 0x55603d08d698 <rb_assert_failure>
if we look at the register values from 0x000055603d2e1ea2:
(rr) print/x $rax
$2 = 0x55603e159ad0
(rr) print/x $r15
$3 = 0x0
So the value from %rax which came from ruby_current_ec_noinline is correctly the value of ruby_current_ec for this thread, and %r15 contains a stale value from a previous thread.
Now, what can we do about this, is a different question :/ There's a really good stackoverflow answer about it here: https://stackoverflow.com/questions/75592038/how-to-disable-clang-expression-elimination-for-thread-local-variable, but to summarise
- longstanding GCC and Clang bugs for this exist and have been marked as WONTFIX (https://gcc.gnu.org/bugzilla/show_bug.cgi?id=26461, https://github.com/llvm/llvm-project/issues/19551)
- It's even worse than this EC problem - things like
errnoalso might be incorrectly persisted across coroutine switches (so e.g. an inlined C library function could in theory seterrnoin another thread, for example) - C++ actually has coroutines now, so this must work for those. Clang at least has fixed some TLS problems in their C++ coroutine implementation (https://github.com/llvm/llvm-project/issues/47179)
Other than reimplementing all of our coroutine stuff on top of C++ coroutines, I'm not sure what else we can do. AFAICT there's no way to tell the compiler that we clobbered the %fs register because that's just not a thing in its model (https://gcc.gnu.org/bugzilla/show_bug.cgi?id=66631, but i assume clang is similar).
Thoughts? For now I think my workaround is to disable M:N at build time when building with ASAN (or turn optimizations down). At least this isn't a problem with Fiber because we never move them across threads (probably for this reason in part).
Updated by kjtsanaktsidis (KJ Tsanaktsidis) 3 months ago
yeah you definitely can't tell the compiler you're clobbering %fs
../thread_pthread.c:1166:20: error: unknown register name 'fs' in asm
1166 | __asm__("" ::: "fs", "memory");
| ^
1 error generated.
make: *** [Makefile:448: thread.o] Error 1
Updated by kjtsanaktsidis (KJ Tsanaktsidis) about 1 month ago
- Related to Misc #20387: Meta-ticket for ASAN support added
Actions
Like0
Like0Like0