Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[PROF-7252] Add Profiling.allocation_count API for new profiler #2635

Merged
merged 8 commits into from
Feb 22, 2023

Conversation

ivoanjo
Copy link
Member

@ivoanjo ivoanjo commented Feb 20, 2023

What does this PR do?:

This PR adds a new profiler public API: Datadog::Profiling.allocation_count.

The public documentation for this API is as follows:

Returns an ever-increasing counter of the number of allocations observed by the profiler in this thread.

Note 1: This counter may not start from zero on new threads. It should only be used to measure how many allocations have happened between two calls to this API:

allocations_before = Datadog::Profiling.allocation_count
do_some_work()
allocations_after = Datadog::Profiling.allocation_count
puts "Allocations during do_some_work: #{allocations_after - allocations_before}"

(This is similar to some OS-based time representations.)

Note 2: All fibers in the same thread will share the same counter values.

Only available when the profiler is running, the new CPU Profiling 2.0 profiler is in use, and allocation-related features are not disabled via configuration.
For instructions on enabling CPU Profiling 2.0 see the ddtrace release notes.

On Ruby 2.x, as long as CPU Profiling 2.0 is in use, this API is enabled by default.

On Ruby 3.x, this API is disabled by default because of a Ractor bug. On Ruby 3 apps that don't use Ractors, this is still safe to enable (via configuration).

To manually enable or disable this feature, this PR adds a new setting:

Datadog.configure do |c|
  c.profiling.advanced.allocation_counting_enabled = # ...
end

Motivation:

This feature has long been something we want to provide with ddtrace, see issues #2164 and #468, as well as PRs #1891, #1805, #597.

As part of the ongoing work of enabling allocation profiling, counting the number of allocations comes at a very cheap cost since the profiler needs to have a RUBY_INTERNAL_EVENT_NEWOBJ tracepoint anyway -- it's just a matter of also incrementing a counter inside it.

Additional Notes:

Note that this does not yet change any user-visible feature for ddtrace. I'm counting on @marcotc to pick up the task of using this API to make some tracing magic :)

This PR is on top of #2634 just for my convenience, but both changes are independent.

How to test the change?:

This change includes code coverage.


Fixes #2164

We now are recommending customers try CPU Profiling 2.0.
The API currently doesn't return anything; will be implemented in the
next commits.
The API still doesn't return anything, but the configuration is
correctly propagated all the way to the `CpuAndWallTimeWorker` native
code.
**What does this PR do?**:

This PR adds a new profiler public API:
`Datadog::Profiling.allocation_count`.

The public documentation for this API is as follows:

> Returns an ever-increasing counter of the number of allocations
> observed by the profiler in this thread.
>
> Note 1: This counter may not start from zero on new threads. It
> should only be used to measure how many
> allocations have happened between two calls to this API:
> ```ruby
> allocations_before = Datadog::Profiling.allocation_count
> do_some_work()
> allocations_after = Datadog::Profiling.allocation_count
> puts "Allocations during do_some_work: #{allocations_after - allocations_before}"
> ```
> (This is similar to some OS-based time representations.)
>
> Note 2: All fibers in the same thread will share the same counter
> values.
>
> Only available when the profiler is running, the new CPU Profiling
> 2.0 profiler is in use, and allocation-related
> features are not disabled via configuration.
> For instructions on enabling CPU Profiling 2.0 see the ddtrace
> release notes.

As long as CPU Profiling 2.0 is in use, this API is enabled by
default. To disable it, this PR adds a new setting:

```ruby
Datadog.configure do |c|
  c.profiling.advanced.allocation_counting_enabled = # ...
end
```

**Motivation**:

This feature has long been something we want to provide with ddtrace,
see issues #2164 and #468, as well as PRs #1891, #1805, #597

As part of the ongoing work of enabling allocation profiling,
counting the number of allocations comes at a very cheap cost since
the profiler needs to have a `RUBY_INTERNAL_EVENT_NEWOBJ`
tracepoint anyway -- it's just a matter of also incrementing a
counter inside it.

**Additional Notes**:

Note that this does not yet change any user-visible feature for
ddtrace. I'm counting on @marcotc to pick up the task of using this
API to make some tracing magic :)

**How to test the change?**:

This change includes code coverage.

---

Fixes #2164
When I wrote the previous expectation, I was assuming that the class
never got loaded on unsupported Rubies.

Which is true... in production. For tests, we actually have something
like

```ruby
require 'datadog/profiling/spec_helper'
require 'datadog/profiling/collectors/cpu_and_wall_time_worker'

RSpec.describe Datadog::Profiling::Collectors::CpuAndWallTimeWorker do
  before { skip_if_profiling_not_supported(self) }
```

which means that even on Ruby 2.1 or JRuby we still load the class,
thus causing CI failures.
These workarounds are similar to the ones we already had for GC
profiling.
Unfortuantely on 3.x Rubies it needs to default to false.
@ivoanjo ivoanjo requested a review from a team February 20, 2023 17:08
@github-actions github-actions bot added core Involves Datadog core libraries profiling Involves Datadog profiling labels Feb 20, 2023
@codecov-commenter
Copy link

Codecov Report

Merging #2635 (40100b6) into ivoanjo/prof-7251-exclude-disabled-profiling-types (a8729a9) will decrease coverage by 0.01%.
The diff coverage is 95.60%.

@@                                  Coverage Diff                                   @@
##           ivoanjo/prof-7251-exclude-disabled-profiling-types    #2635      +/-   ##
======================================================================================
- Coverage                                               98.07%   98.07%   -0.01%     
======================================================================================
  Files                                                    1153     1153              
  Lines                                                   63164    63251      +87     
  Branches                                                 2813     2819       +6     
======================================================================================
+ Hits                                                    61950    62035      +85     
- Misses                                                   1214     1216       +2     
Impacted Files Coverage Δ
lib/datadog/profiling/component.rb 95.45% <ø> (ø)
spec/datadog/profiling_spec.rb 98.78% <88.23%> (-1.22%) ⬇️
...filing/collectors/cpu_and_wall_time_worker_spec.rb 95.39% <95.12%> (+0.65%) ⬆️
lib/datadog/core/configuration/settings.rb 99.20% <100.00%> (+<0.01%) ⬆️
lib/datadog/profiling.rb 100.00% <100.00%> (ø)
...g/profiling/collectors/cpu_and_wall_time_worker.rb 100.00% <100.00%> (ø)
spec/datadog/core/configuration/components_spec.rb 99.87% <100.00%> (+<0.01%) ⬆️
spec/datadog/core/configuration/settings_spec.rb 100.00% <100.00%> (ø)
lib/datadog/core/workers/polling.rb 96.55% <0.00%> (-3.45%) ⬇️
lib/datadog/core/diagnostics/environment_logger.rb 98.46% <0.00%> (+0.76%) ⬆️

📣 We’re building smart automated test selection to slash your CI/CD build times. Learn more

Copy link
Member

@marcotc marcotc left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Awesome work! 🙇

Base automatically changed from ivoanjo/prof-7251-exclude-disabled-profiling-types to master February 22, 2023 10:08
@ivoanjo ivoanjo merged commit 4c0efe4 into master Feb 22, 2023
@ivoanjo ivoanjo deleted the ivoanjo/prof-7252-profiling-newobj-tracepoint branch February 22, 2023 10:43
@github-actions github-actions bot added this to the 1.10.0 milestone Feb 22, 2023
@TonyCTHsu TonyCTHsu mentioned this pull request Mar 6, 2023
ivoanjo added a commit that referenced this pull request Jul 22, 2024
**What does this PR do?**

This PR introduces a new setting for the profiler:
`profiling.advanced.allocation_counting_enabled` which controls the
profiler allocation counting feature.

This setting is off by default, enabling us to reduce allocation
profiling overhead slightly.

**Motivation:**

We actually used to have this setting back in the ddtrace 1.x series.
We introduced it in #2635 and removed it in #3281 -- by tieing it
directly to allocation profiling.

I decided to re-introduce it so we can disable this feature by
default.

**Additional Notes:**

This PR sits atop #3797 because it makes sense to measure both overhead
improvements together, but is otherwise completely independent.

**How to test the change?**

Here's the results for running the `profiler_allocation` benchmark:

```
ruby 2.7.7p221 (2022-11-24 revision 168ec2b1e5) [x86_64-linux]
Warming up --------------------------------------
Allocations (baseline)   1.419M i/100ms
Calculating -------------------------------------
Allocations (baseline)   14.535M (± 2.1%) i/s -    146.197M in  10.062717s

Warming up --------------------------------------
Allocations (alloc_profiling_enabled) 1.122M i/100ms
Calculating -------------------------------------
Allocations (alloc_profiling_enabled) 11.636M (± 2.2%) i/s -    116.679M in  10.032209s

Warming up --------------------------------------
Allocations (alloc_profiling_disabled) 1.124M i/100ms
Calculating -------------------------------------
Allocations (alloc_profiling_disabled) 11.866M (± 2.6%) i/s -    119.175M in  10.050580s

Comparison:
Allocations (baseline): 14534979.3 i/s
Allocations (alloc_profiling_disabled): 11865926.7 i/s - 1.22x  slower
Allocations (alloc_profiling_enabled): 11635919.9 i/s - 1.25x  slower
```

The difference is close to the margin of error; nevertheless
this feature was showing up on the native profiler, and since it was
on the hot path for allocation profiling, I think it's worth it.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
core Involves Datadog core libraries profiling Involves Datadog profiling
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Collect Ruby VM internal event metrics (object allocation)
3 participants