-
Notifications
You must be signed in to change notification settings - Fork 183
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
Bootsnap causes server to hang in Ruby 3.2.1 #448
Comments
This happen on every single restart?
Sorry, but if it was this simple thousands of people would have ran into it. Any idea what the Ruby process hang onto? Can you try adding something like this in main_thread = Thread.current
Thread.new do
loop
puts '-' * 40
puts main_thread.backtrace
sleep 1
end
end If it's stuck with the GVL released that should print the backtrace, if it's stuck in C land with the GVL held, it probably won't output anything once stuck. We'd at least know that. Also are you using NFS or some kind of shared volume (e.g. Docker Desktop or something)? |
Experiencing similar issues Logs using the snippet above in `config/boot.rb```` [LDClient] Stream initialized [44525] - Worker 0 (PID: 44656) booted in 0.23s, phase: 0 ---------------------------------------- /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/cluster.rb:437:in `wait_readable' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/cluster.rb:437:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/launcher.rb:193:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/rack/handler/puma.rb:72:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/rack-2.2.6.4/lib/rack/server.rb:327:in `start' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:38:in `start' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:143:in `block in perform' :90:in `tap' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:134:in `perform' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor/command.rb:27:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor/invocation.rb:127:in `invoke_command' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor.rb:392:in `dispatch' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/command/base.rb:87:in `perform' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/command.rb:48:in `invoke' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands.rb:18:in ` ' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require' bin/rails:4:in `' ---------------------------------------- /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/cluster.rb:437:in `wait_readable' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/cluster.rb:437:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/launcher.rb:193:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/rack/handler/puma.rb:72:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/rack-2.2.6.4/lib/rack/server.rb:327:in `start' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:38:in `start' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:143:in `block in perform' :90:in `tap' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:134:in `perform' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor/command.rb:27:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor/invocation.rb:127:in `invoke_command' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor.rb:392:in `dispatch' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/command/base.rb:87:in `perform' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/command.rb:48:in `invoke' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands.rb:18:in `' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require' bin/rails:4:in `' ---------------------------------------- /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/cluster.rb:437:in `wait_readable' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/cluster.rb:437:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/launcher.rb:193:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/rack/handler/puma.rb:72:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/rack-2.2.6.4/lib/rack/server.rb:327:in `start' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:38:in `start' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:143:in `block in perform' :90:in `tap' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:134:in `perform' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor/command.rb:27:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor/invocation.rb:127:in `invoke_command' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor.rb:392:in `dispatch' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/command/base.rb:87:in `perform' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/command.rb:48:in `invoke' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands.rb:18:in `' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require' bin/rails:4:in `' ---------------------------------------- /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/cluster.rb:437:in `wait_readable' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/cluster.rb:437:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/puma/launcher.rb:193:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/puma-5.6.5/lib/rack/handler/puma.rb:72:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/rack-2.2.6.4/lib/rack/server.rb:327:in `start' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:38:in `start' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:143:in `block in perform' :90:in `tap' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands/server/server_command.rb:134:in `perform' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor/command.rb:27:in `run' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor/invocation.rb:127:in `invoke_command' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/thor-1.2.1/lib/thor.rb:392:in `dispatch' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/command/base.rb:87:in `perform' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/command.rb:48:in `invoke' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/railties-7.0.4.3/lib/rails/commands.rb:18:in `' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require' /Users/kyle/.asdf/installs/ruby/3.2.1/lib/ruby/gems/3.2.0/gems/bootsnap-1.15.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:32:in `require' bin/rails:4:in `' ``` |
I get the sentiment here, but it's not super helpful. This has been reproduced on multiple machines. I'll add some more information that might help us see if this truly is something specific to bootsnap or not. I'm trying to understand more about the caching that bootsnap is doing to see why things work fine on that first app boot, but fail on the second. It's wrecking my brain trying to find what could be different/wrong on that second boot. It seems to be specific to Rails 7 and Ruby 3.2.X. Switching back to Ruby 3.1.2 with no other changes, resolves the issue. I haven't tried this with a lower version of Rails. This looks to be something specific to puma. I've found that bootsnap is working fine when using webrick. When I boot the app the second time after clearing the bootsnap cache, I start getting this error. Commenting out
I'm also going to try the suggestions you made for checking more things. Thanks for sharing that too. I'll report back on that shortly. |
I added the snippet you suggested (thanks for that!) and here's what I see being printed every 1 second
|
Thanks for the answers, I'll have another round of questions.
@kyle-annen is this a totally different app, or are you @themoffatt coworker? I'm a bit surprised to see two persons hitting such huge bug I never heard of the same week.
Apologies, I didn't mean to be snarky or anything, I just meant that these steps weren't actionable.
But same application, right?
That's a very useful information, thank you. If it's not too much trouble, trying
Also very interesting, that hints at a Mutex or Monitor issue. Initially I thought it could be another fallout from https://bugs.ruby-lang.org/issues/17827, but if that was the case, I think
Hum, so That is very weird, I don't get how that could possibly happen. Another question: Are you using
Thank you, however I realize my snippet was a bit incorrect, as since you are using Puma, the main thread isn't the one we care for. Here we simply see puma waiting for another request. Can you try this instead: Thread.new do
loop
puts '-' * 40
Thread.list.each do |thr|
puts main_thread.backtrace
sleep 1
end
end This will print the backtraces of all threads, so it should include the Rails request one, and that should tell us where it's stuck. |
Thanks @casperisfine. No worries, sorry we didn't post more info in the original. I've actually spun up a fresh rails app and don't see this issue with bootsnap on 3.2.1 either. So it has to be something specific with our app or the Gems we're using. My suspicion is GoodJob or LaunchDarkly. I'm going to try your suggestion above and report back. If nothing else, if we can find exactly what's causing this issue maybe it'll help someone in the future who has a similar setup to us. :) |
I made sure the issue is in bootsnap
Yes, deleting bootsnap cache folder consistently resolves the isssue.
Steps to reproduce
3.2.1
(or3.2.2
)rails s
tmp/cache/bootsnap
Expected behavior
Browser shouldn't hang on restart
Actual behavior
Browser hangs on restart
System configuration
Bootsnap version:
1.16.0
,1.15.0
Ruby version:
3.2.1
,3.2.2
Rails version:
7.0.4.3
The text was updated successfully, but these errors were encountered: