[NO-TICKET] Profiling: Reset per-thread state when starting profiler#5960
Conversation
…avoid cross-profile leftover state This helper is called when the `CpuAndWallTimeWorker` is about to start, and resets all the per-thread state. This avoids any cross-state contamination, and it's also not concurrent with other things since the `CpuAndWallTimeWorker` has a built-in mechanism to make sure a given instance is the only one running at a time.
The global reset now ensures a clean slate before each test (similar to what happens in production with a new profiler run).
This ensures the need for a separate initialization step -- the global reset takes care of it all.
This reverts commit 6b56cfa. Now that `_native_global_reset_per_thread_context` runs before every test-case, the leftover state that was causing the flakiness should not happen anymore. Out of curiosity, I could manually reproduce something very close to the original flakiness with ```ruby describe "#sample_after_gvl_running" do before { skip_if_gvl_profiling_not_supported(self) } fcontext "if thread does not have per-thread context" do before { remove_per_thread_context_for(t1) } # it do # expect(sample_after_gvl_running(t1)).to be false # end it 'weird test setup' do sleep_thread = Thread.new { sleep } sample # Creates context on_gvl_released(sleep_thread) sample # Waiting starts sample # Sets skip pp per_thread_context[sleep_thread] end it "does not sample the thread" do sample_after_gvl_running(t1) expect(samples).to be_empty end end ``` And running with `--order=defined` to make sure the specs ran in this order. (There was one very subtle detail here -- the `was_skipped_at_last_sample` gets reset when the recorder is flushed so the issue in particular that made the spec flaky might not happen in practice in production since when we stop the profiler we flush the recorder)
Now that we can rely on having a `thread_context_collector_global_reset_per_thread_context` that will right-size buffers, we no longer need to keep the buffer resizing logic. I still left behind a buffer size check just in case some bug slips through.
This avoids the benchmarks needing to care about this new detail.
Typing analysisNote: Ignored files are excluded from the next sections. Untyped methodsThis PR introduces 2 partially typed methods, and clears 2 partially typed methods. It increases the percentage of typed methods from 65.99% to 66.0% (+0.01%). Partially typed methods (+2-2)❌ Introduced:If you believe a method or an attribute is rightfully untyped or partially typed, you can add |
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 5d999114af
ℹ️ About Codex in GitHub
Codex has been enabled to automatically review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
When you sign up for Codex through ChatGPT, Codex can also answer questions or update the PR, like "@codex address that feedback".
|
…ing logic Codex correctly pointed out: > When `max_frames` changes during `Datadog.configure` reconfiguration, `> replace_components!` builds the new components before calling > `old.shutdown!`, and constructing the new `ThreadContext` updates the > global `latest_max_frames` while the old profiler can still be sampling. > Any thread created in that window gets a buffer sized for the new > collector, so this hard raise makes the still-running old worker report > a profiler failure instead of resizing/capping as it did before. We fix this by setting the `latest_max_frames` not at `ThreadContext` creation, but along with the global reset when the `ThreadContext` is **about to be used**. This avoids the issue above.
BenchmarksBenchmark execution time: 2026-07-09 13:13:00 Comparing candidate commit 4404932 in PR branch Found 0 performance improvements and 0 performance regressions! Performance is the same for 48 metrics, 1 unstable metrics.
|
|
Marking as draft as my last changes were not correct + I uncovered a latent bug elsewhere |
I saw this blowing up in CI due to some other errors on the branch, and in practice raising exceptions here is never correct and it was good that Ruby complained.
|
Ok, I believe this is finally in good shape for review! |
eregon
left a comment
There was a problem hiding this comment.
Great stuff, this feels much cleaner and less brittle than explicitly clearing contexts, because we global reset only at known "safe points" i.e. when the profiler is stopped and all hooks are reliably disabled
… `thread_context_collector_reset_all_per_thread_contexts`
Co-authored-by: Benoit Daloze <[email protected]>
Even though these methods don't get used in practice on old Rubies (since they have no GVL instrumentation API hooks), it's useful to have these outside of `NO_GVL_INSTRUMENTATION` for the `Datadog::Profiling::Collectors::ThreadContext#thread_context_collector_reset_all_per_thread_contexts` "resets every existing per-thread context" test, and it seems harmess to always build it.
…er_thread_contexts` specs This way we ensure that there's a non-zero state on the thread for all other cases (e.g. asserts that a no-op `global_reset_per_thread_context` won't trivially pass).
59b56f4 to
b4021d4
Compare
As pointed out very correctly in PR review, `free` && `ruby_xfree` are happy to no-op a NULL so let's just clean this up instead of writing a treaty on conditions where it might not have been initialized.
…try 2 **What does this PR do?** This PR is a second attempt at #6006 ; the first time got reverted in #6012 as we were seeing flaky failures. From DataDog/ruby-guild#314: ``` W, [2026-07-08T16:58:22.863694 #11835] WARN -- datadog: [datadog] CpuAndWallTimeWorker thread error. Operation: "rescued_sample_from_postponed_job" Cause: RuntimeError: BUG: Unexpected sample during GC (thread_id=11835 (10200), gc_tracking.cpu_time_at_start_ns=2802579244, gc_tracking.wall_time_at_start_ns=729604100602, monotonic_wall_time_now_ns=729890337067) Location: /__w/dd-trace-rb/dd-trace-rb/lib/datadog/profiling/collectors/idle_sampling_helper.rb:42:in 'Datadog::Profiling::Collectors::IdleSamplingHelper._native_idle_sampling_loop' W, [2026-07-08T16:58:22.863821 #11835] WARN -- datadog: [datadog] Failed to send telemetry before components initialization or within components lifecycle records garbage collection cycles (FAILED - 3) marks the new thread as fork-safe does not create a second thread if start is called again with allocation profiling enabled /__w/dd-trace-rb/dd-trace-rb/spec/datadog/profiling/collectors/cpu_and_wall_time_worker_spec.rb:43: [BUG] Datadog Ruby profiler detected callback nested inside sample. Please report this at https://github.com/datadog/dd-trace-rb/blob/master/CONTRIBUTING.md#found-a-bug ruby 4.0.1 (2026-01-13 revision e04267a14b) +PRISM [x86_64-linux] ``` (The "callback nested inside sample" happens because some of our tests have strict assertions that things like object allocations can't happen, and they were failing when trying to raise that `RunntimeError: BUG: Unexpected sample during GC` as well) The problem we were seeing was due to the `#on_gc_start` specs never clearing the "thread is in GC" state and thus this state was leaking to other tests which then would trigger the assertion we added. The fix is to make sure we don't leave such leftover state; in the future #5960 is a more holistic solution to this whole "leftover state between profiler instances" problem. I recommend reviewing this PR commit-by-commit. **Motivation:** The original cleanup is useful so we definitely want to keep it! **Additional Notes:** ``` bundle exec rspec './spec/datadog/profiling/collectors/cpu_and_wall_time_worker_spec.rb[1:2:12:1,1:2:12:2,1:2:13,1:2:15:1,1:2:16,1:2:18:1,1:2:18:2:1,1:2:20:1,1:7:1]' './spec/datadog/profiling/collectors/thread_context_spec.rb[1:3:2:1]' --seed 32922 ``` is one way of reproducing the issue. **How to test the change?** We should see a green CI and no flakiness.
Now that #5960 landed, we don't need these hooks anymore. I've confirmed that #5960 still fixes the issue: ``` bundle exec rspec './spec/datadog/profiling/collectors/cpu_and_wall_time_worker_spec.rb[1:2:12:1,1:2:12:2,1:2:13,1:2:15:1,1:2:16,1:2:18:1,1:2:18:2:1,1:2:20:1,1:7:1]' './spec/datadog/profiling/collectors/thread_context_spec.rb[1:3:2:1]' --seed 32922 ``` doesn't break but commenting out `thread_context_collector_reset_all_per_thread_contexts(state->thread_context_collector_instance);` inside `_native_sampling_loop` in `collectors_cpu_and_wall_time_worker.c` does trigger the issue again, confirming that it's the reset that's now taking care of fixing the issue as expected.
What does this PR do?
This PR introduces a new
thread_context_collector_global_reset_per_thread_contextfunction in theThreadContextcollector.This function, as the name indicates, resets all of the per-thread context we keep, and is called by the
CpuAndWallTimeWorkerright before profiling starts so that we always start with a known-good blank slate, which fixes a few issues (discussed below) of stale state resulting in surprising behaviors.This also allows us to simplify a few things in the code, as we get all of the below "naturally" from this reset:
sampling_bufferresizes (it comes naturally from reallocating a new buffer at the start of profiling)thread_begin_tracepointMotivation:
Since #5816, we've been keeping the profiler's per-thread context directly attached to each Ruby thread.
This has a number of advantages:
Yet, because the per-thread context was being retained from profiler run to profiler run, we ran into a few rare corner cases:
In #5926 (comment) you can see a screenshot of a 1 second profile with 6 seconds of cpu/wall-time blamed on a single sample, representing that gap when the profiler was stopped.
Some of our tests had very strict assertions so we were playing whack-a-mole with "oh what if this one piece of leftover state was there between tests".
Change log entry
Yes. Profiling: Fix left-over state impacting samples when profiler gets stopped and started again
Additional Notes:
This is my third attempt at addressing this issue, and in particular it replaces the earlier #5926 .
How to test the change?
I've added code coverage for the new behavior, including a spec that asserts there's no carry-over state between executions of the profiler/
CpuAndWallTimeWorker.