Skip to content

[PROF-7440] Add workaround for incorrect invoke location when logging gem is in use#3183

Merged
ivoanjo merged 2 commits into
masterfrom
ivoanjo/prof-7440-workaround-logging-gem
Oct 4, 2023
Merged

[PROF-7440] Add workaround for incorrect invoke location when logging gem is in use#3183
ivoanjo merged 2 commits into
masterfrom
ivoanjo/prof-7440-workaround-logging-gem

Conversation

@ivoanjo

@ivoanjo ivoanjo commented Oct 4, 2023

Copy link
Copy Markdown
Member

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
Copy Markdown

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

@ekump ekump left a comment

Copy link
Copy Markdown
Contributor

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

ivoanjo commented Oct 4, 2023

Copy link
Copy Markdown
Member Author

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
@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