rails: Puma raises WARNING: Detected 1 Thread(s) started in app boot with preload_app and workers

I’ve created https://github.com/rails/rails/pull/40399 as a resolution. Once the thread-local is decided, we’ll add to Puma.

For Puma, we plan a 5.1 release with this change somtime around the end of Nov/start of Dec. https://github.com/puma/puma/milestone/12

The warning is a bit…premature. It was added to puma on the assumption that the developer wouldn’t realize that the thread was also running in each fork. But there are cases where we legitimately want a background thread running in the main worker process. I’m not sure how to square those two things. Basically: There’s nothing inherently wrong with having threads running in your worker process, but it might not do what some people think. It’s a messaging problem.

@nateberkopec there’s an edge case where a mid-reap reaper may have the pool locked, and the post-fork process will itself attempt to synchronize the pool in discard… but that’s safe because a ruby mutex will unlock if its owning thread is MIA:

m = Mutex.new
t = Thread.new { m.synchronize { puts "grabbed lock"; sleep 10; puts "sleep done" } }
Thread.pass

fork { m.synchronize { puts "instant output" } }
m.synchronize { puts "still delayed" }
t.join

The pool isn’t closed before fork; the pool is discarded (in the forked process) after fork.

There is one reaper per pool

Yup… and there’s one [or more, with multi-DB stuff involved] pool per forked process -> reaper[s] per forked process.

https://github.com/rails/rails/blob/b5b078cd99b0107fd8e31ff619578e5321182e0a/activerecord/lib/active_record/connection_adapters/pool_config.rb#L43-L47

Puma is warning that something could go wrong if the owner of the thread isn’t implemented correctly, but provides no way for us to indicate that yes, we do know what we’re doing. Alternative suggestions welcome, but right now I really don’t see a problem to solve here.

Oh! Thanks for the clarification. OK, it’s a false positive.

I misunderstood, and thought it was warning that the thread would NOT be running in each fork – I knew we wanted it to be. But in fact it IS running in each fork, and the puma warning is wrongly assuming it should not be.

OK, thanks @schneems , now this explanation is here for anyone else that finds it!

Does anyone have more info about this?

You still get this error under ActiveRecord 6.0.3.3 and puma 4.3.5, if you have puma configured with heroku’s recommendations. (multiple processes with preload, also on_worker_boot { ActiveRecord::Base.establish_connection }, don’t know if that’s relevant).

<Thread:0x000055c7aaa0ac68@/app/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.3.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:334 sleep> - /app/vendor/bundle/ruby/2.6.0/gems/activerecord-6.0.3.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:337:in `sleep'

puma is warning that a thread is started BEFORE fork happens, so may not exist where expected in forked process. It looks like the thread started is meant to be a “reaper” thread, eliminating abandoned connections from the connection pool.

It may not be running in all of your puma processes, meaning some of them may not be reaping abandoned connections. Maybe this isn’t a problem, but definitely isn’t as intended. Perhaps this should be re-opened?

Paging @schneems (hope you don’t mind, let me know if you do), since this happens under the recommended heroku puma configuration (which is where I noticed it), and heroku may want to take account.