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-4756] Fix profiler not restarting on Process.daemon #2150

Merged
merged 3 commits into from
Jul 18, 2022

Conversation

ivoanjo
Copy link
Member

@ivoanjo ivoanjo commented Jul 13, 2022

What does this PR do?:

Extend the Forking monkey patch to also cover the Process.daemon API (that is another way of forking a Ruby process).

Motivation:

When the Ruby VM forks, only the thread that called fork survives in the child process.

Thus, we have the Forking monkey patch which allows us to run callbacks in the child process, including restarting the profiler.

But there's a less known API in Ruby that also makes use of forking -- Process.daemon. One example of using this API is when calling rails server -d; that -d makes Rails call this API.

Because we were missing monkey patching Process.daemon, the profiler would not restart on Process.daemon. A customer using exactly rails server -d ran into this issue.

Additional Notes:

This PR is on top of #2149 just to avoid any conflicts because of close by lines being removed, but both PRs are entirely independent.

How to test the change?

Easy one-liner to validate that the profiler restarts after becoming a daemon:

$ DD_TRACE_DEBUG=true DD_PROFILING_ENABLED=true bundle exec ddtracerb exec ruby -e 'Process.daemon(nil, true); exit!'
D, [#38994] (dd-trace-rb/lib/datadog/core/configuration/components.rb:371:in `startup!') Profiling started
D, [#38994] (dd-trace-rb/lib/datadog/core/workers/async.rb:133:in `start_worker') Starting thread for: #<Datadog::Profiling::Collectors::OldStack:0x00007fb9c828b3e0>
D, [#38994] (dd-trace-rb/lib/datadog/core/workers/async.rb:133:in `start_worker') Starting thread for: #<Datadog::Profiling::Scheduler:0x00007fb9c8289ab8>
 # <-- notice the PID change here
D, [#39013] (dd-trace-rb/lib/datadog/core/workers/async.rb:133:in `start_worker') Starting thread for: #<Datadog::Profiling::Collectors::OldStack:0x00007fb9c828b3e0>
D, [#39013] (dd-trace-rb/lib/datadog/core/workers/async.rb:133:in `start_worker') Starting thread for: #<Datadog::Profiling::Scheduler:0x00007fb9c8289ab8>

The daemon mode seems... broken(?) in Rails 7. With puma, no webserver would be started, and with webrick, a process would stay behind but not reply to any HTTP requests.

Nevertheless, I believe this fix should be enough (the customer reported this a long ago, this was a low priority fix).

I vaguely remember this being the case, but still got slightly
confused by seeing the log around encoding, so hopefully this clarifies
that the log does not mean that a profile would be reported.
When the Ruby VM `fork`s, only the thread that called `fork` survives
in the child process.

Thus, we have the `Forking` monkey patch which allows us to run
callbacks in the child process, including restarting the profiler.

But there's a less known API in Ruby that also makes use of forking
-- `Process.daemon`. One example of using this API is when calling
`rails server -d`; that `-d` makes Rails call this API.

Because we were missing monkey patching `Process.daemon`, the profiler
would not restart on `Process.daemon`. A customer using exactly
`rails server -d` ran into this issue.

Easy one-liner to validate that the profiler restarts after becoming
a daemon:

```
$ DD_TRACE_DEBUG=true DD_PROFILING_ENABLED=true bundle exec ddtracerb exec ruby -e 'Process.daemon(nil, true); exit!'
D, [#38994] (dd-trace-rb/lib/datadog/core/configuration/components.rb:371:in `startup!') Profiling started
D, [#38994] (dd-trace-rb/lib/datadog/core/workers/async.rb:133:in `start_worker') Starting thread for: #<Datadog::Profiling::Collectors::OldStack:0x00007fb9c828b3e0>
D, [#38994] (dd-trace-rb/lib/datadog/core/workers/async.rb:133:in `start_worker') Starting thread for: #<Datadog::Profiling::Scheduler:0x00007fb9c8289ab8>
 # <-- notice the PID change here
D, [#39013] (dd-trace-rb/lib/datadog/core/workers/async.rb:133:in `start_worker') Starting thread for: #<Datadog::Profiling::Collectors::OldStack:0x00007fb9c828b3e0>
D, [#39013] (dd-trace-rb/lib/datadog/core/workers/async.rb:133:in `start_worker') Starting thread for: #<Datadog::Profiling::Scheduler:0x00007fb9c8289ab8>
```
Without this, the test fails if the `Forking` patch has been applied
by a different spec (due to RSpec not being able to properly setup
mocks).
@ivoanjo ivoanjo requested a review from a team July 13, 2022 10:09
Base automatically changed from ivoanjo/prof-4756-simplify-forking-monkey-patch to master July 13, 2022 12:43
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.

The saga of finding new fork points in Ruby continues!

@ivoanjo ivoanjo merged commit 7400ace into master Jul 18, 2022
@ivoanjo ivoanjo deleted the ivoanjo/prof-4756-restart-on-process-daemon-v2 branch July 18, 2022 08:20
@github-actions github-actions bot added this to the 1.3.0 milestone Jul 18, 2022
@ivoanjo
Copy link
Member Author

ivoanjo commented Jul 18, 2022

Thanks Marco! I actually raised some questions upstream about making this easier to hook/find: https://bugs.ruby-lang.org/issues/18911 .

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants