[profiling] Fix 3 flaky tests #3554
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
AlexJF
force-pushed
the
alexjf/handle-allocation-flaky-test
branch
from
9445ae8 to
5d14f23
Compare
marcotc
approved these changes
Mar 22, 2024
ivoanjo
approved these changes
Mar 25, 2024
ivoanjo
added a commit
that referenced
this pull request
Feb 10, 2025
**What does this PR do?** This PR fixes the following flaky profiler spec (seen in https://app.circleci.com/pipelines/github/DataDog/dd-trace-rb/19126/workflows/00361a70-d216-4fa9-9ce9-0f87e5f033f1/jobs/669239): ``` Failures: 1) Datadog::Profiling::Collectors::CpuAndWallTimeWorker._native_allocation_count when CpuAndWallTimeWorker has been started when allocation profiling and allocation counting is enabled returns different numbers of allocations for different threads Failure/Error: expect(after_t1 - before_t1).to be 100 expected #<Integer:201> => 100 got #<Integer:217> => 108 Compared using equal?, which compares object identity, but expected and actual are not the same object. Use `expect(actual).to eq(expected)` if you don't care about object identity in this example. # ./spec/datadog/profiling/collectors/cpu_and_wall_time_worker_spec.rb:1377:in `block (5 levels) in <top (required)>' # ./spec/spec_helper.rb:238:in `block (2 levels) in <top (required)>' # ./spec/spec_helper.rb:123:in `block (2 levels) in <top (required)>' # /usr/local/bundle/gems/webmock-3.23.0/lib/webmock/rspec.rb:39:in `block (2 levels) in <top (required)>' # /usr/local/bundle/gems/rspec-wait-0.0.9/lib/rspec/wait.rb:46:in `block (2 levels) in <top (required)>' ``` We had previously debugged the same issue on another spec in #3554 (and left a nice comment explaining what the issue is). I just propagated the same fix (disabling GC for the duration of the test) to this spec as well. **Motivation:** Zero known flaky profiler tests! **Additional Notes:** In practice what happens is that we're counting how many Ruby objects get created during the spec, but if GC gets triggered at the exact wrong time, it may trigger other Ruby code running, and thus more objects than expected being allocated. By disabling GC for this test, hopefully we're able to keep the Ruby VM from not allocating any incidental things in the background. This GC counting feature is also deprecated, so in the future we'll remove it which is even nicer :) **How to test the change?** Validate that CI is still green.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
What does this PR do?
Fix 3 flaky tests that have surfaced this week:
Datadog::Profiling::Collectors::CpuAndWallTimeWorker ._native_allocation_count when CpuAndWallTimeWorker has been started when allocation profiling is enabled returns the number of allocations between two calls of the methodhttps://app.circleci.com/pipelines/github/DataDog/dd-trace-rb/14119/workflows/cbefa69c-c16e-41fd-a601-2e951a5264ab/jobs/525211
expect(after_allocations - before_allocations).to be 100 | expected #<Integer:201> => 100 | got #<Integer:215> => 107TL;DR: Rare GC occurrence in the middle of the test would count extra array allocations due to execution of finalizer functions with complex arguments (
*rest) which are expected to come from usage ofTempfilein previous tests in the run.C backtrace of Array-typed allocation samples during allocation of 100 Objects
Datadog::Profiling::Collectors::CpuAndWallTimeWorker #stats_reset_not_thread_safe returns accumulated stats and resets them back to 0Datadog::Profiling::Collectors::CpuAndWallTimeWorker #start when heap profiling is enabled records live heap objectsexpect(relevant_sample.values[:'heap-live-samples']).to eq test_num_allocated_object | expected: 123 | got: 120gc gen ageand thus being aggregated in multiple samples rather than the expected individual one.Motivation:
Less flakes!
Additional Notes:
How to test the change?
These bugs were reproduced and fixed through thousands of local executions of the
cpu_and_wall_time_worker_spec.rb. We haven't hit failures after fixing them but you're welcome to give it a try!For Datadog employees:
credentials of any kind, I've requested a review from
@DataDog/security-design-and-guidance.Unsure? Have a question? Request a review!