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-7440] Add workaround for incorrect invoke location when logging gem is in use #3183

Merged
merged 2 commits into from
Oct 4, 2023

Conversation

ivoanjo
Copy link
Member

@ivoanjo ivoanjo commented Oct 4, 2023

What does this PR do?

In #2950, we added a fallback for nameless threads: we use their "invoke location", as shown by Ruby in the default Thread#to_s. The invoke location is the file and line of the first method of the thread.

This fallback has an issue: when thread creation is monkey patched. One common source of this is the logging gem. When the logging gem monkey patches thread creation, every thread will have the same invoke location, which will point to the logging gem.

This made the fallback invoke location worse than not having anything.

To work around this, this PR changes the profiler so that when the invoke location belongs to the logging gem, it's not used, and a simpler (Unnamed thread) placeholder is used instead.

Motivation:

This issue came up when testing the timeline feature with some of the internal Ruby apps.

Additional Notes:

In the future we could probably explore a more generic fix (e.g. using Thread.method(:new).source_location or something like that to detect redefinition) but doing that from the profiler native code is a bit more work so I decided to go with a simpler approach.

How to test the change?

Change includes test coverage. You can also see the thread name difference on an app by creating a simple thread before/after loading the logging gem and see the fallback name for the thread.

For Datadog employees:

  • If this PR touches code that signs or publishes builds or packages, or handles
    credentials of any kind, I've requested a review from @DataDog/security-design-and-guidance.
  • This PR doesn't touch any of that.

… gem is in use

**What does this PR do?**

In #2950, we added a fallback for nameless threads: we use their
"invoke location", as shown by Ruby in the default `Thread#to_s`.
The invoke location is the file and line of the first method of the
thread.

This fallback has an issue: when thread creation is monkey patched.
One common source of this is the `logging` gem. When the `logging`
gem monkey patches thread creation, every thread will have the
same invoke location, which will point to the `logging` gem.

This made the fallback invoke location worse than not having anything.

To work around this, this PR changes the profiler so that when the
invoke location belongs to the `logging` gem, it's not used, and
a simpler `(Unnamed thread)` placeholder is used instead.

**Motivation:**

This issue came up when testing the timeline feature with some of
the internal Ruby apps.

**Additional Notes:**

In the future we could probably explore a more generic fix
(e.g. using `Thread.method(:new).source_location` or something
like that to detect redefinition) but doing that from the profiler
native code is a bit more work so I decided to go with a simpler
approach.

**How to test the change?**

Change includes test coverage. You can also see the thread name
difference on an app by creating a simple thread before/after loading
the `logging` gem and see the fallback name for the thread.
@ivoanjo ivoanjo requested a review from a team as a code owner October 4, 2023 15:29
@github-actions github-actions bot added the profiling Involves Datadog profiling label Oct 4, 2023
@codecov-commenter
Copy link

Codecov Report

Merging #3183 (1cde833) into master (c8de363) will increase coverage by 0.00%.
Report is 10 commits behind head on master.
The diff coverage is 100.00%.

@@           Coverage Diff           @@
##           master    #3183   +/-   ##
=======================================
  Coverage   98.21%   98.21%           
=======================================
  Files        1247     1248    +1     
  Lines       71664    71685   +21     
  Branches     3329     3330    +1     
=======================================
+ Hits        70382    70403   +21     
  Misses       1282     1282           
Files Coverage Δ
...iling_native_extension/native_extension_helpers.rb 96.73% <100.00%> (ø)

... and 5 files with indirect coverage changes

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

Copy link
Contributor

@ekump ekump left a comment

Choose a reason for hiding this comment

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

A hacky solution, but LGTM to unblock the 1.15 release. This is better than no fix at all. Might be worth adding a comment to the code indicating that it's likely a temporary solution?

@ivoanjo
Copy link
Member Author

ivoanjo commented Oct 4, 2023

A hacky solution, but LGTM to unblock the 1.15 release. This is better than no fix at all. Might be worth adding a comment to the code indicating that it's likely a temporary solution?

Thanks for the review + agreed. Documented it in 4ff3cf6.

@ivoanjo ivoanjo merged commit e1a3596 into master Oct 4, 2023
217 checks passed
@ivoanjo ivoanjo deleted the ivoanjo/prof-7440-workaround-logging-gem branch October 4, 2023 17:15
@github-actions github-actions bot added this to the 1.15.0 milestone Oct 4, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
profiling Involves Datadog profiling
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants