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.

Sign up for GitHub

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

Jump to bottom

Add context inheritance via prepend instead of changing Thread #230

Open
wants to merge 2 commits into
base: master
Choose a base branch
from
Open

Add context inheritance via prepend instead of changing Thread #230

wants to merge 2 commits into from

Conversation

ivoanjo
Copy link

@ivoanjo ivoanjo commented Jun 15, 2021 •
edited
Loading

👋 Hello there!

I work at @DataDog on our open-source Ruby APM library, ddtrace.

One of our users has ran into an issue where logging's Thread inherit context behavior was conflicting with dd-trace's own extensions to Thread, leading to a stack level too deep (SystemStackError) due to both of our extensions conflicting.

We've seen this happen from time to time, e.g. rollbar/rollbar-gem#1018 or MiniProfiler/rack-mini-profiler#444. (See also rails/rails#19434 and rails/rails#19413 where rails moved to prepend as well)

Changing logging to use prepend makes it compatible with all libraries that have moved to use prepend.

Furthermore, while I was in the neighbourhood, I've added the tweaks necessary to not break Ruby 3.0 keyword arguments when used with threads, as well as a test to cover it.

I've tested these changes with Ruby 2.4, 2.7 and 3.0.

Hopefully this change is acceptable? Let me know if I can provide any more info or help, as we're really interested in solving this 😀

Note: As documented in the logging source code, setting the LOGGING_INHERIT_CONTEXT environment variable to false also avoids this issue, although at the cost of loosing that helpful feature.

ivoanjo added 2 commits June 15, 2021 09:43
@ivoanjo
Add context inheritance via prepend instead of changing Thread
fe9bc0f 
Directly modifying the `Thread` class leads to
`stack level too deep (SystemStackError)` if other gems have prepended
modules to `Thread`, see for instance:

* <rollbar/rollbar-gem#1018>
* <MiniProfiler/rack-mini-profiler#444>
* <https://github.com/DataDog/dd-trace-rb/blob/master/docs/GettingStarted.md#stack-level-too-deep>

This behavior can be triggered with the following example app
(NOTE: the issue is triggered only on Linux, as due to unrelated
reasons the ddtrace gem only adds the module to `Thread` on that OS):

```ruby
require 'bundler/inline'

gemfile do
  source 'http://rubygems.org'

  gem 'logging', '= 2.3.0', require: false
  gem 'ddtrace', '= 0.50.0', require: false
  gem 'google-protobuf'
end

require 'ddtrace'

Datadog.configure do |c|
  c.profiling.enabled = true
end

require 'logging'

Thread.new { }.join
```

By changing context inheritance to use a `prepend`, it becomes
compatible with all libraries that use this technique as well.
@ivoanjo
Add support for Ruby 3.0 keyword arguments
7cc2163 
`ruby2_keywords` enables keyword arguments to work on Ruby 3.0
`Thread`s that have been prepended with `InheritContext`.
@ivoanjo
Copy link
Author

ivoanjo commented Jun 15, 2021 •
edited
Loading

Note: I'm experimenting with a hack in ddtrace that hopefully avoids triggering this issue, but older versions of ddtrace and other libraries using these monkey patches would still be affected, and thus I think it's still worth the fix.

Update: Experiment didn't work, either this patch or LOGGING_INHERIT_CONTEXT=false is still required.

ivoanjo added a commit to DataDog/dd-trace-rb that referenced this pull request Jun 17, 2021
@ivoanjo
[PROF-3514] Skip CPU time instrumentation if logging gem is detected
b7f7b01 
This is a repeat of #1362 -- the logging gem also monkey patches
`Thread` initialization using `alias_method`, which is incompatible
with our instrumentation that uses `preload`.

For details, see TwP/logging#230 where we
submitted a fix to the upstream gem.

Right now the only way to avoid this issue and still enable proflier is
to either remove the logging gem or to disable the feature using the
`LOGGING_INHERIT_CONTEXT` environment variable.

If/when the gem creators accept our proposed change and release it,
we'll need to revise this to take that into consideration, as we do
for rollbar.

NOTE: I'm not entirely happy with the complexity that is accumulating
for the tests, but I've decided to not refactor it yet. If we need
to add more gems, we should definitely refactor the tests. My hope is
that soon we can get rid of our `Thread` monkey patches, and thus get
rid of all of this instead.
ivoanjo added a commit to DataDog/dd-trace-rb that referenced this pull request Jun 17, 2021
@ivoanjo
[PROF-3514] Skip CPU time instrumentation if logging gem is detected
add4289 
Instead, customers will get the following log message:

```
INFO -- ddtrace: [ddtrace] (/app/lib/ddtrace/profiling/tasks/setup.rb
:44:in `activate_cpu_extensions') CPU time profiling skipped because
native CPU time is not supported: The `logging` gem is installed and
its thread inherit context feature is enabled. Please add
LOGGING_INHERIT_CONTEXT=false to your application's environment
variables to disable the conflicting `logging` gem feature. See
TwP/logging#230 for details. Profiles
containing Wall time will still be reported.
```

This is a repeat of #1362 -- the logging gem also monkey patches
`Thread` initialization using `alias_method`, which is incompatible
with our instrumentation that uses `preload`.

For details, see TwP/logging#230 where we
submitted a fix to the upstream gem.

Right now the only way to avoid this issue and still enable proflier is
to either remove the logging gem or to disable the feature using the
`LOGGING_INHERIT_CONTEXT` environment variable.

If/when the gem creators accept our proposed change and release it,
we'll need to revise this to take that into consideration, as we do
for rollbar.

NOTE: I'm not entirely happy with the complexity that is accumulating
for the tests, but I've decided to not refactor it yet. If we need
to add more gems, we should definitely refactor the tests. My hope is
that soon we can get rid of our `Thread` monkey patches, and thus get
rid of all of this instead.
@ivoanjo ivoanjo mentioned this pull request Jun 17, 2021
Merged
ivoanjo added a commit to DataDog/dd-trace-rb that referenced this pull request Jun 17, 2021
@ivoanjo
[PROF-3514] Skip CPU time instrumentation if logging gem is detected
cef8067 
Instead, customers will get the following log message:

```
INFO -- ddtrace: [ddtrace] (/app/lib/ddtrace/profiling/tasks/setup.rb
:44:in `activate_cpu_extensions') CPU time profiling skipped because
native CPU time is not supported: The `logging` gem is installed and
its thread inherit context feature is enabled. Please add
LOGGING_INHERIT_CONTEXT=false to your application's environment
variables to disable the conflicting `logging` gem feature. See
TwP/logging#230 for details. Profiles
containing Wall time will still be reported.
```

This is a repeat of #1362 -- the logging gem also monkey patches
`Thread` initialization using `alias_method`, which is incompatible
with our instrumentation that uses `preload`.

For details, see TwP/logging#230 where we
submitted a fix to the upstream gem.

Right now the only way to avoid this issue and still enable proflier is
to either remove the logging gem or to disable the feature using the
`LOGGING_INHERIT_CONTEXT` environment variable.

If/when the gem creators accept our proposed change and release it,
we'll need to revise this to take that into consideration, as we do
for rollbar.

NOTE: I'm not entirely happy with the complexity that is accumulating
for the tests, but I've decided to not refactor it yet. If we need
to add more gems, we should definitely refactor the tests. My hope is
that soon we can get rid of our `Thread` monkey patches, and thus get
rid of all of this instead.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
1 participant
@ivoanjo