Skip to content

Wrap evaluation of db/seeds.rb with the executor#40626

Merged
rafaelfranca merged 1 commit intorails:masterfrom
jonathanhefner:executor-wrap-db-seeds
Nov 24, 2020
Merged

Wrap evaluation of db/seeds.rb with the executor#40626
rafaelfranca merged 1 commit intorails:masterfrom
jonathanhefner:executor-wrap-db-seeds

Conversation

@jonathanhefner
Copy link
Member

Before #34953, when using the :async Active Job queue adapter, jobs enqueued in db/seeds.rb, such as Active Storage analysis jobs, would cause a hang (see #34939). Therefore, #34953 changed all jobs enqueued in db/seeds.rb to use the :inline queue adapter instead. (This behavior was later limited to only take effect when the :async adapter was configured, see #35905.) However, inline jobs in db/seeds.rb cleared CurrentAttributes values (see #37526). Therefore, #37568 changed the :inline adapter to wrap each job in its own thread, for isolation. However, wrapping a job in its own thread affects which database connection it uses. Thus inline jobs can no longer execute within the calling thread's database transaction, including seeing any uncommitted changes. Additionally, if the calling thread is not wrapped with the executor, the inline job thread (which is wrapped with the executor) can deadlock on the load interlock. And when testing (with connection_pool.lock_thread = true), the inline job thread can deadlock on one of the locks added by #28083.

Therefore, this commit reverts the solutions of #34953 and #37568, and instead wraps evaluation of db/seeds.rb with the executor. This eliminates the original hang from #34939, which was also due to running multiple threads and not wrapping all of them with the executor. And, because nested calls to executor.wrap are ignored, any inline jobs in db/seeds.rb will not clear CurrentAttributes values.

Alternative fix for #34939.
Reverts #34953.
Reverts #35905.
Partially reverts #35896.

Alternative fix for #37526.
Reverts #37568.

Fixes #40552.


It's worth noting that rails db:seed will no longer run :async adapter jobs, because those jobs will wait for a lock acquired via executor.wrap, and then be killed by Concurrent::ThreadPoolExecutor when the process exits. However, this makes the :async adapter behave like all other non-:inline adapters, so I think it's reasonable. If we specifically want Active Storage analysis jobs to run during rails db:seed, we can add something like the following to load_seed:

ActiveSupport.on_load(:active_storage_job) { self.queue_adapter = :inline }

If there is interest in that, I will open a follow-up PR.

initializer :set_executor, before: :load_environment_hook do |app|
@executor = app.executor
@reloader = app.reloader
end
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this a bad idea? An alternative would be to add a load_seed callback and something like the following:

initializer :wrap_load_seed_with_executor do |app|
  self.class.set_callback(:load_seed, :around) do |_, loading|
    app.executor.wrap(&loading)
  end
end

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think engines should have their own executors and reloaders. I think we should go with a different implementation.

@eugeneius
Copy link
Member

This eliminates the original hang from #34939, which was also due to running multiple threads and not wrapping all of them with the executor.

Could you elaborate on this? It's not clear to me how wrapping the evaluation of db/seeds.rb with the executor solves the original problem.

@jonathanhefner
Copy link
Member Author

Could you elaborate on this? It's not clear to me how wrapping the evaluation of db/seeds.rb with the executor solves the original problem.

I was able to recreate the hang from #34939 with a load_seed definition like in this PR minus the executor.wrap call, and a db/seeds.rb file like:

Post.create!.image.attach(io: File.open("path/to/tiny.gif"), filename: "tiny.gif")
sleep 1
Post.create!

The sleep is to provoke the outcome of a race condition, but I can reproduce the hang without it fairly reliably by adding another .image.attach to the last line, as described in #34939. (With sleep, the main thread will hang when creating the Post; with .image.attach, it will hang when creating the 2nd attachment.) However, if the sleep is too long (e.g. sleep 10), the job thread will complete successfully, including performing a constants reload, which will cause the last line to raise NameError: uninitialized constant Post.

Running bin/rails db:drop db:create db:migrate db:seed, here are the thread backtraces during the hang:

Main thread backtrace
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:111:in `sleep'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:111:in `wait'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:111:in `block (2 levels) in wait'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:110:in `handle_interrupt'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:110:in `block in wait'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:106:in `handle_interrupt'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:106:in `wait'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:125:in `wait_while'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:220:in `wait_for'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:190:in `block in yield_shares'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:230:in `mon_synchronize'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:189:in `yield_shares'
rails/activesupport/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
rails/activerecord/lib/active_record/connection_adapters/sqlite3/database_statements.rb:47:in `block in exec_query'
rails/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb:687:in `block (2 levels) in log'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
rails/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb:686:in `block in log'
rails/activesupport/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
rails/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb:678:in `log'
rails/activerecord/lib/active_record/connection_adapters/sqlite3/database_statements.rb:46:in `exec_query'
rails/activerecord/lib/active_record/connection_adapters/abstract/database_statements.rb:136:in `exec_insert'
rails/activerecord/lib/active_record/connection_adapters/abstract/database_statements.rb:171:in `insert'
rails/activerecord/lib/active_record/connection_adapters/abstract/query_cache.rb:22:in `insert'
rails/activerecord/lib/active_record/persistence.rb:375:in `_insert_record'
rails/activerecord/lib/active_record/persistence.rb:929:in `_create_record'
rails/activerecord/lib/active_record/counter_cache.rb:166:in `_create_record'
rails/activerecord/lib/active_record/locking/optimistic.rb:79:in `_create_record'
rails/activerecord/lib/active_record/attribute_methods/dirty.rb:201:in `_create_record'
rails/activerecord/lib/active_record/callbacks.rb:461:in `block in _create_record'
rails/activesupport/lib/active_support/callbacks.rb:106:in `run_callbacks'
rails/activesupport/lib/active_support/callbacks.rb:824:in `_run_create_callbacks'
rails/activerecord/lib/active_record/callbacks.rb:461:in `_create_record'
rails/activerecord/lib/active_record/timestamp.rb:108:in `_create_record'
rails/activerecord/lib/active_record/persistence.rb:900:in `create_or_update'
rails/activerecord/lib/active_record/callbacks.rb:457:in `block in create_or_update'
rails/activesupport/lib/active_support/callbacks.rb:106:in `run_callbacks'
rails/activesupport/lib/active_support/callbacks.rb:824:in `_run_save_callbacks'
rails/activerecord/lib/active_record/callbacks.rb:457:in `create_or_update'
rails/activerecord/lib/active_record/timestamp.rb:126:in `create_or_update'
rails/activerecord/lib/active_record/persistence.rb:507:in `save!'
rails/activerecord/lib/active_record/validations.rb:53:in `save!'
rails/activerecord/lib/active_record/transactions.rb:300:in `block in save!'
rails/activerecord/lib/active_record/transactions.rb:352:in `block in with_transaction_returning_status'
rails/activerecord/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `block in transaction'
rails/activerecord/lib/active_record/connection_adapters/abstract/transaction.rb:310:in `block in within_new_transaction'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
rails/activerecord/lib/active_record/connection_adapters/abstract/transaction.rb:308:in `within_new_transaction'
rails/activerecord/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `transaction'
rails/activerecord/lib/active_record/transactions.rb:348:in `with_transaction_returning_status'
rails/activerecord/lib/active_record/transactions.rb:300:in `save!'
rails/activerecord/lib/active_record/suppressor.rb:48:in `save!'
rails/activerecord/lib/active_record/persistence.rb:55:in `create!'
myapp/db/seeds.rb:3:in `<top (required)>'
rails/railties/lib/rails/engine.rb:564:in `load'
rails/railties/lib/rails/engine.rb:564:in `load_seed'
rails/activerecord/lib/active_record/tasks/database_tasks.rb:449:in `load_seed'
rails/activerecord/lib/active_record/railties/databases.rake:386:in `block (2 levels) in <top (required)>'
gems/rake-13.0.1/lib/rake/task.rb:281:in `block in execute'
gems/rake-13.0.1/lib/rake/task.rb:281:in `each'
gems/rake-13.0.1/lib/rake/task.rb:281:in `execute'
gems/rake-13.0.1/lib/rake/task.rb:219:in `block in invoke_with_call_chain'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:230:in `mon_synchronize'
gems/rake-13.0.1/lib/rake/task.rb:199:in `invoke_with_call_chain'
gems/rake-13.0.1/lib/rake/task.rb:188:in `invoke'
gems/rake-13.0.1/lib/rake/application.rb:160:in `invoke_task'
gems/rake-13.0.1/lib/rake/application.rb:116:in `block (2 levels) in top_level'
gems/rake-13.0.1/lib/rake/application.rb:116:in `each'
gems/rake-13.0.1/lib/rake/application.rb:116:in `block in top_level'
gems/rake-13.0.1/lib/rake/application.rb:125:in `run_with_threads'
gems/rake-13.0.1/lib/rake/application.rb:110:in `top_level'
rails/railties/lib/rails/commands/rake/rake_command.rb:24:in `block (2 levels) in perform'
gems/rake-13.0.1/lib/rake/application.rb:186:in `standard_exception_handling'
rails/railties/lib/rails/commands/rake/rake_command.rb:24:in `block in perform'
gems/rake-13.0.1/lib/rake/rake_module.rb:59:in `with_application'
rails/railties/lib/rails/commands/rake/rake_command.rb:18:in `perform'
rails/railties/lib/rails/command.rb:52:in `invoke'
rails/railties/lib/rails/commands.rb:18:in `<top (required)>'
bin/rails:4:in `require'
bin/rails:4:in `<main>'
Job thread backtrace
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:189:in `lock'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:189:in `mon_enter'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `block in mon_enter'
rails/activesupport/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
rails/activesupport/lib/active_support/dependencies/interlock.rb:47:in `permit_concurrent_loads'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `mon_enter'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:22:in `block in synchronize'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
rails/activesupport/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:592:in `checkin'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:546:in `block (3 levels) in clear_reloadable_connections'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:543:in `each'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:543:in `block (2 levels) in clear_reloadable_connections'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:230:in `mon_synchronize'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:542:in `block in clear_reloadable_connections'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:744:in `block in with_exclusively_acquired_all_connections'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:819:in `with_new_connections_blocked'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:742:in `with_exclusively_acquired_all_connections'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:541:in `clear_reloadable_connections'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:565:in `clear_reloadable_connections!'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:1088:in `each'
rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:1088:in `clear_reloadable_connections!'
rails/activerecord/lib/active_record/connection_handling.rb:345:in `clear_reloadable_connections!'
rails/activerecord/lib/active_record/railtie.rb:235:in `block (3 levels) in <class:Railtie>'
rails/activesupport/lib/active_support/callbacks.rb:427:in `instance_exec'
rails/activesupport/lib/active_support/callbacks.rb:427:in `block in make_lambda'
rails/activesupport/lib/active_support/callbacks.rb:198:in `block (2 levels) in halting'
rails/activesupport/lib/active_support/callbacks.rb:604:in `block (2 levels) in default_terminator'
rails/activesupport/lib/active_support/callbacks.rb:603:in `catch'
rails/activesupport/lib/active_support/callbacks.rb:603:in `block in default_terminator'
rails/activesupport/lib/active_support/callbacks.rb:199:in `block in halting'
rails/activesupport/lib/active_support/callbacks.rb:512:in `block in invoke_before'
rails/activesupport/lib/active_support/callbacks.rb:512:in `each'
rails/activesupport/lib/active_support/callbacks.rb:512:in `invoke_before'
rails/activesupport/lib/active_support/callbacks.rb:105:in `run_callbacks'
rails/activesupport/lib/active_support/reloader.rb:120:in `class_unload!'
rails/railties/lib/rails/application/finisher.rb:246:in `block (2 levels) in <module:Finisher>'
rails/activesupport/lib/active_support/callbacks.rb:427:in `instance_exec'
rails/activesupport/lib/active_support/callbacks.rb:427:in `block in make_lambda'
rails/activesupport/lib/active_support/callbacks.rb:198:in `block (2 levels) in halting'
rails/activesupport/lib/active_support/callbacks.rb:604:in `block (2 levels) in default_terminator'
rails/activesupport/lib/active_support/callbacks.rb:603:in `catch'
rails/activesupport/lib/active_support/callbacks.rb:603:in `block in default_terminator'
rails/activesupport/lib/active_support/callbacks.rb:199:in `block in halting'
rails/activesupport/lib/active_support/callbacks.rb:512:in `block in invoke_before'
rails/activesupport/lib/active_support/callbacks.rb:512:in `each'
rails/activesupport/lib/active_support/callbacks.rb:512:in `invoke_before'
rails/activesupport/lib/active_support/callbacks.rb:105:in `run_callbacks'
rails/activesupport/lib/active_support/execution_wrapper.rb:111:in `run!'
rails/activesupport/lib/active_support/reloader.rb:114:in `run!'
rails/activesupport/lib/active_support/execution_wrapper.rb:73:in `block in run!'
rails/activesupport/lib/active_support/execution_wrapper.rb:70:in `tap'
rails/activesupport/lib/active_support/execution_wrapper.rb:70:in `run!'
rails/activesupport/lib/active_support/reloader.rb:63:in `run!'
rails/activesupport/lib/active_support/execution_wrapper.rb:86:in `wrap'
rails/activesupport/lib/active_support/reloader.rb:72:in `block in wrap'
rails/activesupport/lib/active_support/execution_wrapper.rb:88:in `wrap'
rails/activesupport/lib/active_support/reloader.rb:71:in `wrap'
rails/activejob/lib/active_job/railtie.rb:46:in `block (3 levels) in <class:Railtie>'
rails/activesupport/lib/active_support/callbacks.rb:126:in `instance_exec'
rails/activesupport/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
rails/activesupport/lib/active_support/callbacks.rb:137:in `run_callbacks'
rails/activejob/lib/active_job/execution.rb:23:in `execute'
rails/activejob/lib/active_job/queue_adapters/async_adapter.rb:70:in `perform'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:363:in `run_task'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:352:in `block (3 levels) in create_worker'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:335:in `loop'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:335:in `block (2 levels) in create_worker'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `catch'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `block in create_worker'

Weaving the relevant lines together in chronological order (via printf debugging!):

  1. (Job thread) rails/activejob/lib/active_job/railtie.rb:46:in 'block (3 levels) in <class:Railtie>'
  2. (Job thread) rails/railties/lib/rails/application/finisher.rb:246:in 'block (2 levels) in <module:Finisher>'
  3. (Job thread) rails/activesupport/lib/active_support/reloader.rb:120:in 'class_unload!'
    • At this point, the job thread has acquired the load interlock's lock via the call on line 119 to require_unload_lock!.
  4. (Job thread) rails/activerecord/lib/active_record/railtie.rb:235:in 'block (3 levels) in <class:Railtie>'
  5. (Main thread) myapp/db/seeds.rb:3:in '<top (required)>'
  6. (Main thread) rails/activerecord/lib/active_record/connection_adapters/abstract/transaction.rb:308:in 'within_new_transaction'
    • Here is where the main thread acquires the connection's lock.
  7. (Main thread) rails/activerecord/lib/active_record/connection_adapters/sqlite3/database_statements.rb:47:in 'block in exec_query'
    • Here is where the main thread deadlocks waiting for the load interlock's lock.
  8. (Job thread) rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:546:in 'block (3 levels) in clear_reloadable_connections'
  9. (Job thread) rails/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:592:in 'checkin'
    • Here is where the job thread deadlocks waiting for the connection's lock.

After adding the executor.wrap call to load_seed as in this PR, the process no longer hangs. Here is the backtrace of the job thread right after db/seeds.rb completes:

Job thread backtrace
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:111:in `sleep'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:111:in `wait'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:111:in `block (2 levels) in wait'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:110:in `handle_interrupt'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:110:in `block in wait'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:106:in `handle_interrupt'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:106:in `wait'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:125:in `wait_while'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:220:in `wait_for'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:83:in `block (2 levels) in start_exclusive'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:82:in `block in start_exclusive'
ruby-2.6.1/lib/ruby/2.6.0/monitor.rb:230:in `mon_synchronize'
rails/activesupport/lib/active_support/concurrency/share_lock.rb:77:in `start_exclusive'
rails/activesupport/lib/active_support/dependencies/interlock.rb:25:in `start_unloading'
rails/activesupport/lib/active_support/reloader.rb:100:in `require_unload_lock!'
rails/activesupport/lib/active_support/reloader.rb:119:in `class_unload!'
rails/railties/lib/rails/application/finisher.rb:246:in `block (2 levels) in <module:Finisher>'
rails/activesupport/lib/active_support/callbacks.rb:427:in `instance_exec'
rails/activesupport/lib/active_support/callbacks.rb:427:in `block in make_lambda'
rails/activesupport/lib/active_support/callbacks.rb:198:in `block (2 levels) in halting'
rails/activesupport/lib/active_support/callbacks.rb:604:in `block (2 levels) in default_terminator'
rails/activesupport/lib/active_support/callbacks.rb:603:in `catch'
rails/activesupport/lib/active_support/callbacks.rb:603:in `block in default_terminator'
rails/activesupport/lib/active_support/callbacks.rb:199:in `block in halting'
rails/activesupport/lib/active_support/callbacks.rb:512:in `block in invoke_before'
rails/activesupport/lib/active_support/callbacks.rb:512:in `each'
rails/activesupport/lib/active_support/callbacks.rb:512:in `invoke_before'
rails/activesupport/lib/active_support/callbacks.rb:105:in `run_callbacks'
rails/activesupport/lib/active_support/execution_wrapper.rb:111:in `run!'
rails/activesupport/lib/active_support/reloader.rb:114:in `run!'
rails/activesupport/lib/active_support/execution_wrapper.rb:73:in `block in run!'
rails/activesupport/lib/active_support/execution_wrapper.rb:70:in `tap'
rails/activesupport/lib/active_support/execution_wrapper.rb:70:in `run!'
rails/activesupport/lib/active_support/reloader.rb:63:in `run!'
rails/activesupport/lib/active_support/execution_wrapper.rb:86:in `wrap'
rails/activesupport/lib/active_support/reloader.rb:72:in `block in wrap'
rails/activesupport/lib/active_support/execution_wrapper.rb:88:in `wrap'
rails/activesupport/lib/active_support/reloader.rb:71:in `wrap'
rails/activejob/lib/active_job/railtie.rb:46:in `block (3 levels) in <class:Railtie>'
rails/activesupport/lib/active_support/callbacks.rb:126:in `instance_exec'
rails/activesupport/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
rails/activesupport/lib/active_support/callbacks.rb:137:in `run_callbacks'
rails/activejob/lib/active_job/execution.rb:23:in `execute'
rails/activejob/lib/active_job/queue_adapters/async_adapter.rb:70:in `perform'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:363:in `run_task'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:352:in `block (3 levels) in create_worker'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:335:in `loop'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:335:in `block (2 levels) in create_worker'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `catch'
gems/concurrent-ruby-1.1.7/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `block in create_worker'

The job thread did not reach rails/activesupport/lib/active_support/reloader.rb:120. It's waiting to acquire the load interlock's lock via the call on line 119 to require_unload_lock!, but the main thread owns the lock for the duration of the executor.wrap block due to this call via this hook.

I didn't think about this before, but the hang does go away when config.cache_classes is true because the reloader isn't used. That means that :async adapter jobs in db/seeds.rb would execute in production, but not in development, assuming the default config.cache_classes settings. But perhaps that matches how other non-:inline adapters are typically used?

Before rails#34953, when using the `:async` Active Job queue adapter, jobs
enqueued in `db/seeds.rb`, such as Active Storage analysis jobs, would
cause a hang (see rails#34939).  Therefore, rails#34953 changed all jobs enqueued
in `db/seeds.rb` to use the `:inline` queue adapter instead.  (This
behavior was later limited to only take effect when the `:async` adapter
was configured, see rails#35905.)  However, inline jobs in `db/seeds.rb`
cleared `CurrentAttributes` values (see rails#37526).  Therefore, rails#37568
changed the `:inline` adapter to wrap each job in its own thread, for
isolation.  However, wrapping a job in its own thread affects which
database connection it uses.  Thus inline jobs can no longer execute
within the calling thread's database transaction, including seeing any
uncommitted changes.  Additionally, if the calling thread is not wrapped
with the executor, the inline job thread (which is wrapped with the
executor) can deadlock on the load interlock.  And when testing (with
`connection_pool.lock_thread = true`), the inline job thread can
deadlock on one of the locks added by rails#28083.

Therefore, this commit reverts the solutions of rails#34953 and rails#37568, and
instead wraps evaluation of `db/seeds.rb` with the executor.  This
eliminates the original hang from rails#34939, which was also due to running
multiple threads and not wrapping all of them with the executor.  And,
because nested calls to `executor.wrap` are ignored, any inline jobs in
`db/seeds.rb` will not clear `CurrentAttributes` values.

Alternative fix for rails#34939.
Reverts rails#34953.
Reverts rails#35905.
Partially reverts rails#35896.

Alternative fix for rails#37526.
Reverts rails#37568.

Fixes rails#40552.
class Railtie
autoload :Configuration, "rails/railtie/configuration"

extend ActiveSupport::DescendantsTracker
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why this change? This is adding a lot of methods to railties that we don't need to add.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is to prevent Railtie.subclasses from being overridden by DescendantsTracker#subclasses when ActiveSupport::Callbacks is included in Engine (because ActiveSupport::Callbacks also extends DescendantsTracker). If Railtie.subclasses is overridden, then it will include abstract railties, which will raise an error when instantiated via Railties#initialize.

An alternative would be to move the abstract railties filtering logic to Railties#initialize, though that would change the contract of Railtie.subclasses.

It's worth mentioning, though, that DescendantsTracker would only add ::descendants and ::direct_descendants methods to railties.

@rafaelfranca rafaelfranca merged commit 90fa01b into rails:master Nov 24, 2020
@JasonBarnabe
Copy link
Contributor

The problem described in #40552 is still happening in Rails 6.1.0rc2 (but is not happening in master). Can we get this merged to the 6.1.0 branch?

@jprosevear
Copy link

jprosevear commented Dec 2, 2021

Did the follow up PR for ActiveSupport.on_load(:active_storage_job) { self.queue_adapter = :inline } ever get opened? This is a regression.

Inserting ActiveJob::Base.queue_adapter = :inline at the top of the seeds.rb file seems to be the work around for now.

@cantin
Copy link
Contributor

cantin commented Sep 1, 2022

The trick ActiveJob::Base.queue_adapter = :inline is not working for me. Instead, I need to wrap the seeds into Rails.application.reloader.wrap do.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6.1.0.rc1, after commit hook, ActiveJob :inline adapter, code lockup

6 participants