Puma does not shutdown gracefully

[Adithya-copart]

Using Ctrl + C or pumactl stop does not shutdown puma gracefully.

Gemfile:

ruby '2.5.0', engine: 'jruby', engine_version: '9.2.0.0'

gem 'sinatra'
gem 'sucker_punch'

gem 'pry'
gem 'puma'

Gemfile.lock:

  remote: https://rubygems.org/
  specs:
    coderay (1.1.2)
    concurrent-ruby (1.0.5-java)
    ffi (1.9.25-java)
    method_source (0.8.2)
    mustermann (1.0.3)
    pry (0.10.4-java)
      coderay (~> 1.1.0)
      method_source (~> 0.8.1)
      slop (~> 3.4)
      spoon (~> 0.0)
    puma (3.12.0-java)
    rack (2.0.5)
    rack-protection (2.0.0)
      rack
    sinatra (2.0.0)
      mustermann (~> 1.0)
      rack (~> 2.0)
      rack-protection (= 2.0.0)
      tilt (~> 2.0)
    slop (3.6.0)
    spoon (0.0.6)
      ffi
    sucker_punch (2.1.1)
      concurrent-ruby (~> 1.0)
    tilt (2.0.8)

PLATFORMS
  java

DEPENDENCIES
  pry
  puma
  sinatra
  sucker_punch

RUBY VERSION
   ruby 2.5.0p0 (jruby 9.2.0.0)

BUNDLED WITH
   1.16.5

test_app.rb:

class TestApp < Sinatra::Base

  class TestJob
    include SuckerPunch::Job

    def perform
      puts "The job #{self} is starting to sleep 5sec in #{Thread.current}"
      hsh = Thread.list.reduce({}) {|hsh,t| hsh[t] = t.status; hsh}
      # puts "Thread list in #{Thread.current}: #{hsh}"
      sleep 5
      puts "The job #{self} woke up from sleep in #{Thread.current}"
    end
  end

  get '/' do
    3.times {TestJob.perform_async}
  end

  get '/pry' do
    binding.pry
  end

end

config.ru

require 'sinatra/base'
require 'sucker_punch'
require 'pry'
require './test_app.rb'

run TestApp

Steps to reproduce

1. bundle install and then bundle exec puma.

2. Hit the URL get '/' to trigger the jobs.

3. Use Ctrl + C or pumactl stop.

Expected behavior

Puma should shutdown gracefully.

Actual behavior

Puma doesn't shutdown gracefully and prints the following every time Ctrl + C or pumactl stop -p <pid> is used:

Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2018-11-08 11:01:08 -0600 ===
- Goodbye!

The following is the first two lines after Ctrl + \

Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.181-b13 mixed mode):

"DestroyJavaVM" #23 prio=5 os_prio=31 tid=0x00007fc7da0d2000 nid=0x2703 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

However, graceful shutdown is successful when:

1. URL get '/' is not opened.
2. URL get '/pry' is opened followed by get '/'.

The results when using bundler/inline are different and the shutdown is successful.

test_app_bundler_inline:

require 'bundler/inline'

gemfile do
  source 'https://rubygems.org'

  ruby '2.5.0', engine: 'jruby', engine_version: '9.2.0.0'

  gem 'sucker_punch'
  gem 'puma'
  gem 'pry'
  gem 'sinatra'
end

require 'sinatra/base'
require 'sucker_punch'
require 'pry'

class TestApp < Sinatra::Base

  class TestJob
    include SuckerPunch::Job

    def perform
      puts "The job #{self} is starting to sleep 5sec in #{Thread.current}"
      hsh = Thread.list.reduce({}) {|hsh,t| hsh[t] = t.status; hsh}
      puts "Thread list in #{Thread.current}: #{hsh}"
      sleep 5
      puts "The job #{self} woke up from sleep in #{Thread.current}"
    end
  end

  get '/' do
    3.times {TestJob.perform_async}
  end

  get '/pry' do
    binding.pry
  end

  run! if app_file == $0
end

System configuration

Ruby version: jruby 9.2.0.0 (2.5.0) 2018-05-24 81156a8 Java HotSpot(TM) 64-Bit Server VM 25.181-b13 on 1.8.0_181-b13 +jit [darwin-x86_64]
Rails version: NA
Puma version: puma (3.12.0-java)

EDIT: Removed the reference to #1382 as it deals with workers in clustered mode.

[Adithya-copart]

Issue not with Puma. Opened a issue in suckerpunch.

[Adithya-copart]

I did some debugging and found out that at_exit hooks and the SIGINT trap introduced in 8903eea are running in different threads leading to a race condition which is not allowing the at_exit hook in sucker_punch.

This can be observed by adding a puts "#{Thread.current}" here and comparing it with the thread printed in the at_exit hook in test.rb.

## Config.ru

require 'sinatra'
require './test.rb'

run Test

## Gemfile
source 'https://rubygems.org'

ruby '2.5.0', engine: 'jruby', engine_version: '9.2.0.0'

gem 'sinatra','2.0.4'
gem 'puma','3.12.0'

## test.rb

class Test < Sinatra::Base
  at_exit { puts "Thread in test.rb at_exit: #{Thread.current}"}
end

[Adithya-copart]

Should be fixed by jruby/jruby#5441

[Adithya-copart]

Ignore my previous comments, the following code is the easiest way to reproduce this issue

require 'bundler/inline'

gemfile do
  source 'https://rubygems.org'

  gem 'sucker_punch'
  gem 'puma'
  gem 'sinatra'
end

# Enabling this exit handler will not reproduce the problem.

at_exit {p "Cleaning up........"}
# at_exit do
#  trace = TracePoint.new do |tp|
#     p [tp.path, tp.lineno, tp.method_id, tp.event, tp.raised_exception]
#   end

#   trace.enable
# end

require 'sucker_punch'
require 'sinatra'

set :bind,'0.0.0.0'

class TestJob
  include SuckerPunch::Job

  def perform
    puts "The job #{self} is starting to sleep 5sec"
    sleep 5
    puts "The job #{self} woke up from sleep"
  end
end

get '/' do
  p "Hello"
  3.times {TestJob.perform_async}
  p 'Enqueued job'
end

Thread.new do
  sleep 1 # Wait for startup
  require 'net/http'
  Net::HTTP.get(URI 'http://0.0.0.0:4567/')

  # TERM works but INT doesn't kill the puma process.
  puts "Sending SIGINT.."
  Process.kill('INT', Process.pid) 
end

This issue can be replicated in the above code using JRuby.
I tried 9.2.7.0 and jruby-head. I'm not sure if Puma is responsible for this behavior.

I tried debugging a little bit and will update this issue if I can find the root cause.

I tried using a at_exit handler with Tracepoint and did jruby --debug -S test.rb which did not replicate the behavior for some reason.

[dentarg]

@Adithya-copart what version of Puma are you using?

[Adithya-copart]

@dentarg Here is my Gemfile.lock.

GEM
  specs:
    concurrent-ruby (1.1.5)
    mustermann (1.0.3)
    nio4r (2.4.0-java)
    puma (4.0.1-java)
      nio4r (~> 2.0)
    rack (2.0.7)
    rack-protection (2.0.5)
      rack
    sinatra (2.0.5)
      mustermann (~> 1.0)
      rack (~> 2.0)
      rack-protection (= 2.0.5)
      tilt (~> 2.0)
    sucker_punch (2.1.2)
      concurrent-ruby (~> 1.0)
    tilt (2.0.9)

PLATFORMS
  java

DEPENDENCIES
  puma
  sinatra
  sucker_punch

BUNDLED WITH
   1.17.3

[Adithya-copart]

Sample app without suckerpunch.
Details: jruby/jruby#5437 (comment)

[nateberkopec]

Closed by #1961

_{Sent with GitHawk}