Sometimes when running the rake task, the workers do not respond to SIGINT. I send a Ctrl+c and it says it's shutting down workers, but it doesn't. In fact I can hold Ctrl+c and it just floods the screen with "Shutting down workers" messages, but doesn't shut everything down. If I send the rake task to background with Ctrl+z and try to kill
the PID, it likewise doesn't respond. I end up having to kill -9
it.
Here is the console output from a run I just had where this occurred (sorry for the weird linebreaks, copied+pasted from my console):
^C2014-04-13T22:59:48Z p-23076 t-os3pt2j64 INFO: Heartbeat: running threads [54]
2014-04-13T22:59:48Z p-23076 t-os3q5m354 INFO: Shutting down workers
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store1:1:hhkhcb][#<ServerEngine::SignalThread:0x007f
29e3d16cd0>][store1][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2,
:workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :dur
able=>true, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:dir
ect, :hooks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: unsubscribing.
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store1:1:hhkhcb][#<ServerEngine::SignalThread:0x007f
29e3d16cd0>][store1][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2,
:workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :dur
able=>true, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:dir
ect, :hooks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: I'm gone.
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store2:1:fm59b2][#<ServerEngine::SignalThread:0x007f29e3
d16cd0>][store2][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2, :workers
=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :durable=>tr
ue, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:direct, :ho
oks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: unsubscribing.
Unexpected error Trying to send frame through a closed connection. Frame is #<AMQ::Protocol::MethodFrame:0x007f29ac0694
10 @payload="\x00<\x00\x1E bunny-1397429831000-559756359092\x00", @channel=2>, method class is AMQ::Protocol::Basic::Ca
ncel
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/session.rb:846:in `send_frame
'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/channel.rb:917:in `basic_canc
el'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/consumer.rb:84:in `cancel'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/queue.rb:48:in `uns
ubscribe'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/worker.rb:93:in `st
op'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:40:i
n `block in stop'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:39:i
n `each'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:39:i
n `stop'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/worker.rb:60:in
`block (2 levels) in install_signal_handlers'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/signal_thread.r
b:98:in `call'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/signal_thread.r
b:98:in `main'
^C2014-04-13T22:59:48Z p-23076 t-os3pt2j64 INFO: Heartbeat: running threads [54]
2014-04-13T22:59:48Z p-23076 t-os3q5m354 INFO: Shutting down workers
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store1:1:hhkhcb][#<ServerEngine::SignalThread:0x007f
29e3d16cd0>][store1][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2, :workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :dur
able=>true, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:dir
ect, :hooks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: unsubscribing.
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store1:1:hhkhcb][#<ServerEngine::SignalThread:0x007f
29e3d16cd0>][store1][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2,
:workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :dur
able=>true, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:dir
ect, :hooks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: I'm gone.
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store2:1:fm59b2][#<ServerEngine::SignalThread:0x007f29e3
d16cd0>][store2][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2, :workers
=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :durable=>tr
ue, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:direct, :ho
oks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: unsubscribing.
Unexpected error Trying to send frame through a closed connection. Frame is #<AMQ::Protocol::MethodFrame:0x007f29ac0731
18 @payload="\x00<\x00\x1E bunny-1397429831000-559756359092\x00", @channel=2>, method class is AMQ::Protocol::Basic::Ca
ncel
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/session.rb:846:in `send_frame
'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/channel.rb:917:in `basic_canc
el'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/consumer.rb:84:in `cancel'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/queue.rb:48:in `uns
ubscribe'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/worker.rb:93:in `st
op'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:40:i
n `block in stop'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:39:i
n `each'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:39:i
n `stop'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/worker.rb:60:in
`block (2 levels) in install_signal_handlers'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/signal_thread.r
b:98:in `call'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/signal_thread.r
b:98:in `main'
^C2014-04-13T22:59:48Z p-23076 t-os3pt2j64 INFO: Heartbeat: running threads [54]
2014-04-13T22:59:48Z p-23076 t-os3q5m354 INFO: Shutting down workers
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store1:1:hhkhcb][#<ServerEngine::SignalThread:0x007f
29e3d16cd0>][store1][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2,
:workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :dur
able=>true, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:dir
ect, :hooks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: unsubscribing.
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store1:1:hhkhcb][#<ServerEngine::SignalThread:0x007f
29e3d16cd0>][store1][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2,
:workers=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :dur
able=>true, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:dir
ect, :hooks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: I'm gone.
2014-04-13T22:59:48Z p-23076 t-os3q5m354 DEBUG: [worker-store2:1:fm59b2][#<ServerEngine::SignalThread:0x007f29e3
d16cd0>][store2][{:runner_config_file=>nil, :metrics=>nil, :daemonize=>false, :start_worker_delay=>0.2, :workers
=>4, :log=>#<IO:<STDOUT>>, :pid_path=>"sneakers.pid", :timeout_job_after=>30, :prefetch=>15, :threads=>15, :durable=>tr
ue, :ack=>true, :heartbeat=>2, :amqp=>"amqp://foo:[email protected]:5672", :vhost=>"/", :exchange=>"sneakers", :exchange_type=>:direct, :ho
oks=>{}, :handler=>Sneakers::Handlers::Oneshot}] Stopping worker: unsubscribing.
Unexpected error Trying to send frame through a closed connection. Frame is #<AMQ::Protocol::MethodFrame:0x007f29ac0796
08 @payload="\x00<\x00\x1E bunny-1397429831000-559756359092\x00", @channel=2>, method class is AMQ::Protocol::Basic::Ca
ncel
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/session.rb:846:in `send_frame
'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/channel.rb:917:in `basic_canc
el'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/bunny-1.1.9/lib/bunny/consumer.rb:84:in `cancel'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/queue.rb:48:in `uns
ubscribe'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/worker.rb:93:in `st
op'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:40:i
n `block in stop'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:39:i
n `each'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/sneakers-0.1.1.pre/lib/sneakers/workergroup.rb:39:i
n `stop'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/worker.rb:60:in
`block (2 levels) in install_signal_handlers'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/signal_thread.r
b:98:in `call'
/home/vagrant/.rbenv/versions/2.0.0-p451/lib/ruby/gems/2.0.0/gems/serverengine-1.5.7/lib/serverengine/signal_thread.r
b:98:in `main'
^Z
[1]+ Stopped rake sneakers:run
vagrant@precise-base:/vagrant$ ps aux | grep rake
vagrant 22926 2.6 0.4 1224600 32580 pts/1 Tl 22:57 0:04 ruby /home/vagrant/.rbenv/versions/2.0.0-p451/bin/rake
sneakers:run
vagrant 23076 5.8 2.1 3080344 176568 pts/1 Tl 22:57 0:09 ruby /home/vagrant/.rbenv/versions/2.0.0-p451/bin/rake
sneakers:run
vagrant 26499 0.0 0.0 8112 932 pts/1 S+ 22:59 0:00 grep rake
vagrant@precise-base:/vagrant$ kill 22926
vagrant@precise-base:/vagrant$ kill 23076
vagrant@precise-base:/vagrant$ ps aux | grep rake
vagrant 22926 2.3 0.4 1224600 32584 pts/1 Tl 22:57 0:04 ruby /home/vagrant/.rbenv/versions/2.0.0-p451/bin/rake
sneakers:run
vagrant 23076 5.1 2.1 3080344 176572 pts/1 Tl 22:57 0:09 ruby /home/vagrant/.rbenv/versions/2.0.0-p451/bin/rake
sneakers:run
vagrant@precise-base:/vagrant$ kill -9 22926
vagrant@precise-base:/vagrant$ kill -9 23076
-bash: kill: (23076) - No such process
[1]+ Killed rake sneakers:run