mperham/sidekiq — Issue #43: Sidekiq hangs after Manager crashes
Author: maxjustus
Created: 2012-02-19 16:05:02+00:00
State: open

I got this exception on Heroku running Ruby 1.9.2 after a processor died due to an exception.
After this happened, no further processing occurred and I had to manually restart the sidekiq process.

Processor death: Waited 1 sec
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:25:in `block (2 levels) in timed_pop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:22:in `loop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:22:in `block in timed_pop'
:10:in `synchronize'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:21:in `timed_pop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/connection_pool.rb:57:in `checkout'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/connection_pool.rb:48:in `method_missing'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/server/unique_jobs.rb:12:in `call'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/chain.rb:73:in `block in invoke'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/server/airbrake.rb:6:in `call'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/chain.rb:73:in `block in invoke'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/chain.rb:76:in `call'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/chain.rb:76:in `invoke'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/processor.rb:37:in `block in process'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/processor.rb:66:in `stats'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/processor.rb:36:in `process'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/calls.rb:93:in `dispatch'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/actor.rb:181:in `block in handle_message'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/task.rb:45:in `block in initialize'
Processor death: Waited 1 sec
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:25:in `block (2 levels) in timed_pop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:22:in `loop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:22:in `block in timed_pop'
:10:in `synchronize'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:21:in `timed_pop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/connection_pool.rb:57:in `checkout'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/connection_pool.rb:48:in `method_missing'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/server/unique_jobs.rb:12:in `call'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/chain.rb:73:in `block in invoke'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/server/airbrake.rb:6:in `call'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/chain.rb:73:in `block in invoke'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/chain.rb:76:in `call'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/middleware/chain.rb:76:in `invoke'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/processor.rb:37:in `block in process'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/processor.rb:66:in `stats'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/processor.rb:36:in `process'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/calls.rb:93:in `dispatch'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/actor.rb:181:in `block in handle_message'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/task.rb:45:in `block in initialize'
E, [2012-02-19T09:03:29.704046 #1] ERROR -- : Sidekiq::Manager crashed!
Timeout::Error: Waited 1 sec
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:25:in `block (2 levels) in timed_pop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:22:in `loop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:22:in `block in timed_pop'
:10:in `synchronize'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/timed_queue.rb:21:in `timed_pop'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/connection_pool.rb:57:in `checkout'
/app/vendor/bundle/ruby/1.9.1/gems/connection_pool-0.1.0/lib/connection_pool.rb:48:in `method_missing'
/app/vendor/bundle/ruby/1.9.1/bundler/gems/sidekiq-4c7ae756c8b5/lib/sidekiq/processor.rb:30:in `initialize'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/calls.rb:47:in `dispatch'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/actor.rb:181:in `block in handle_message'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/task.rb:45:in `block in initialize'
E, [2012-02-19T09:03:29.704315 #1] ERROR -- : Sidekiq::Manager: ERROR HANDLER CRASHED!
ThreadError: Attempt to unlock a mutex which is not locked
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/mailbox.rb:101:in `unlock'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/mailbox.rb:101:in `ensure in shutdown'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/mailbox.rb:101:in `shutdown'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/actor.rb:212:in `cleanup'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/actor.rb:205:in `handle_crash'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/actor.rb:144:in `rescue in run'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/actor.rb:147:in `run'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/actor.rb:89:in `block in initialize'
/app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.8.0/lib/celluloid/thread_pool.rb:46:in `call'
in `block in create'

It looks like this may actually be partially a celluloid issue, Although it appears that mutex.unlock is meant to raise
an exception if the mutex wasn't already locked. I'm unsure if this is how Celluloid's mailbox is meant to work.

Perhaps Sidekiq just needs some sort of ability to restart a crashed Manager.
Or at the very least it needs to exit the process if the Manager crashes so that a monitoring process can restart Sidekiq.