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

Puma warning log #3203

Closed
pbstriker38 opened this issue Oct 17, 2023 · 4 comments · Fixed by #3279
Closed

Puma warning log #3203

pbstriker38 opened this issue Oct 17, 2023 · 4 comments · Fixed by #3279
Assignees
Labels
bug Involves a bug community Was opened by a community member

Comments

@pbstriker38
Copy link

Current behaviour
Puma logs a warning that it has detected threads starting when the app boots

[1] ! WARNING: Detected 1 Thread(s) started in app boot:
[1] ! #<Thread:0x0000ffff7ecdf4a0@Datadog::Core::Telemetry::Heartbeat /home/ruby/vendor/bundle/ruby/3.0.0/gems/ddtrace-1.15.0/lib/datadog/core/workers/async.rb:136 sleep> - /home/ruby/vendor/bundle/ruby/3.0.0/gems/ddtrace-1.15.0/lib/datadog/core/workers/interval_loop.rb:98:in `sleep'

Expected behaviour
ddtrace should not be starting threads during app boot

Steps to reproduce
start puma with workers and preload_app!

bundle exec puma -w 2 --preload

Environment

  • ddtrace version: 1.15.0
  • Configuration block (Datadog.configure ...):
Datadog.configure do |c|
  c.tracing.instrument :rack, service_name: ENV['DD_SERVICE']
  c.tracing.instrument :grape, service_name: ENV['DD_SERVICE']
  c.tracing.instrument :http, service_name: ENV['DD_SERVICE']

  c.tracing.instrument :http, describes: /\.us-west-2\.amazonaws\.com/ do |http|
    http.service_name = "#{ENV['DD_SERVICE']}-dynamodb"
  end
  c.tracing.instrument :aws, service_name: "#{ENV['DD_SERVICE']}-dynamodb"

  c.runtime_metrics.enabled = true
end
  • Ruby version: 3.0.5
  • Operating system: Alpine Linux
  • Relevant library versions: puma v6.4.0
@pbstriker38 pbstriker38 added bug Involves a bug community Was opened by a community member labels Oct 17, 2023
@ivoanjo
Copy link
Member

ivoanjo commented Oct 25, 2023

Hey @pbstriker38, thanks for reaching out!

So... this one is a bit awkward/annoying. Mixing threads and processes using fork is often not a great idea, because (among others) the threads will (usually) not be carried over to the forked processes. I believe this is why puma issues that warning when it detects background threads.

In the specific case of ddtrace, the above is not a problem: ddtrace automatically detects the fork operation and restarts its threads, so that's fine.

But... puma doesn't really know about that... which is the awkward/annoying part.

One way of avoiding this is to use puma's on_worker_boot hook, any only loading ddtrace/running Datadog.configure there -- this will make sure ddtrace's threads are only started in the child processes, after puma forks. (One downside is that you'll get slightly more memory usage -- because child processes will not share their copy of ddtrace).

@pbstriker38
Copy link
Author

Good to know. Should there maybe be some documentation somewhere that mentions this?

@ivoanjo
Copy link
Member

ivoanjo commented Oct 26, 2023

Very reasonable ask! I'm thinking it could be added to the "Known issues and suggested configurations" section of our docs.

I'll leave this issue open until I open a PR for it (may take a few days, a bit tight ATM!) :)

@ivoanjo ivoanjo self-assigned this Oct 31, 2023
@ivoanjo
Copy link
Member

ivoanjo commented Nov 23, 2023

Actually now that I got back to this, I spotted in the puma code that there's actually a way to mark threads as fork safe, which is much better! So I've opened #3279 and in the future puma will not show this warning for ddtrace threads 🎉

pull bot pushed a commit to astradot/dd-trace-rb that referenced this issue Nov 27, 2023
**What does this PR do?**

This PR applies to all relevant ddtrace threads a pattern pioneered by
rails: set the `:fork_safe` thread variable to indicate that it's OK
if ddtrace threads are started before a Ruby app calls fork.

**Motivation:**

This PR fixes the issue reported in DataDog#3203. The puma webserver in
clustering mode has a check where it will warn when it detects that
threads were started before the webserver has fork'd the child
processes, see:

https://github.com/puma/puma/blob/32e011ab9e029c757823efb068358ed255fb7ef4/lib/puma/cluster.rb#L353-L359

This is not a problem for ddtrace (as discussed in DataDog#3203), but the
warning is annoying.

While looking into the issue again today, I spotted that actually
there's a way to tell puma that a thread is fine and is it's not a
problem if it's started before the webserver has fork'd: puma
checks if the thread has a `:fork_safe` thread-variable set to `true`.

**Additional Notes:**

We have a bunch of places in ddtrace where we create threads...
I briefly played with the idea of creating a superclass of all
ddtrace Threads, but decided to not get into a bigger refactoring
for such a small issue. Maybe next time...?

**How to test the change?**

Test coverage included. Furthermore, you can try running
a Ruby webapp in puma before/after the change to confirm the
warning is gone.

Fixes DataDog#3203
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Involves a bug community Was opened by a community member
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants