Puma is not shutting down gracefully while running suckerpunch Jobs

[Adithya-copart]

Also opened the same issue in Puma: https://github.com/puma/puma/issues/1675

Relates to #1382 : 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: Formatting

[brandonhilkert]

I don't use jruby. Happy to take a look at PRs, but unlikely to dig in myself.

[Adithya-copart]

@brandonhilkert I'm new to using jruby as well. Will try to add a PR if I can find the issue. Thanks for the quick response.

[Adithya-copart]

@brandonhilkert I went through the documentation and required sucker_punch before sinatra but still ran into the problem. I noticed that the exit is waiting forever here: https://github.com/brandonhilkert/sucker_punch/blob/d06ba290be4d56fbbd45d37f73c47bd441ad0224/lib/sucker_punch.rb#L54

I was able to bypass by moving the shutdown process into a new thread. Thread.new {SuckerPunch::Queue.shutdown_all}.join

Do you have any ideas on what might be causing this or where I should be looking?

[brandonhilkert]

I think you'd want to dig in to the shutdown_all function. It's pretty complex and has some atomic objects pulled from concurrent-ruby that may have different behavior on jruby. I'd started by figuring out where in that method things are blocked and that would give a better sense for what's causing it.

[Adithya-copart]

TL;DR: Closing this issue as it deals with JRuby signal handling.

I did RUBYOPT=-d bundle exec puma and encountered 'Exception `SystemExit' at org/jruby/RubyKernel.java:735 - exit' at sleep PAUSE_TIME in the shutdown_all method.

I commented out the sleep statement and the exception occurred again after executing the next two lines.

I did some googling and found out that the signal handling in JRuby is different. The reason I saw a graceful shutdown after opening a pry shell is because pry traps 'SIGINT'. https://github.com/pry/pry/blob/4b0b49bcbea76c46dd67b06adff0471b318997af/lib/pry/pry_class.rb#L117-L121

[brandonhilkert]

@Adithya-copart Nice find! Glad you got to the bottom of it.