scoutapp
hang on startup with 5.3.5+ and carrierwave
After upgrading a simple Rails app from scout 5.3.3 to 5.4.0, puma now hangs on initialization. strace shows that it's spinning on a futex; the process also ignores SIGINT, which seems kind of rude (but does respond to SIGTERM). Everything works fine if starting a rails console or other interactive process; it's something unhappy between scout and puma.
Downgrading to 5.3.3 fixes the problem; upgrading to 5.3.5 or 5.4.0 reproduces it.
Bisection points to 37c88b8ef160727a89793e1cf5f069a73897688d as the offending commit; everything works in 679670e990e07820b928d46c52a4740933e21d0f but and hangs in 37c88b8ef160727a89793e1cf5f069a73897688d.
Relevant specs
Ruby: 3.3.5 Rails: 7.2.1.2
Sorry for the trouble there, and thanks for narrowing it down. Based on the context of that commit, I wonder if there are other things in your app that were using the hook (Rails.configuration.after_initialize) that are causing some kind of contention/deadlock with the ActiveRecord instrumentation now that it is being added with it.
If you post a Gemfile or otherwise dump things that are registered to that hook, we might be able to narrow it down farther/see what is executing before it wedges. Meanwhile we'll put an environment together with those specs. This is the first we have heard of this particular issue and it makes me very curious about what is going on.
Nothing in our codebase is using after_initialize directly, but I wouldn't be entirely surprised if some dependency did. I hacked up rails to print out everything that calls after_initialize and got the following
after_initialize callers
/src/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.1.2/lib/active_support/i18n_railtie.rb:19:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:20:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:25:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:30:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:37:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:44:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:49:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:55:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:62:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:67:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:74:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionview-7.2.1.2/lib/action_view/railtie.rb:108:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actionmailer-7.2.1.2/lib/action_mailer/railtie.rb:82:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/actiontext-7.2.1.2/lib/action_text/engine.rb:88:in `<class:Engine>'
/src/vendor/bundle/ruby/3.3.0/gems/sprockets-rails-3.4.2/lib/sprockets/railtie.rb:219:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/sassc-rails-2.1.2/lib/sassc/rails/railtie.rb:30:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/bugsnag-6.27.1/lib/bugsnag/integrations/railtie.rb:122:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/sidekiq-7.3.4/lib/sidekiq/rails.rb:62:in `<class:Rails>'
/src/vendor/bundle/ruby/3.3.0/gems/draper-4.0.2/lib/draper/railtie.rb:14:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/simple_form-5.3.1/lib/simple_form/railtie.rb:8:in `<class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.1.2/lib/active_support/railtie.rb:17:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.1.2/lib/active_support/railtie.rb:25:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.1.2/lib/active_support/railtie.rb:33:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.1.2/lib/active_support/railtie.rb:127:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.1.2/lib/active_support/railtie.rb:135:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.1.2/lib/active_support/railtie.rb:143:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activesupport-7.2.1.2/lib/active_support/railtie.rb:151:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:113:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:156:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:211:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:221:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:233:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:322:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:351:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:385:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activerecord-7.2.1.2/lib/active_record/railtie.rb:414:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/globalid-1.2.1/lib/global_id/railtie.rb:23:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activejob-7.2.1.2/lib/active_job/railtie.rb:22:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/activejob-7.2.1.2/lib/active_job/railtie.rb:44:in `block in <class:Railtie>'
/src/vendor/bundle/ruby/3.3.0/gems/scout_apm-5.4.0/lib/scout_apm/instruments/active_record.rb:55:in `install'
What's interesting is that the ScoutApm::Instruments::ActiveRecord#add_instruments method actually never seems to be called; I stuck a breakpoint there and it never hits.
Nonetheless, I think this was fruitful, because this pointed me to instrumenting the ActiveSupport::LazyLoadHooks class, which revealed that the hanging code appears to be a deadlock between carrierwave/orm/activerecord and scout_apm/instruments/active_record. Removing carrierwave fixes the problem, even with scoutapm 5.4.0.
In this case, we're migrating to ActiveStorage anyway, so dropping Carrierwave seems like straightforward solution. Perhaps someone cleverer than I can figure out why carrierwave and scout_apm are fighting this way.
Nicely done. Thank you again for taking the time. Updated the issue title to highlight the conflict while we take a look.