Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add Postgres LISTEN/NOTIFY support #82

Merged
merged 1 commit into from
Aug 19, 2020
Merged

Add Postgres LISTEN/NOTIFY support #82

merged 1 commit into from
Aug 19, 2020

Conversation

bensheldon
Copy link
Owner

@bensheldon bensheldon commented Aug 17, 2020

Closes #54

Thread Deadlock

There is a deadlock caused by the interaction between the Scheduler and the Notifier, when the Scheduler is instantiated before the Notifier is instantiated.

Problem Identified inside of Rails with Rails 6 and Classic Audoloader: Sidekiq hangs using Rails 6 app with "classic" autoloader

The deadlock reliably happens directly when running bundle exec good_job and the implementation can be adjusted by changing these lines: https://github.com/bensheldon/good_job/pull/82/files#diff-12faa12f1aae21d6e988253da1d9333eR22-R24

`ActionDispatch::DebugLocks` output
200
{"Content-Type"=>"text/plain", "Content-Length"=>15065}
Thread 0 [0x3fd8aeee7098 sleep]  No lock (yielded share)
  Waiting in start_exclusive to "load"
  may be pre-empted for: "load"
  blocked by: 1

/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:114:in `sleep'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:114:in `wait'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:114:in `block (2 levels) in wait'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:113:in `handle_interrupt'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:113:in `block in wait'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:109:in `handle_interrupt'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:109:in `wait'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:128:in `wait_while'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/concurrency/share_lock.rb:220:in `wait_for'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/concurrency/share_lock.rb:83:in `block (2 levels) in start_exclusive'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/concurrency/share_lock.rb:82:in `block in start_exclusive'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/2.6.0/monitor.rb:235:in `mon_synchronize'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/concurrency/share_lock.rb:77:in `start_exclusive'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/concurrency/share_lock.rb:149:in `exclusive'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies/interlock.rb:13:in `loading'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:40:in `load_interlock'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:389:in `require_or_load'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:544:in `load_missing_constant'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:214:in `const_missing'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:581:in `load_missing_constant'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:214:in `const_missing'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:581:in `load_missing_constant'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:214:in `const_missing'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/actiontext-6.0.3.2/lib/action_text/engine.rb:50:in `block (2 levels) in <class:Engine>'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:71:in `class_eval'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:71:in `block in execute_hook'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:61:in `with_execution_control'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:66:in `execute_hook'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:52:in `block in run_load_hooks'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:51:in `each'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:51:in `run_load_hooks'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/actiontext-6.0.3.2/lib/action_text/content.rb:132:in `<top (required)>'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:324:in `require'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:324:in `block in require'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:291:in `load_dependency'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:324:in `require'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/actiontext-6.0.3.2/lib/action_text/engine.rb:46:in `block (2 levels) in <class:Engine>'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:428:in `instance_exec'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:428:in `block in make_lambda'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:200:in `block (2 levels) in halting'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:605:in `block (2 levels) in default_terminator'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:604:in `catch'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:604:in `block in default_terminator'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:201:in `block in halting'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:513:in `block in invoke_before'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:513:in `each'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:513:in `invoke_before'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:134:in `run_callbacks'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:111:in `run!'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:73:in `block in run!'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:70:in `tap'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:70:in `run!'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:86:in `wrap'
/Users/bensheldon/Repositories/bensheldon/good_job/lib/good_job/scheduler.rb:142:in `block in create_thread'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:24:in `block in execute'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:19:in `execute'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/ivar.rb:169:in `safe_execute'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/future.rb:55:in `block in execute'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'


---


Thread 1 [0x3fd8aeeeacc0 sleep]  Sharing
  blocking: 0

/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/actiontext-6.0.3.2/lib/action_text/engine.rb:46:in `block (2 levels) in <class:Engine>'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:428:in `instance_exec'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:428:in `block in make_lambda'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:200:in `block (2 levels) in halting'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:605:in `block (2 levels) in default_terminator'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:604:in `catch'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:604:in `block in default_terminator'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:201:in `block in halting'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:513:in `block in invoke_before'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:513:in `each'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:513:in `invoke_before'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/callbacks.rb:134:in `run_callbacks'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:111:in `run!'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:73:in `block in run!'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:70:in `tap'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:70:in `run!'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/execution_wrapper.rb:86:in `wrap'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/activesupport-6.0.3.2/lib/active_support/reloader.rb:71:in `wrap'
/Users/bensheldon/Repositories/bensheldon/good_job/lib/good_job/notifier.rb:72:in `block in listen'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:24:in `block in execute'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:19:in `execute'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/ivar.rb:169:in `safe_execute'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/future.rb:55:in `block in execute'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
/Users/bensheldon/.rbenv/versions/2.6.6/lib/ruby/gems/2.6.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'

Workaround: Instantiate the Notifier before instantiating the Scheduler.

This is written out linear, but in reality the threads seem to be interwoven:

Main Scheduler Worker Thread Notifier Listen Thread
Scheduler.new
Scheduler#create_thread
executor.wrap
Performer#next
database connection
Notifier.new
Notifier#listen
reloader.wrap
database connection
permit_concurrent_loads
loop on pg_wait_for_notify

Debugging Thread Locks / Deadlocks

lib/good_job/notifier.rb Outdated Show resolved Hide resolved
lib/good_job/adapter.rb Outdated Show resolved Hide resolved
lib/good_job/cli.rb Outdated Show resolved Hide resolved
@bensheldon bensheldon force-pushed the listen_notify branch 7 times, most recently from d4bebd0 to 8b22ca6 Compare August 18, 2020 18:21
@bensheldon bensheldon merged commit a55dbf3 into main Aug 19, 2020
@bensheldon bensheldon deleted the listen_notify branch August 19, 2020 21:51
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Investigate Listen/Notify as alternative to polling
1 participant