Bug #22098: RUBY_INTERNAL_THREAD_EVENT_RESUMED runs without GVL held

• Status: Open
• Assignee: luke-gru (Luke Gruber)
• Target version: -
• Backport: 3.3: UNKNOWN, 3.4: UNKNOWN, 4.0: UNKNOWN

[luke-gru (Luke Gruber)]

Today, it's possible to get a deadlock when allocating during a hook for this event. I attached a reproduction script using the gvltools gem. One way to fix it would be to not allocate during this hook and change the documentation to be clear that the GVL is not held. Any gems relying on this behavior, like gvltools, would need to be patched.

Another way to approach it would be to change the call site for this hook invocation. I believe it would need to be added to quite a few places. To maintain Ractor safety, it would also need to be invoked without any locks held.

I'm curious about your thoughts @byroot (Jean Boussier).

[luke-gru (Luke Gruber)]

• File deleted (run_loop.sh)

[luke-gru (Luke Gruber)]

• File run_loop.sh run_loop.sh added

[byroot (Jean Boussier)]

I don't think I understand the bug, but:

change the documentation to be clear that the GVL is not held.

This I really don't understand. Are you saying the GVL isn't held when THREAD_EVENT_RESUMED triggers? That would really surprise me.

The main use case for this event is to measure how long it took to acquire the GVL, as such it MUST be called after the GVL held.

[luke-gru (Luke Gruber)]

It really depends on what "holding the GVL" means. Right now, ruby_thread_has_gvl_p() can return false in hooks for this event. This is what can cause a deadlock.

The stack trace for the deadlock looks like this:

    frame #3: 0x00000001048c7e38 ruby`rb_native_mutex_lock(lock=0x00000001057fae20) at thread_pthread.c:125:14 [inlined]
    frame #4: 0x00000001048c7e34 ruby`thread_sched_lock_(sched=0x00000001057fae20, th=<unavailable>, file=<unavailable>, line=939) at thread_pthread.c:403:5 [inlined]
    frame #5: 0x00000001048c7e34 ruby`thread_sched_to_running(sched=0x00000001057fae20, th=0x000000090ae61800) at thread_pthread.c:939:5
    frame #6: 0x00000001048be5c8 ruby`blocking_region_end(th=0x000000090ae61800, region=0x000000016c0559e4) at thread.c:1553:5
    frame #7: 0x00000001048becb0 ruby`rb_thread_call_with_gvl(func=(ruby`gc_with_gvl at default.c:6770), data1=0x000000016c055828) at thread.c:2088:5
    frame #8: 0x000000010477d2dc ruby`garbage_collect_with_gvl(objspace=0x00000001057f8f00, reason=512) at default.c:6791:15
    frame #9: 0x000000010477d258 ruby`objspace_malloc_increase_body(objspace=0x00000001057f8f00, mem=<unavailable>, new_size=<unavailable>, old_size=<unavailable>, type=<unavailable>, gc_allowed=<unavailable>) at default.c:8122:13
    frame #10: 0x0000000104769ad8 ruby`objspace_malloc_fixup(objspace=0x00000001057f8f00, mem=0x000000090b396e50, size=40, gc_allowed=true) at default.c:8200:5 [inlined]
    frame #11: 0x0000000104769ac0 ruby`rb_gc_impl_calloc(objspace_ptr=0x00000001057f8f00, size=40, gc_allowed=true) at default.c:8317:12 [inlined]
    frame #12: 0x0000000104769a44 ruby`ruby_xcalloc_body(n=<unavailable>, size=<unavailable>) at gc.c:5235:12 [inlined]
    frame #13: 0x00000001047699e4 ruby`ruby_xcalloc(n=<unavailable>, size=<unavailable>) at gc.c:5229:34
    frame #14: 0x0000000104769d1c ruby`rb_data_typed_object_zalloc(klass=<unavailable>, size=40, type=<unavailable>) at gc.c:1131:21
    frame #15: 0x0000000124730f84 instrumentation.bundle`GT_LOCAL_STATE(thread=4905812880, allocate=true) at instrumentation.c:47:25
    frame #16: 0x0000000124730f54 instrumentation.bundle`gt_thread_callback(event=<unavailable>, event_data=<unavailable>, user_data=<unavailable>) at instrumentation.c:211:41
    frame #17: 0x00000001048b9550 ruby`rb_thread_execute_hooks(event=4, th=0x000000090ae61800) at thread_pthread.c:3478:17
    frame #18: 0x00000001048b976c ruby`thread_sched_wait_running_turn(sched=<unavailable>, th=<unavailable>, can_direct_transfer=<unavailable>) at thread_pthread.c:904:5 [artificial]
    frame #19: 0x00000001048c7f48 ruby`thread_sched_to_running_common(sched=0x00000001057fae20, th=0x000000090ae61800) at thread_pthread.c:927:5 [inlined]
    frame #20: 0x00000001048c7e3c ruby`thread_sched_to_running(sched=0x00000001057fae20, th=0x000000090ae61800) at thread_pthread.c:941:9
    frame #21: 0x00000001048be5c8 ruby`blocking_region_end(th=0x000000090ae61800, region=0x000000016c0559e4) at thread.c:1553:5
    frame #22: 0x00000001048be18c ruby`rb_nogvl(func=<unavailable>, data1=<unavailable>, ubf=<unavailable>, data2=<unavailable>, flags=<unavailable>) at thread.c:1628:5
    frame #23: 0x0000000124524e80 IO_Event.bundle`IO_Event_Selector_KQueue_select + 588

[luke-gru (Luke Gruber)]

• Subject changed from Reconsider whether THREAD_EVENT_RESUMED runs with GVL held to THREAD_EVENT_RESUMED runs without GVL held

[byroot (Jean Boussier)]

Right now, ruby_thread_has_gvl_p() can return false in hooks for this event.

Then that's a bug.

[jhawthorn (John Hawthorn)]

Here's a reproduction showing that ruby_thread_has_gvl_p() is false https://github.com/ruby/ruby/pull/17263. I think it has been since the introduction of the callback.

I think it might be fine for ruby_thread_has_gvl_p() to return false (we could adjust the documentation to say "about to acquire the GVL" or "has exclusive hold on the GVL, but hasn't yet fully acquired it"). But I think the bigger question is are we allowed to allocate in this callback? Doing so seems broken today and I also don't think it should be allowed.

[luke-gru (Luke Gruber)]

Yes, this has always been buggy and I also don't think we should allow allocating objects/xmalloc in the hook. Even if we changed ruby_thread_has_gvl_p(), the problem is that this hook runs with the scheduler lock held (and always has). We would have to move the invocation of the hook outside of any locks, so it would need to be copied to many call sites (~10). Otherwise, under Ractors, a different type of deadlock could occur if the hook caused a GC and another Ractor was blocked on this Ractor's scheduler lock (it wouldn't be able to join the VM barrier).

[byroot (Jean Boussier)]

But I think the bigger question is are we allowed to allocate in this callback? Doing so seems broken today and I also don't think it should be allowed.

I'm fine with adding that restriction is there really isn't any other solution, but ideally we'd make the necessary changes to allow it.
These callbacks typically want to record information, and THREAD_EVENT_RESUMED is the ideal hooks to update whatever statistics were collected.

so it would need to be copied to many call sites (~10).

Is that inevitable, or could it be solved with a bit of a refactoring. (Sorry, the scheduler code is all but fresh in my head, I'm still unclear on what you are suggesting exactly)

[Eregon (Benoit Daloze)]

As I wrote in https://github.com/Shopify/gvltools/pull/34#issuecomment-4667841039,
my expectation is also that this hook is called with the GVL, on the thread which just acquired the GVL.

I think not being to allocate is not the end (maybe already a requirement for this hook in previous releases?), but it sure would be nice if it was.
Since the hook is called after the GVL is acquired, one would expect to be able to run regular Ruby code there.
However as you say the scheduler lock is held and so one should use a postponed_job for now like here (we should document that).

Being able to do more in that hook would simplify things quite a bit, I actually tried that last week by coincidence but eventually found about the undocumented fact that it runs with the scheduler lock held and so probably not a good idea.

FWIW RB_INTERNAL_THREAD_HOOK(RUBY_INTERNAL_THREAD_EVENT_SUSPENDED, th); is currently called in 6 places, so having it in 10 callers sure feels not so nice but there is also precedent, and maybe something that could be refactored.
FWIW in Ruby 3.2 there were actually much fewer RB_INTERNAL_THREAD_HOOK() call sites, maybe the new scheduler is still "taking shape"?

[Eregon (Benoit Daloze)]

jhawthorn (John Hawthorn) wrote in #note-7:

we could adjust the documentation to say "about to acquire the GVL" or "has exclusive hold on the GVL, but hasn't yet fully acquired it"

This sounds pretty weird (to me at least) because intuitively, either a thread has a lock (i.e. it is its sole owner and won a compare-and-swap or so), or it doesn't and can't know when it will get it (depends on another thread releasing it and this thread winning the race to acquire it).
Interesting that ruby_thread_has_gvl_p() is false, but I think it's something to fix, not to make even harder to use :sweat:

[jhawthorn (John Hawthorn)]

• Subject changed from THREAD_EVENT_RESUMED runs without GVL held to RUBY_INTERNAL_THREAD_EVENT_RESUMED runs without GVL held

Eregon (Benoit Daloze) wrote in #note-10:

Since the hook is called after the GVL is acquired, one would expect to be able to run regular Ruby code there.

I feel very strongly that we must not allow arbitrary Ruby code in these hooks. Arbitrary Ruby code may release the GVL and so that would require these hooks to deal with reentrancy, which is a really bad idea.

As a subscriber to this API (as a profiler) I need the guarantee that these events are delivered reliably and in order (for the given thread). It's not acceptable that an earlier subscriber delays and changes the order in which events are delivered, breaking the documented invariants of the GVL state machine (ex. if we re-suspend in a hook the hook after it will see the SUSPENDED event before the previous RESUMED, will later see multiple RESUMED in a row). We could detect re-entrancy and disable the hooks (as tracepoint does), I really do not want that. It's important for my profiler to have accurate delivery of all events. This is a very low level API and we should expect consumers to all be careful and well behaved.

At best a limited selection of Ruby APIs could be made safe to use here (currently most are unsafe).

We could probably support allocation here (through the rewrite discussed above to call the hooks later from N different locations). I don't think we should.

To support allocations we need to make ruby_thread_has_gvl_p() return true. However we're in some intermediate "you have the GVL but releasing it is illegal" state that is going to result with buggy instrumentation extensions (like we just found). With the current state where ruby_thread_has_gvl_p() returns false, we can at least still detect these bugs via assertions.

IMO the INTERNAL thread event API should adopt the same warning in documentation the INTERNAL tracepoint events have for all events including RUBY_INTERNAL_THREAD_EVENT_RESUMED. It effectively already has this restriction for all events except for RUBY_INTERNAL_THREAD_EVENT_RESUMED (well, it effectively has it for that event too, hence this bug).

You can use any Ruby APIs (calling methods and so on) on normal event hooks.
However, in internal events, you can not use any Ruby APIs (even object creations).

[Eregon (Benoit Daloze)]

jhawthorn (John Hawthorn) wrote in #note-12:

I feel very strongly that we must not allow arbitrary Ruby code in these hooks.

I agree, I expressed that poorly.
I meant to say one would expect the GVL is held (given the name of the hook); and it would be nice if we can call various rb_*() functions, as in regular C extension code.
But the latter (in general) does conflict with what you say, good points.
Anything that check interrupts or may switch threads or release the GVL, etc is clearly a no-go.

As a subscriber to this API (as a profiler)

I'm also using this API for a profiler :)

I need the guarantee that these events are delivered reliably and in order (for the given thread). It's not acceptable that an earlier subscriber delays and changes the order in which events are delivered, breaking the documented invariants of the GVL state machine (ex. if we re-suspend in a hook the hook after it will see the SUSPENDED event before the previous RESUMED, will later see multiple RESUMED in a row). We could detect re-entrancy and disable the hooks (as tracepoint does), I really do not want that. It's important for my profiler to have accurate delivery of all events. This is a very low level API and we should expect consumers to all be careful and well behaved.

Agreed. (FTR, Ruby 3.2 does emit multiple SUSPENDED events in a row with ConditionVariable, but 3.3+ does not seem to have the issue)

Better documentation would go a long way.
I think we still want the RESUMED hook to be called on the thread which just acquired the GVL, it's too surprising otherwise and doesn't seem advantageous either.

However, in internal events, you can not use any Ruby APIs (even object creations).

"you can not use any Ruby APIs" is too strict, at minimum we need:

• rb_internal_thread_specific_get()/rb_internal_thread_specific_set()
• rb_postponed_job_trigger()
• TypedData_Get_Struct()
• some way to check if on main Ractor or not

(which is BTW what the datadog gem uses, and similar for gvltools)

If we forbid APIs like allocation, would it be possibly to reliably fail if called from these hooks with a RUBY_DEBUG build?
That'd be a good way to validate it (which we could even document on rb_internal_thread_add_event_hook()).

[jhawthorn (John Hawthorn)]

Eregon (Benoit Daloze) wrote in #note-13:

"you can not use any Ruby APIs" is too strict, at minimum we need:

• rb_internal_thread_specific_get()/rb_internal_thread_specific_set()
• rb_postponed_job_trigger()

These are all documented to be async-signal-safe, and so can be called everywhere (including the existing hooks with the quoted restriction). I don't think that needs clarification here, but we could spell it out I guess.

• TypedData_Get_Struct()

Should not be explicitly supported as it can raise an exception (though I'm sure it doesn't in your use) and so runs arbitrary user code. RTYPEDDATA_GET_DATA is probably fine, but unlike the async-signal-safe examples doesn't feel like the type that should be explicitly allowed here or in the internal GC hooks. Why do you need it? Could you pass the raw pointer?

If we forbid APIs like allocation, would it be possibly to reliably fail if called from these hooks with a RUBY_DEBUG build?
That'd be a good way to validate it (which we could even document on rb_internal_thread_add_event_hook()).

I'd love to add ASSERT(ruby_thread_has_gvl_p()) to newobj (and maybe to rb_funcall), but I don't know if the performance is acceptable even for debug builds.

[Eregon (Benoit Daloze)]

One reason it would be valuable to be able to allocate in RESUMED is that's a good spot to set the per-thread state.

I looked at the datadog gem, gvltools, gvl-tracing and vernier.
All of them except vernier use rb_internal_thread_specific_get()/rb_internal_thread_specific_set(), but also all of them need to mark some things inside the per-thread state (to mark a sample taken in a signal handler, etc).

• vernier uses a std::vector to keep all per-thread states and mark them (that probably means linear lookup with the # of thread then + need to lock around it so some contention).
• until recently, datadog used a st_table to keep all per-thread states and mark them (+ an integer in rb_internal_thread_specific, as it couldn't touch the st_table in GVL events).
• datadog master uses a TypedData object stored as a hidden ivar on the Thread, this is simpler and convenient, it always has the full per-thread state with just rb_internal_thread_specific_get (no need for a st_table and no need to remove dead threads)
• gvltools and gvl-tracing use rb_internal_thread_specific and a TypedData object stored as a Fiber-local (rb_thread_local_aset) on the Thread

Storing as a Fiber-local/Thread-local/ivar on the Thread is not ideal because that would fail if the Thread is frozen (but I think nobody freezes Threads).
Maybe rb_internal_thread_specific_*() should support GC-marking the value to fix that, but that still wouldn't help regarding allocations.

A good place to allocate that TypedData object would be in RESUMED, that's both the initial state of a thread, and a good state to start tracking at for threads that existed before the profiler.

The approach in https://github.com/Shopify/gvltools/pull/34 is to iterate the threads when starting the profiler, and to use the RUBY_INTERNAL_THREAD_EVENT_STARTED event, but that's not guaranteed to be called with the GVL according to the docs at least (and unclear if guaranteed to be called on the new Thread, if not could be problematic if the thread runs for a very short time and we try to cleanup the state concurrently (in EXITED) with initializing it).
So we're saying in this issue the event that tracks getting the GVL may not have the GVL but the STARTED event which might not have the GVL is OK to rely on having the GVL? (I'm just highlighting how surprising that may be, but I think it may be fine if well documented and if it holds on existing releases)

The current approach in the datadog gem is to allocate the thread states in a postponed job after the periodic signal handler sample, where it also samples other threads.
Any RESUMED event before that sample is effectively lost, because we can't allocate in RESUMED, allocating in a postponed job after RESUMED is too late since we have nowhere to store the data.
We could iterate threads when the profiler starts, but that wouldn't capture new threads (and unclear if RUBY_INTERNAL_THREAD_EVENT_STARTED can allocate).
Maybe a regular :thread_start TracePoint should be used? That has guarantees about the GVL and running on the right thread, but is heavier.

BTW because we can't call Ruby APIs in the RESUMED event, we need to use a postponed job.
The means the postponed job must be scheduled quickly after the RESUMED event, as notably if there would be another GVL event in between that would cause problems.

[Eregon (Benoit Daloze)]

jhawthorn (John Hawthorn) wrote in #note-14:

Why do you need it? Could you pass the raw pointer?

In this case it's to access some configuration of the profiler for whether to sample after RESUMED (state->waiting_for_gvl_threshold_ns), i.e. if it took a while to acquire the GVL (from READY to RESUMED).
There are ways to work around it, e.g. by storing that in a C global, or passing it to the GVL callback as the extra data pointer, but since this hook should effectively "have" the GVL I thought it's fine enough to get it from the Ruby object.