Slow restarts #1730
Description
We love puma and have been using it for years... baffled by this one though! What are we missing?
Steps to reproduce
- puma configs
# web
tag "#{ENV['RAILS_ENV']}-app-puma"
environment ENV['RAILS_ENV']
pidfile "#{ENV['SHARED_PATH']}/puma.pid"
stdout_redirect "#{ENV['SHARED_PATH']}/log/#{ENV['RAILS_ENV']}_app_puma.stdout.log",
"#{ENV['SHARED_PATH']}/log/#{ENV['RAILS_ENV']}_app_puma.stderr.log",
false # don't append
bind "unix://#{ENV['SHARED_PATH']}/#{ENV['RAILS_ENV']}-app-puma.sock"
worker_timeout 30
threads 0,4
workers 1
preload_app!
on_worker_boot do
ActiveSupport.on_load(:active_record) do
ActiveRecord::Base.establish_connection
end
Que.mode = :off
end# action cable
tag "#{ENV['RAILS_ENV']}-app-puma-actioncable"
environment ENV['RAILS_ENV']
pidfile "#{ENV['SHARED_PATH']}/puma-actioncable.pid"
stdout_redirect "#{ENV['SHARED_PATH']}/log/#{ENV['RAILS_ENV']}_app_puma_actioncable.stdout.log",
"#{ENV['SHARED_PATH']}/log/#{ENV['RAILS_ENV']}_app_puma_actioncable.stderr.log",
false # don't append
bind "unix://#{ENV['SHARED_PATH']}/#{ENV['RAILS_ENV']}-app-puma-actioncable.sock"
worker_timeout 30
threads 1,4
workers 1- Action Cable Configs
All defaults except for:
config.action_cable.allowed_request_origins = ['https://www.app.com']
config.action_cable.logger = ActiveSupport::Logger.new(
File.join(Rails.root, 'log', "#{Rails.env}-cable.log")
)- Systemd
# web
[Unit]
Description=Rails Web Server
PartOf=staging-app.target
[Service]
EnvironmentFile=/etc/default/staging-app
User=staging-app
WorkingDirectory=/home/staging-app/app/current
Type=simple
Restart=always
KillMode=process
ExecStart=/bin/bash -lc 'bundle exec --keep-file-descriptors puma -C config/deploy/staging/puma.rb'
# cable
[Unit]
Description=Rails Cable Server
PartOf=staging-app.target
[Service]
EnvironmentFile=/etc/default/staging-app
User=staging-app
WorkingDirectory=/home/staging-app/app/current
Type=simple
Restart=always
KillMode=process
ExecStart=/bin/bash -lc 'bundle exec --keep-file-descriptors puma -C config/deploy/staging/puma-action-cable.rb'
- Restart
time sudo systemctl restart staging-app-puma.service
real 1m30.106s
user 0m0.011s
sys 0m0.000s
Expected behavior
Normally, we get instant restarts with puma.
Actual behavior
Restarts take 1m30s usually.
I have never seen it take this long, but we weren't the original developer of the application.
This application uses ActionCable running in a separate process with nginx sending all /cable requests to another process (also on puma). Both processes take the 1m30s to restart, the ActionCable config file is the same minus preload_app! and the on_worker_boot block.
The ActiveJob process restarts instantly.
Questions
- Is there a way to tell what is happening in puma after the restart is initiated?
- Is it expected Action Cable processes take a long time to stop restart? But with no Action Cable requests going to the puma web process, why is that slow to restart as well?
- Is this a known problem with 5.1? The client will be updating eventually.
- What are we missing?
System configuration
Ruby version: 2.6.0
Rails version: 5.1.6.1
Puma version: 3.12.0