rails icon indicating copy to clipboard operation
rails copied to clipboard
verified publisher icon rails

Test suite hangs after upgrading from 6.1 to 7.0

Open krebbl opened this issue 2 years ago • 30 comments

Steps to reproduce

We have a project with a multi-database (2 databases) configuration. When executing the test suite like follows the tests hang after some time.

PARALLEL_WORKERS=1 bin/rails test

As you can see in the sigdump all threads get stuck in load_interlock_aware_monitor.rb:17:in 'enter' I am currently trying to create an example project to reproduce this issue but maybe this info is enough for now to make some conclusions.

Sigdump at 2023-06-14 10:11:32 +0200 process 90089 (bin/rails)
  Thread #<Thread:0x00000001023db0f0 run> status=run priority=0
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:52:in `backtrace'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:52:in `dump_backtrace'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:34:in `block in dump_all_thread_backtrace'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:33:in `each'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:33:in `dump_all_thread_backtrace'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:16:in `block in dump'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:136:in `open'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:136:in `_open_dump_path'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:14:in `dump'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/sigdump-0.2.4/lib/sigdump.rb:7:in `block in setup'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `block in mon_enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/dependencies/interlock.rb:41:in `permit_concurrent_loads'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `mon_enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:22:in `block in synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/query_cache.rb:91:in `clear_query_cache'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_handling.rb:343:in `block in clear_on_handler'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_handling.rb:342:in `each'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_handling.rb:342:in `clear_on_handler'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_handling.rb:272:in `clear_query_caches_for_current_thread'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/query_cache.rb:21:in `insert'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/persistence.rb:496:in `_insert_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/persistence.rb:1096:in `_create_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/counter_cache.rb:166:in `_create_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/locking/optimistic.rb:79:in `_create_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/attribute_methods/dirty.rb:222:in `_create_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/callbacks.rb:459:in `block in _create_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:107:in `run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:929:in `_run_create_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/callbacks.rb:459:in `_create_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/timestamp.rb:108:in `_create_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/bullet-7.0.7/lib/bullet/active_record70.rb:6:in `_create_record'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/persistence.rb:1067:in `create_or_update'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/callbacks.rb:455:in `block in create_or_update'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/autosave_association.rb:370:in `around_save_collection_association'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:138:in `run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:929:in `_run_save_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/callbacks.rb:455:in `create_or_update'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/timestamp.rb:126:in `create_or_update'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/persistence.rb:648:in `save!'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/validations.rb:53:in `save!'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/transactions.rb:302:in `block in save!'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/transactions.rb:354:in `block in with_transaction_returning_status'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/transaction.rb:319:in `block in within_new_transaction'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/transaction.rb:317:in `within_new_transaction'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/database_statements.rb:316:in `transaction'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/transactions.rb:350:in `with_transaction_returning_status'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/transactions.rb:302:in `save!'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/suppressor.rb:54:in `save!'
      /Users/krebbl/Projects/ProCarement/care-center/app/models/medical_report.rb:121:in `save_report_as_document'
      /Users/krebbl/Projects/ProCarement/care-center/test/models/medical_report_test.rb:167:in `block (3 levels) in <class:MedicalReportTest>'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/testing/assertions.rb:34:in `assert_nothing_raised'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/testing/assertions.rb:250:in `_assert_nothing_raised_or_warn'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/testing/assertions.rb:102:in `assert_difference'
      /Users/krebbl/Projects/ProCarement/care-center/test/models/medical_report_test.rb:165:in `block (2 levels) in <class:MedicalReportTest>'
      /Users/krebbl/Projects/ProCarement/care-center/test/models/medical_report_test.rb:172:in `instance_exec'
      /Users/krebbl/Projects/ProCarement/care-center/test/models/medical_report_test.rb:172:in `block in create_test_from_should_hash'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/test.rb:102:in `block (3 levels) in run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/test.rb:199:in `capture_exceptions'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/test.rb:97:in `block (2 levels) in run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:296:in `time_it'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/test.rb:96:in `block in run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:391:in `on_signal'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/test.rb:247:in `with_info_handler'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/test.rb:95:in `run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-reporters-1.4.3/lib/minitest/reporters.rb:48:in `run_with_hooks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:1051:in `run_one_method'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:365:in `run_one_method'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:352:in `block (2 levels) in run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:351:in `each'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:351:in `block in run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:391:in `on_signal'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:378:in `with_info_handler'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:350:in `run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/railties-7.0.5/lib/rails/test_unit/line_filtering.rb:10:in `run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:182:in `block in __run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:182:in `map'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:182:in `__run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:159:in `run'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest.rb:83:in `block in autorun'
  Thread #<Thread:0x0000000109047888 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:40 sleep> status=sleep priority=0
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:46:in `sleep'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:46:in `block in spawn_thread'
  Thread #<Thread:0x0000000109443018@Timeout stdlib thread /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/timeout-0.3.2/lib/timeout.rb:101 sleep> status=sleep priority=0
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/timeout-0.3.2/lib/timeout.rb:113:in `sleep'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/timeout-0.3.2/lib/timeout.rb:113:in `wait'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/timeout-0.3.2/lib/timeout.rb:113:in `block (2 levels) in create_timeout_thread'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/timeout-0.3.2/lib/timeout.rb:111:in `synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/timeout-0.3.2/lib/timeout.rb:111:in `block in create_timeout_thread'
  Thread #<Thread:0x000000010c94b918 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:28 sleep_forever> status=sleep priority=0
      <internal:thread_sync>:18:in `pop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
  Thread #<Thread:0x000000010c94b800 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:28 sleep_forever> status=sleep priority=0
      <internal:thread_sync>:18:in `pop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
  Thread #<Thread:0x000000010c94b710 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:28 sleep_forever> status=sleep priority=0
      <internal:thread_sync>:18:in `pop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
  Thread #<Thread:0x000000010c94b620 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:28 sleep_forever> status=sleep priority=0
      <internal:thread_sync>:18:in `pop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
  Thread #<Thread:0x000000010c94b530 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:28 sleep_forever> status=sleep priority=0
      <internal:thread_sync>:18:in `pop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
  Thread #<Thread:0x000000010c94b440 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:28 sleep_forever> status=sleep priority=0
      <internal:thread_sync>:18:in `pop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
  Thread #<Thread:0x000000010c94b350 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:28 sleep_forever> status=sleep priority=0
      <internal:thread_sync>:18:in `pop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
  Thread #<Thread:0x000000010c94b260 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:28 sleep_forever> status=sleep priority=0
      <internal:thread_sync>:18:in `pop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/minitest-5.18.0/lib/minitest/parallel.rb:30:in `block (2 levels) in start'
  Thread #<Thread:0x000000010ce4f180@worker-1 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:332 sleep_forever> status=sleep priority=0
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `block in mon_enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/dependencies/interlock.rb:41:in `permit_concurrent_loads'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `mon_enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:22:in `block in synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/query_cache.rb:128:in `cache_sql'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/query_cache.rb:107:in `select_all'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/querying.rb:54:in `_query_by_sql'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:942:in `block in exec_main_query'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:962:in `skip_query_cache_if_necessary'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:928:in `exec_main_query'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:914:in `block in exec_queries'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:962:in `skip_query_cache_if_necessary'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:908:in `exec_queries'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:695:in `load'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:250:in `records'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/bullet-7.0.7/lib/bullet/active_record70.rb:46:in `records'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:520:in `find_take'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:98:in `take'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:473:in `find_one'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:457:in `find_with_ids'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:69:in `find'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/querying.rb:22:in `find'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/core.rb:271:in `find'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:129:in `locate'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:154:in `block in locate'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:164:in `block in unscoped'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:881:in `_scoping'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:428:in `scoping'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/scoping/default.rb:43:in `unscoped'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:164:in `unscoped'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:154:in `locate'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:16:in `locate'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:148:in `deserialize_global_id'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:132:in `deserialize_argument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:43:in `block in deserialize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:43:in `map'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:43:in `deserialize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/core.rb:190:in `deserialize_arguments'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/core.rb:180:in `deserialize_arguments_if_needed'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/execution.rb:44:in `perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/instrumentation.rb:14:in `block in perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/instrumentation.rb:25:in `block in instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/notifications.rb:206:in `block in instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/notifications.rb:206:in `instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/instrumentation.rb:35:in `instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/instrumentation.rb:14:in `perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/logging.rb:18:in `block in perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/tagged_logging.rb:99:in `block in tagged'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/tagged_logging.rb:37:in `tagged'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/tagged_logging.rb:99:in `tagged'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/logging.rb:25:in `tag_logger'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/logging.rb:18:in `perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/execution.rb:24:in `block in execute'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/railtie.rb:54:in `block (4 levels) in <class:Railtie>'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/execution_wrapper.rb:92:in `wrap'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/reloader.rb:72:in `block in wrap'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/execution_wrapper.rb:92:in `wrap'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/reloader.rb:71:in `wrap'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/railtie.rb:53:in `block (3 levels) in <class:Railtie>'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:127:in `instance_exec'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:138:in `run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/execution.rb:22:in `execute'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/queue_adapters/async_adapter.rb:70:in `perform'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:352:in `run_task'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:343:in `block (3 levels) in create_worker'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `loop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `block (2 levels) in create_worker'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `catch'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `block in create_worker'
  Thread #<Thread:0x000000010d989d20@worker-2 /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:332 sleep_forever> status=sleep priority=0
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `block in mon_enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/dependencies/interlock.rb:41:in `permit_concurrent_loads'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:17:in `mon_enter'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:22:in `block in synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/query_cache.rb:128:in `cache_sql'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/connection_adapters/abstract/query_cache.rb:107:in `select_all'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/querying.rb:54:in `_query_by_sql'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:942:in `block in exec_main_query'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:962:in `skip_query_cache_if_necessary'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:928:in `exec_main_query'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:914:in `block in exec_queries'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:962:in `skip_query_cache_if_necessary'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:908:in `exec_queries'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:695:in `load'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:250:in `records'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/bullet-7.0.7/lib/bullet/active_record70.rb:46:in `records'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:520:in `find_take'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:98:in `take'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:473:in `find_one'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:457:in `find_with_ids'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation/finder_methods.rb:69:in `find'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/querying.rb:22:in `find'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/core.rb:271:in `find'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:129:in `locate'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:154:in `block in locate'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:164:in `block in unscoped'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:881:in `_scoping'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/relation.rb:428:in `scoping'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activerecord-7.0.5/lib/active_record/scoping/default.rb:43:in `unscoped'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:164:in `unscoped'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:154:in `locate'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/globalid-1.1.0/lib/global_id/locator.rb:16:in `locate'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:148:in `deserialize_global_id'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:132:in `deserialize_argument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:43:in `block in deserialize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:43:in `map'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/arguments.rb:43:in `deserialize'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/core.rb:190:in `deserialize_arguments'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/core.rb:180:in `deserialize_arguments_if_needed'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/execution.rb:44:in `perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/instrumentation.rb:14:in `block in perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/instrumentation.rb:25:in `block in instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/notifications.rb:206:in `block in instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/notifications.rb:206:in `instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/instrumentation.rb:35:in `instrument'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/instrumentation.rb:14:in `perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/logging.rb:18:in `block in perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/tagged_logging.rb:99:in `block in tagged'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/tagged_logging.rb:37:in `tagged'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/tagged_logging.rb:99:in `tagged'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/logging.rb:25:in `tag_logger'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/logging.rb:18:in `perform_now'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/execution.rb:24:in `block in execute'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/railtie.rb:54:in `block (4 levels) in <class:Railtie>'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/execution_wrapper.rb:92:in `wrap'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/reloader.rb:72:in `block in wrap'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/execution_wrapper.rb:92:in `wrap'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/reloader.rb:71:in `wrap'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/railtie.rb:53:in `block (3 levels) in <class:Railtie>'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:127:in `instance_exec'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activesupport-7.0.5/lib/active_support/callbacks.rb:138:in `run_callbacks'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/execution.rb:22:in `execute'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/activejob-7.0.5/lib/active_job/queue_adapters/async_adapter.rb:70:in `perform'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:352:in `run_task'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:343:in `block (3 levels) in create_worker'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `loop'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `block (2 levels) in create_worker'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `catch'
      /Users/krebbl/.rbenv/versions/3.2.0/lib/ruby/gems/3.2.0/gems/concurrent-ruby-1.2.2/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `block in create_worker'

Expected behavior

The tests should just run through

Actual behavior

The tests get stuck after some while

System configuration

Rails version: 7.0.5 Ruby version: 3.2.0

krebbl avatar Jun 14 '23 08:06 krebbl

Hi @krebbl there's not enough information here for us to determine what's wrong. We don't have the bandwidth for application support and haven't received any other reports of behavior like this.

I noticed that you're using parallel testing via threads from minitest. Did you upgrade minitest at the same time as Rails? I would try downgrading some gems or at least getting the test suite down to a smaller failure set. Without a reproduction, we can't determine if this originates from Rails or how to fix it.

eileencodes avatar Jun 14 '23 13:06 eileencodes

Ok, after some deeper digging I found that the reason for the deadlocks are some active job calls with perform_later. If I change all these calls to perform_now the test suite runs smoothly. I will try to prepare an example to reproduce this behaviour.

krebbl avatar Jun 15 '23 12:06 krebbl

For anyone who also runs in this problem, we have solved the issue by clearing the job queue after each test:

class ActiveSupport::TestCase
  teardown do
    clear_enqueued_jobs
  end
end

krebbl avatar Jun 20 '23 08:06 krebbl

Which job runner are you using for tests?

rafaelfranca avatar Jun 20 '23 15:06 rafaelfranca

The default one ... so no sidekiq

krebbl avatar Jun 26 '23 09:06 krebbl

Could you check if changing the adapter to be the inline your issue goes away?

Rails.application.config.active_job.queue_adapter = :inline

rafaelfranca avatar Jun 26 '23 17:06 rafaelfranca

@rafaelfranca thanks for the hint, with the inline adapter it works!

krebbl avatar Jun 27 '23 10:06 krebbl

This seems to be the same issue as https://github.com/rails/rails/issues/45994.

Could you check if applying the patch that fixed that issue fixes your problem as well?

rafaelfranca avatar Jun 27 '23 16:06 rafaelfranca

@rafaelfranca which patch exactly do you mean? this one https://github.com/rails/rails/pull/46553 ?

krebbl avatar Jun 29 '23 13:06 krebbl

Yes

rafaelfranca avatar Jun 29 '23 14:06 rafaelfranca

is this patch included in 7.0.6?

krebbl avatar Jun 29 '23 21:06 krebbl

Doesn't seems so. You could try to backport to your fork of Rails in the 7-0-stable branch and try to see if it fixed the problem.

rafaelfranca avatar Jun 30 '23 17:06 rafaelfranca

This issue has been automatically closed because there has been no follow-up response from the original author. We currently don't have enough information in order to take action. Please reach out if you have any additional information that will help us move this issue forward.

rails-bot[bot] avatar Aug 19 '23 21:08 rails-bot[bot]

@krebbl did you solve this? Did the patch work for you? Curious as I'm investigating frequently hanging specs with 7.1.0.beta1 (which would have the patch) and similar backtraces. I can also workaround with config.active_job.queue_adapter = :inline (or by removing an after_commit callback to UserMailer deliver_later).

ansonhoyt avatar Sep 18 '23 13:09 ansonhoyt

@ansonhoyt hi, I was not able to apply the patch to the latest release version, because there were too many differences or so. we now just use the workaround with :inline. I think the issue is that the Jobs are not closing or returning their used threads to the threadpool and once empty the remaining jobs are not starting anymore.

krebbl avatar Sep 21 '23 10:09 krebbl

Thanks for the update! 🙏 I narrowed mine down to a set of 3 specs, and was able to avoid it by wrapping the triggering spec with ActiveJob::TestHelper's perform_enqueued_jobs. I haven't been able to create a reproduction yet, but hope to try again after I catch up on some deadlines.

ansonhoyt avatar Sep 21 '23 17:09 ansonhoyt

Strangely enough, I had this issue when upgrading from 7.0 to 7.1 version. I fixed it by setting queue_adapter option like @rafaelfranca mentioned here.

# config/environments/test.rb

Rails.application.configure do
  config.active_job.queue_adapter = :inline
end

rainerborene avatar Oct 06 '23 01:10 rainerborene

I had a similar issue when upgrading from 7.0.8 to 7.1.1. Spent quite some hours trying to figure out why it hangs but have not been succesful. What I've found so far:

  • The default queue_adapter on the test environment is set to :async unless we include the ActiveJob::TestHelper or explicitly set the queue_adapter to :test.
  • Having the async queue adapter allows jobs to run outside of the transaction that wraps the tests. This can cause an ActiveJob::DeserializationError as the original object passed to the job no longer exists in the database.
  • This is exactly what happens whenever my test suite hangs, a job is executed, but fails due to being executed after the transaction is rolled back.
  • The job running outside of the transaction and failing due to the record passed along no longer existing already existed in Rails 7.0.8 (I rolled back the application locally to test this), but the test suite would not hang on it.

My assumption then is that somehow the thread running the job asynchronously does not exit properly when the job errors and therefore blocks further test execution. However, I'm not sure how to diagnose this.

I was able to recreate the 'job executing outside of the test transaction behaviour' in a new rails project for which I created a repo: nbelzer/rails-async-test-queue-example. However, I was not able to replicate the test suite hanging in this repo, which would indicate that I'm still missing an ingredient.

Regardless in all situations where the test suite hangs for me, a failed job with a ActiveJob::DeserializationError is the last part of the test.log. This leads me to believe that the two are related and fixing the first, would solve the latter.

The solution for me has been to set the queue_adapter to :test in the test environment, but I wonder why the default is :async.

I'll keep an eye on this issue as I'd like to figure out what is causing the hanging. I'm out of clues for now, but hopefully, by sharing these findings someone else is able to find the next one.

nbelzer avatar Oct 19 '23 20:10 nbelzer

Thanks @nbelzer! I think you found the root of the problems.

I had the same problems for 2 different Rails apps after updating to 7.1

Setting the queue_adapter to :inline led to a different error during the tests:

NotImplementedError: Use a queueing backend to enqueue jobs in the future. Read more at https://guides.rubyonrails.org/active_job_basics.html

But doing what @nbelzer did solved the problem for me:

# environments/test.rb
config.active_job.queue_adapter = :test

I think this line should be automatically added to environments/test.rb while upgrading Rails to 7.1. Unless there is a good reason (like test performance?) why we would want :async as the default queue_adapter, but then this issue needs to be fixed.

edit:

btw. in my case I experienced the problems with minitest. So it doesn't affect only rspec.

arusa avatar Oct 25 '23 19:10 arusa

I also hit this when upgrading from Rails 7.0 to 7.1 but was never able to create a good minimal reproduction. Like the others if I add config.active_job.queue_adapter = :test.

I was able to do a git bisect between Rails 7.0 and 7.1 and it started being an issue from the commits in this PR

eric1234 avatar Nov 23 '23 21:11 eric1234

I got the same problem, thanks for the tip @nbelzer, In my case, I'm using minitest and also Rails Event Store library, so I have a bunch of background jobs that trigger on events generated.

config.active_job.queue_adapter = :test totally fixed my problem. Before I was either having hanging tests or multiple errors such as:

ActiveRecord::StatementInvalid: PG::UnableToSend: insufficient data in "T" message

    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/postgresql/database_statements.rb:55:in `exec'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/postgresql/database_statements.rb:55:in `block (2 levels) in raw_execute'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract_adapter.rb:1028:in `block in with_raw_connection'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.1.2/lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract_adapter.rb:1000:in `with_raw_connection'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/postgresql/database_statements.rb:54:in `block in raw_execute'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.1.2/lib/active_support/notifications/instrumenter.rb:58:in `instrument'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract_adapter.rb:1143:in `log'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/postgresql/database_statements.rb:53:in `raw_execute'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/database_statements.rb:521:in `internal_execute'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/postgresql/database_statements.rb:101:in `begin_db_transaction'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/transaction.rb:373:in `materialize!'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/transaction.rb:449:in `block in begin_transaction'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.1.2/lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/transaction.rb:416:in `begin_transaction'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/database_statements.rb:352:in `begin_transaction'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/test_fixtures.rb:149:in `block in setup_fixtures'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/test_fixtures.rb:148:in `each'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/test_fixtures.rb:148:in `setup_fixtures'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.1.2/lib/active_record/test_fixtures.rb:10:in `before_setup'
    /home/mendes/.rbenv/versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.1.2/lib/active_support/testing/setup_and_teardown.rb:40:in `before_setup'

Rails 7.1.2

Mendes11 avatar Dec 15 '23 13:12 Mendes11

I had same issue with deliver_later and rspec test. Test hangs or sometimes I got some of those errors:

     ActiveRecord::StatementInvalid:
       PG::UnableToSend: insufficient data in "T" message

message type 0x32 arrived from server while idle
message type 0x54 arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle

What I had in test:

        expect(MyMailer).to receive(:notification).once.and_call_original
        MyMailer.notification

I changed it to:

        dbl = double
        expect(MyMailer).to receive(:notification).once.and_return(dbl)
        expect(dbl).to receive(:deliver_later).once
        MyMailer.notification

1v avatar Jan 11 '24 23:01 1v

I recently upgraded to rails 7.1.3 and changed to SolidQueue. I ran in to this issue where tests would hang. Setting config.active_job.queue_adapter = :test in test.rb solved it for me too. I actually thought it defaulted to that and I previously didn't have queue_adapter set in test.rb at all.

Thanks!

atstockland avatar Jan 30 '24 02:01 atstockland

My unit tests are getting stuck sometimes too. I don't use ActiveJob at all.

In github actions output I see something like this:

message type 0x32 arrived from server while idle
message type 0x54 arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle

Theory – parallel tests use fork and it causes issues with postgresql?

https://www.postgresql.org/docs/current/libpq-connect.html#LIBPQ-CONNECT

On Unix, forking a process with open libpq connections can lead to unpredictable results because the parent and child processes share the same sockets and operating system resources. For this reason, such usage is not recommended, though doing an exec from the child process to load a new executable is safe.

xeron avatar Apr 12 '24 16:04 xeron

I believe we just got hit by this as well. Brand new rails app on 7.1.3.2 on ruby 3.3.1. Our rspec suite randomly hangs a small portion of the time. I was able to get a sigdump of it (which is below). It looks like both our rspec test and an active storage analyze job thread are deadlocked.

2024-05-16T18:37:01.8164184Z Sigdump at 2024-05-16 18:37:01 +0000 process 1 (/home/app/bundle/ruby/3.3.0/bin/rspec)
2024-05-16T18:37:01.8166269Z   Thread #<Thread:0x00007f116812a978 sleep_forever> status=sleep priority=0
2024-05-16T18:37:01.8206900Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:55:in `lock'
2024-05-16T18:37:01.8209474Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:55:in `mon_enter'
2024-05-16T18:37:01.8220746Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:15:in `block in mon_enter'
2024-05-16T18:37:01.8223388Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'
2024-05-16T18:37:01.8225835Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/dependencies/interlock.rb:41:in `permit_concurrent_loads'
2024-05-16T18:37:01.8228532Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:15:in `mon_enter'
2024-05-16T18:37:01.8231210Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:20:in `block in synchronize'
2024-05-16T18:37:01.8234357Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `handle_interrupt'
2024-05-16T18:37:01.8237157Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `synchronize'
2024-05-16T18:37:01.8239776Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract_adapter.rb:1000:in `with_raw_connection'
2024-05-16T18:37:01.8242520Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql/quoting.rb:75:in `quote_string'
2024-05-16T18:37:01.8244962Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/quoting.rb:15:in `quote'
2024-05-16T18:37:01.8247359Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql/quoting.rb:69:in `quote'
2024-05-16T18:37:01.8250060Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql_adapter.rb:1084:in `column_definitions'
2024-05-16T18:37:01.8253164Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/schema_statements.rb:109:in `columns'
2024-05-16T18:37:01.8255929Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/schema_cache.rb:346:in `block in columns'
2024-05-16T18:37:01.8258331Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/schema_cache.rb:345:in `fetch'
2024-05-16T18:37:01.8260680Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/schema_cache.rb:345:in `columns'
2024-05-16T18:37:01.8263270Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/schema_cache.rb:354:in `block in columns_hash'
2024-05-16T18:37:01.8265694Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/schema_cache.rb:353:in `fetch'
2024-05-16T18:37:01.8268072Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/schema_cache.rb:353:in `columns_hash'
2024-05-16T18:37:01.8270921Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/schema_cache.rb:58:in `columns_hash'
2024-05-16T18:37:01.8273549Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/schema_cache.rb:188:in `columns_hash'
2024-05-16T18:37:01.8275910Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/model_schema.rb:618:in `load_schema!'
2024-05-16T18:37:01.8278061Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/attributes.rb:264:in `load_schema!'
2024-05-16T18:37:01.8280291Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/encryption/encryptable_record.rb:127:in `load_schema!'
2024-05-16T18:37:01.8282748Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/model_schema.rb:563:in `block in load_schema'
2024-05-16T18:37:01.8284906Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/model_schema.rb:560:in `synchronize'
2024-05-16T18:37:01.8287070Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/model_schema.rb:560:in `load_schema'
2024-05-16T18:37:01.8289151Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/model_schema.rb:425:in `columns_hash'
2024-05-16T18:37:01.8291322Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation/query_methods.rb:1796:in `arel_column'
2024-05-16T18:37:01.8293751Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation/calculations.rb:444:in `aggregate_column'
2024-05-16T18:37:01.8296222Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation/calculations.rb:464:in `execute_simple_calculation'
2024-05-16T18:37:01.8298695Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation/calculations.rb:433:in `perform_calculation'
2024-05-16T18:37:01.8301115Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation/calculations.rb:245:in `calculate'
2024-05-16T18:37:01.8303301Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation/calculations.rb:102:in `count'
2024-05-16T18:37:01.8305378Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/querying.rb:23:in `count'
2024-05-16T18:37:01.8307109Z       /home/app/app/spec/support/shared_examples/factory_examples.rb:9:in `block (4 levels) in <main>'
2024-05-16T18:37:01.8309294Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/matchers/built_in/change.rb:425:in `evaluate_value_proc'
2024-05-16T18:37:01.8311806Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/matchers/built_in/change.rb:390:in `perform_change'
2024-05-16T18:37:01.8314679Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/matchers/built_in/change.rb:223:in `perform_change'
2024-05-16T18:37:01.8317197Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/matchers/built_in/change.rb:193:in `matches?'
2024-05-16T18:37:01.8319640Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/handler.rb:51:in `block in handle_matcher'
2024-05-16T18:37:01.8321978Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/handler.rb:27:in `with_matcher'
2024-05-16T18:37:01.8324413Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/handler.rb:48:in `handle_matcher'
2024-05-16T18:37:01.8326672Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/expectation_target.rb:65:in `to'
2024-05-16T18:37:01.8328955Z       /home/app/bundle/ruby/3.3.0/gems/rspec-expectations-3.13.0/lib/rspec/expectations/expectation_target.rb:139:in `to'
2024-05-16T18:37:01.8330987Z       /home/app/app/spec/support/shared_examples/factory_examples.rb:8:in `block (3 levels) in <main>'
2024-05-16T18:37:01.8332900Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:263:in `instance_exec'
2024-05-16T18:37:01.8335093Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:263:in `block in run'
2024-05-16T18:37:01.8337345Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:511:in `block in with_around_and_singleton_context_hooks'
2024-05-16T18:37:01.8339735Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:468:in `block in with_around_example_hooks'
2024-05-16T18:37:01.8350388Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:486:in `block in run'
2024-05-16T18:37:01.8352535Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:626:in `block in run_around_example_hooks_for'
2024-05-16T18:37:01.8354766Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:352:in `call'
2024-05-16T18:37:01.8357156Z       /home/app/bundle/ruby/3.3.0/gems/rspec-rails-6.1.2/lib/rspec/rails/adapters.rb:75:in `block (2 levels) in <module:MinitestLifecycleAdapter>'
2024-05-16T18:37:01.8359463Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:457:in `instance_exec'
2024-05-16T18:37:01.8361441Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:457:in `instance_exec'
2024-05-16T18:37:01.8363384Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:390:in `execute_with'
2024-05-16T18:37:01.8365569Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:628:in `block (2 levels) in run_around_example_hooks_for'
2024-05-16T18:37:01.8367777Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:352:in `call'
2024-05-16T18:37:01.8369728Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:629:in `run_around_example_hooks_for'
2024-05-16T18:37:01.8371711Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/hooks.rb:486:in `run'
2024-05-16T18:37:01.8373660Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:468:in `with_around_example_hooks'
2024-05-16T18:37:01.8375929Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:511:in `with_around_and_singleton_context_hooks'
2024-05-16T18:37:01.8378044Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example.rb:259:in `run'
2024-05-16T18:37:01.8379972Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:646:in `block in run_examples'
2024-05-16T18:37:01.8381940Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:642:in `map'
2024-05-16T18:37:01.8384209Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:642:in `run_examples'
2024-05-16T18:37:01.8386131Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:607:in `run'
2024-05-16T18:37:01.8388184Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:608:in `block in run'
2024-05-16T18:37:01.8390065Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:608:in `map'
2024-05-16T18:37:01.8391930Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:608:in `run'
2024-05-16T18:37:01.8394336Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:608:in `block in run'
2024-05-16T18:37:01.8396254Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:608:in `map'
2024-05-16T18:37:01.8398083Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/example_group.rb:608:in `run'
2024-05-16T18:37:01.8400241Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:121:in `block (3 levels) in run_specs'
2024-05-16T18:37:01.8402176Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:121:in `map'
2024-05-16T18:37:01.8404516Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:121:in `block (2 levels) in run_specs'
2024-05-16T18:37:01.8406711Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/configuration.rb:2091:in `with_suite_hooks'
2024-05-16T18:37:01.8408754Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:116:in `block in run_specs'
2024-05-16T18:37:01.8410696Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/reporter.rb:74:in `report'
2024-05-16T18:37:01.8412484Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:115:in `run_specs'
2024-05-16T18:37:01.8414294Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:89:in `run'
2024-05-16T18:37:01.8415960Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:71:in `run'
2024-05-16T18:37:01.8417639Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/lib/rspec/core/runner.rb:45:in `invoke'
2024-05-16T18:37:01.8419388Z       /home/app/bundle/ruby/3.3.0/gems/rspec-core-3.13.0/exe/rspec:4:in `<top (required)>'
2024-05-16T18:37:01.8420609Z       /home/app/bundle/ruby/3.3.0/bin/rspec:25:in `load'
2024-05-16T18:37:01.8421612Z       /home/app/bundle/ruby/3.3.0/bin/rspec:25:in `<top (required)>'
2024-05-16T18:37:01.8422898Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/cli/exec.rb:58:in `load'
2024-05-16T18:37:01.8424153Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/cli/exec.rb:58:in `kernel_load'
2024-05-16T18:37:01.8425490Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/cli/exec.rb:23:in `run'
2024-05-16T18:37:01.8426661Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/cli.rb:455:in `exec'
2024-05-16T18:37:01.8427999Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/vendor/thor/lib/thor/command.rb:28:in `run'
2024-05-16T18:37:01.8429798Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
2024-05-16T18:37:01.8431466Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/vendor/thor/lib/thor.rb:527:in `dispatch'
2024-05-16T18:37:01.8432780Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/cli.rb:35:in `dispatch'
2024-05-16T18:37:01.8434638Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/vendor/thor/lib/thor/base.rb:584:in `start'
2024-05-16T18:37:01.8435963Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/cli.rb:29:in `start'
2024-05-16T18:37:01.8437660Z       /usr/local/lib/ruby/gems/3.3.0/gems/bundler-2.5.10/exe/bundle:28:in `block in <top (required)>'
2024-05-16T18:37:01.8439287Z       /usr/local/lib/ruby/site_ruby/3.3.0/bundler/friendly_errors.rb:117:in `with_friendly_errors'
2024-05-16T18:37:01.8441195Z       /usr/local/lib/ruby/gems/3.3.0/gems/bundler-2.5.10/exe/bundle:20:in `<top (required)>'
2024-05-16T18:37:01.8442458Z       /home/app/app/bin/bundle:113:in `load'
2024-05-16T18:37:01.8443237Z       /home/app/app/bin/bundle:113:in `<main>'
2024-05-16T18:37:01.8461905Z   Thread #<Thread:0x00007f115f82ada8@DEBUGGER__::SESSION@server /home/app/bundle/ruby/3.3.0/gems/debug-1.9.2/lib/debug/session.rb:179 sleep_forever> status=sleep priority=0
2024-05-16T18:37:01.8463786Z       <internal:thread_sync>:18:in `pop'
2024-05-16T18:37:01.8465045Z       /home/app/bundle/ruby/3.3.0/gems/debug-1.9.2/lib/debug/session.rb:250:in `pop_event'
2024-05-16T18:37:01.8466893Z       /home/app/bundle/ruby/3.3.0/gems/debug-1.9.2/lib/debug/session.rb:254:in `session_server_main'
2024-05-16T18:37:01.8468679Z       /home/app/bundle/ruby/3.3.0/gems/debug-1.9.2/lib/debug/session.rb:207:in `block in activate'
2024-05-16T18:37:01.8470533Z   Thread #<Thread:0x00007f115f6b5680@Timeout stdlib thread /usr/local/lib/ruby/3.3.0/timeout.rb:98 sleep> status=sleep priority=0
2024-05-16T18:37:01.8472169Z       /usr/local/lib/ruby/3.3.0/timeout.rb:110:in `sleep'
2024-05-16T18:37:01.8473438Z       /usr/local/lib/ruby/3.3.0/timeout.rb:110:in `wait'
2024-05-16T18:37:01.8475091Z       /usr/local/lib/ruby/3.3.0/timeout.rb:110:in `block (2 levels) in create_timeout_thread'
2024-05-16T18:37:01.8476364Z       /usr/local/lib/ruby/3.3.0/timeout.rb:108:in `synchronize'
2024-05-16T18:37:01.8477545Z       /usr/local/lib/ruby/3.3.0/timeout.rb:108:in `block in create_timeout_thread'
2024-05-16T18:37:01.8480303Z   Thread #<Thread:0x00007f115b8cb950 /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:42 sleep> status=sleep priority=0
2024-05-16T18:37:01.8483388Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:48:in `sleep'
2024-05-16T18:37:01.8486218Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:48:in `block in spawn_thread'
2024-05-16T18:37:01.8489683Z   Thread #<Thread:0x00007f11599c0588@worker-1 /home/app/bundle/ruby/3.3.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:339 sleep> status=sleep priority=0
2024-05-16T18:37:01.8492815Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql_adapter.rb:966:in `prepare'
2024-05-16T18:37:01.8495496Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql_adapter.rb:966:in `prepare_statement'
2024-05-16T18:37:01.8498203Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql_adapter.rb:907:in `block in exec_cache'
2024-05-16T18:37:01.8500970Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract_adapter.rb:1028:in `block in with_raw_connection'
2024-05-16T18:37:01.8503594Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
2024-05-16T18:37:01.8506074Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract_adapter.rb:1000:in `with_raw_connection'
2024-05-16T18:37:01.8508737Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql_adapter.rb:906:in `exec_cache'
2024-05-16T18:37:01.8511285Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql_adapter.rb:874:in `execute_and_clear'
2024-05-16T18:37:01.8514357Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/postgresql/database_statements.rb:64:in `internal_exec_query'
2024-05-16T18:37:01.8517211Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:630:in `select'
2024-05-16T18:37:01.8520067Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:71:in `select_all'
2024-05-16T18:37:01.8522755Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/query_cache.rb:112:in `block in select_all'
2024-05-16T18:37:01.8525541Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/query_cache.rb:152:in `block in cache_sql'
2024-05-16T18:37:01.8528211Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `handle_interrupt'
2024-05-16T18:37:01.8531011Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:23:in `block in synchronize'
2024-05-16T18:37:01.8533800Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `handle_interrupt'
2024-05-16T18:37:01.8536400Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/concurrency/load_interlock_aware_monitor.rb:19:in `synchronize'
2024-05-16T18:37:01.8539272Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/query_cache.rb:147:in `cache_sql'
2024-05-16T18:37:01.8541752Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/query_cache.rb:112:in `select_all'
2024-05-16T18:37:01.8544081Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/querying.rb:62:in `_query_by_sql'
2024-05-16T18:37:01.8546208Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation.rb:998:in `block in exec_main_query'
2024-05-16T18:37:01.8548498Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation.rb:1018:in `skip_query_cache_if_necessary'
2024-05-16T18:37:01.8550800Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation.rb:984:in `exec_main_query'
2024-05-16T18:37:01.8553413Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation.rb:962:in `block in exec_queries'
2024-05-16T18:37:01.8555782Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation.rb:1018:in `skip_query_cache_if_necessary'
2024-05-16T18:37:01.8558060Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation.rb:956:in `exec_queries'
2024-05-16T18:37:01.8560179Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/association_relation.rb:44:in `exec_queries'
2024-05-16T18:37:01.8562350Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation.rb:742:in `load'
2024-05-16T18:37:01.8564245Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation.rb:264:in `records'
2024-05-16T18:37:01.8566262Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/relation/delegation.rb:100:in `each'
2024-05-16T18:37:01.8568562Z       /home/app/bundle/ruby/3.3.0/gems/activestorage-7.1.3.2/app/models/active_storage/blob.rb:364:in `touch_attachment_records'
2024-05-16T18:37:01.8570926Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:403:in `block in make_lambda'
2024-05-16T18:37:01.8573342Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:239:in `block in halting_and_conditional'
2024-05-16T18:37:01.8575662Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:602:in `block in invoke_after'
2024-05-16T18:37:01.8577734Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:602:in `each'
2024-05-16T18:37:01.8579707Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:602:in `invoke_after'
2024-05-16T18:37:01.8582043Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:111:in `run_callbacks'
2024-05-16T18:37:01.8584222Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:952:in `_run_update_callbacks'
2024-05-16T18:37:01.8586461Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/callbacks.rb:449:in `_update_record'
2024-05-16T18:37:01.8588516Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/timestamp.rb:120:in `_update_record'
2024-05-16T18:37:01.8590703Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/persistence.rb:1221:in `create_or_update'
2024-05-16T18:37:01.8593251Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/callbacks.rb:441:in `block in create_or_update'
2024-05-16T18:37:01.8595519Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
2024-05-16T18:37:01.8598069Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/autosave_association.rb:375:in `around_save_collection_association'
2024-05-16T18:37:01.8600747Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `block in run_callbacks'
2024-05-16T18:37:01.8602889Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:141:in `run_callbacks'
2024-05-16T18:37:01.8605125Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:952:in `_run_save_callbacks'
2024-05-16T18:37:01.8607297Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/callbacks.rb:441:in `create_or_update'
2024-05-16T18:37:01.8609599Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/timestamp.rb:125:in `create_or_update'
2024-05-16T18:37:01.8611646Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/persistence.rb:751:in `save!'
2024-05-16T18:37:01.8613555Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/validations.rb:55:in `save!'
2024-05-16T18:37:01.8615654Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/transactions.rb:313:in `block in save!'
2024-05-16T18:37:01.8618029Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/transactions.rb:365:in `block in with_transaction_returning_status'
2024-05-16T18:37:01.8620790Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:342:in `transaction'
2024-05-16T18:37:01.8623359Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/transactions.rb:361:in `with_transaction_returning_status'
2024-05-16T18:37:01.8625540Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/transactions.rb:313:in `save!'
2024-05-16T18:37:01.8627576Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/suppressor.rb:56:in `save!'
2024-05-16T18:37:01.8629554Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/persistence.rb:906:in `block in update!'
2024-05-16T18:37:01.8631935Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/transactions.rb:365:in `block in with_transaction_returning_status'
2024-05-16T18:37:01.8634973Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:342:in `transaction'
2024-05-16T18:37:01.8637573Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/transactions.rb:361:in `with_transaction_returning_status'
2024-05-16T18:37:01.8639856Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/persistence.rb:904:in `update!'
2024-05-16T18:37:01.8642189Z       /home/app/bundle/ruby/3.3.0/gems/activestorage-7.1.3.2/app/models/active_storage/blob/analyzable.rb:30:in `analyze'
2024-05-16T18:37:01.8644404Z       /home/app/bundle/ruby/3.3.0/gems/activestorage-7.1.3.2/app/jobs/active_storage/analyze_job.rb:11:in `perform'
2024-05-16T18:37:01.8646626Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/execution.rb:69:in `block in _perform_job'
2024-05-16T18:37:01.8648788Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
2024-05-16T18:37:01.8650717Z       /home/app/bundle/ruby/3.3.0/gems/i18n-1.14.5/lib/i18n.rb:351:in `with_locale'
2024-05-16T18:37:01.8652724Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/translation.rb:9:in `block (2 levels) in <module:Translation>'
2024-05-16T18:37:01.8654958Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `instance_exec'
2024-05-16T18:37:01.8657257Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `block in run_callbacks'
2024-05-16T18:37:01.8659438Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/time/zones.rb:65:in `use_zone'
2024-05-16T18:37:01.8661894Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/timezones.rb:9:in `block (2 levels) in <module:Timezones>'
2024-05-16T18:37:01.8664189Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `instance_exec'
2024-05-16T18:37:01.8666370Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `block in run_callbacks'
2024-05-16T18:37:01.8668632Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:141:in `run_callbacks'
2024-05-16T18:37:01.8670592Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/execution.rb:68:in `_perform_job'
2024-05-16T18:37:01.8672529Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/instrumentation.rb:32:in `_perform_job'
2024-05-16T18:37:01.8674825Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/execution.rb:52:in `perform_now'
2024-05-16T18:37:01.8676854Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/instrumentation.rb:26:in `block in perform_now'
2024-05-16T18:37:01.8679095Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/railties/job_runtime.rb:13:in `block in instrument'
2024-05-16T18:37:01.8681408Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/instrumentation.rb:40:in `block in instrument'
2024-05-16T18:37:01.8683667Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/notifications.rb:206:in `block in instrument'
2024-05-16T18:37:01.8686148Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/notifications/instrumenter.rb:58:in `instrument'
2024-05-16T18:37:01.8688367Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/notifications.rb:206:in `instrument'
2024-05-16T18:37:01.8690397Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/instrumentation.rb:39:in `instrument'
2024-05-16T18:37:01.8692651Z       /home/app/bundle/ruby/3.3.0/gems/activerecord-7.1.3.2/lib/active_record/railties/job_runtime.rb:11:in `instrument'
2024-05-16T18:37:01.8694758Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/instrumentation.rb:26:in `perform_now'
2024-05-16T18:37:01.8696844Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/logging.rb:18:in `block in perform_now'
2024-05-16T18:37:01.8698924Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/tagged_logging.rb:135:in `block in tagged'
2024-05-16T18:37:01.8701058Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/tagged_logging.rb:39:in `tagged'
2024-05-16T18:37:01.8704146Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/tagged_logging.rb:135:in `tagged'
2024-05-16T18:37:01.8706406Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/broadcast_logger.rb:240:in `method_missing'
2024-05-16T18:37:01.8708416Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/logging.rb:25:in `tag_logger'
2024-05-16T18:37:01.8710386Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/logging.rb:18:in `perform_now'
2024-05-16T18:37:01.8712736Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/execution.rb:30:in `block in execute'
2024-05-16T18:37:01.8716342Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
2024-05-16T18:37:01.8718671Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/railtie.rb:67:in `block (4 levels) in <class:Railtie>'
2024-05-16T18:37:01.8720834Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/reloader.rb:77:in `block in wrap'
2024-05-16T18:37:01.8723017Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/execution_wrapper.rb:92:in `wrap'
2024-05-16T18:37:01.8725255Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/reloader.rb:74:in `wrap'
2024-05-16T18:37:01.8727485Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/railtie.rb:66:in `block (3 levels) in <class:Railtie>'
2024-05-16T18:37:01.8729645Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `instance_exec'
2024-05-16T18:37:01.8731823Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `block in run_callbacks'
2024-05-16T18:37:01.8734184Z       /home/app/bundle/ruby/3.3.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:141:in `run_callbacks'
2024-05-16T18:37:01.8736119Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/execution.rb:28:in `execute'
2024-05-16T18:37:01.8738127Z       /home/app/bundle/ruby/3.3.0/gems/activejob-7.1.3.2/lib/active_job/queue_adapters/async_adapter.rb:70:in `perform'
2024-05-16T18:37:01.8740671Z       /home/app/bundle/ruby/3.3.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:359:in `run_task'
2024-05-16T18:37:01.8743625Z       /home/app/bundle/ruby/3.3.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:350:in `block (3 levels) in create_worker'
2024-05-16T18:37:01.8745557Z       <internal:kernel>:187:in `loop'
2024-05-16T18:37:01.8747571Z       /home/app/bundle/ruby/3.3.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:341:in `block (2 levels) in create_worker'
2024-05-16T18:37:01.8750476Z       /home/app/bundle/ruby/3.3.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `catch'
2024-05-16T18:37:01.8753666Z       /home/app/bundle/ruby/3.3.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `block in create_worker'
2024-05-16T18:37:01.8755896Z   Thread #<Thread:0x00007f1159871358 /home/app/app/lib/sigdump_wrapper.rb:27 run> status=run priority=0
2024-05-16T18:37:01.8757579Z       /home/app/bundle/ruby/3.3.0/gems/sigdump-0.2.5/lib/sigdump.rb:53:in `backtrace'
2024-05-16T18:37:01.8759262Z       /home/app/bundle/ruby/3.3.0/gems/sigdump-0.2.5/lib/sigdump.rb:53:in `dump_backtrace'
2024-05-16T18:37:01.8761089Z       /home/app/bundle/ruby/3.3.0/gems/sigdump-0.2.5/lib/sigdump.rb:34:in `block in dump_all_thread_backtrace'
2024-05-16T18:37:01.8762922Z       /home/app/bundle/ruby/3.3.0/gems/sigdump-0.2.5/lib/sigdump.rb:33:in `each'
2024-05-16T18:37:01.8764581Z       /home/app/bundle/ruby/3.3.0/gems/sigdump-0.2.5/lib/sigdump.rb:33:in `dump_all_thread_backtrace'
2024-05-16T18:37:01.8766247Z       /home/app/bundle/ruby/3.3.0/gems/sigdump-0.2.5/lib/sigdump.rb:16:in `block in dump'
2024-05-16T18:37:01.8768186Z       /home/app/bundle/ruby/3.3.0/gems/sigdump-0.2.5/lib/sigdump.rb:142:in `_open_dump_path'
2024-05-16T18:37:01.8769761Z       /home/app/bundle/ruby/3.3.0/gems/sigdump-0.2.5/lib/sigdump.rb:14:in `dump'
2024-05-16T18:37:01.8771253Z       /home/app/app/lib/sigdump_wrapper.rb:27:in `block (2 levels) in trigger_from_signal'

cswilliams avatar May 16 '24 19:05 cswilliams

@cswilliams Are you using the async adapter?

zzak avatar May 18 '24 07:05 zzak

@zzak We were not setting config.active_job.queue_adapter. My understanding (correct me if I'm wrong) is that async is the default. So yes, we were using it. After reading through this thread, I updated config.active_job.queue_adapter to inline in our test environment. We haven't seen any hangs since doing that, but it's only been about 2 days since I merged in the fix. Typically we were seeing about 1 out of every 15 rspec runs on github actions hanging (we never saw it hang on our local development machines). I'm guessing this is due to the github action runners being much slower.

cswilliams avatar May 18 '24 18:05 cswilliams

@cswilliams we have a number of Rails apps and we encountered a similar issue after upgrading to Ruby 3.3. I'm not sure what exactly changed, but it only affects the projects where we had disabled active_job (commented out in config/application.rb).

For these projects our tests pass locally but the test suite hangs before the tests start running on GitHub Actions (CI). Your comment lead me to try configuring active_job to use the :test adapter even though it's supposed to be disabled, and that lead to the tests passing in CI. We are using ActiveStorage and I see that it actually depends on ActiveJob (via RailTie dependency) so I guess the takeaway is that if we're using ActiveStorage we should explicitly depend on and configure ActiveJob.

sfnelson avatar Jun 06 '24 03:06 sfnelson

We're seeing this too and probably roughly tied to our 7.0 upgrade in timing. Specifically in CI and system tests (Capybara w/Cuprite) but I did manage to replicate locally and using this https://thoughtbot.com/blog/multi-thread-backtrace-for-silently-hanging-tests I was able to get what seems like a decent backtrace:

================================================================================
Received USR1 signal; printing all 4 thread backtraces.

Main thread backtrace:
.../app/test/test_helper.rb:188:in `backtrace'
.../app/test/test_helper.rb:188:in `block (2 levels) in <main>'
.../app/test/test_helper.rb:184:in `each'
.../app/test/test_helper.rb:184:in `block in <main>'
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelization.rb:51:in `waitpid'
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelization.rb:51:in `block in shutdown'
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelization.rb:51:in `each'
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelization.rb:51:in `shutdown'
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelize_executor.rb:26:in `shutdown'
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/minitest-5.20.0/lib/minitest.rb:166:in `run'
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/minitest-5.20.0/lib/minitest.rb:86:in `block in autorun'

#<Thread:0x000000010c29fe48 .../versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.0.8.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:40 sleep> backtrace:
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.0.8.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:46:in `sleep'
.../versions/3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.0.8.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:46:in `block in spawn_thread'

#<Thread:0x00000001350586c0 .../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1555 sleep> backtrace:
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:986:in `select'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:986:in `accept_or_shutdown'
.../versions/3.2.2/lib/ruby/3.2.0/drb/unix.rb:106:in `accept'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1714:in `main_loop'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1557:in `block in run'

#<Thread:0x0000000135051898 .../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1716 sleep> backtrace:
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:580:in `read'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:580:in `load'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:619:in `recv_request'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:931:in `recv_request'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1659:in `init_with_client'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1671:in `setup_message'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1631:in `perform'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1729:in `block (2 levels) in main_loop'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1725:in `loop'
.../versions/3.2.2/lib/ruby/3.2.0/drb/drb.rb:1725:in `block in main_loop'

I tried setting the active_job adapter to :inline and :test with no success. I'm a bit lost as to where to dig next, does the above give anyone anything more to go on?

Edit: Using https://github.com/fluent/sigdump#install I also got this...

Sigdump at 2024-06-14 14:33:39 -0700 process 51748 (bin/rails)
  Thread #<Thread:0x000000010271b0d0 run> status=run priority=0
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:53:in `backtrace'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:53:in `dump_backtrace'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:34:in `block in dump_all_thread_backtrace'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:33:in `each'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:33:in `dump_all_thread_backtrace'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:16:in `block in dump'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:138:in `open'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:138:in `_open_dump_path'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:14:in `dump'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/sigdump-0.2.5/lib/sigdump.rb:7:in `block in setup'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelization.rb:51:in `waitpid'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelization.rb:51:in `block in shutdown'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelization.rb:51:in `each'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelization.rb:51:in `shutdown'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/activesupport-7.0.8.1/lib/active_support/testing/parallelize_executor.rb:26:in `shutdown'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/minitest-5.20.0/lib/minitest.rb:166:in `run'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/minitest-5.20.0/lib/minitest.rb:86:in `block in autorun'
  Thread #<Thread:0x000000010e466ab8 ../3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.0.8.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:40 sleep> status=sleep priority=0
      ../3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.0.8.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:46:in `sleep'
      ../3.2.2/lib/ruby/gems/3.2.0/gems/activerecord-7.0.8.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:46:in `block in spawn_thread'
  Thread #<Thread:0x000000011a501bd8 ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1555 sleep> status=sleep priority=0
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:986:in `select'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:986:in `accept_or_shutdown'
      ../3.2.2/lib/ruby/3.2.0/drb/unix.rb:106:in `accept'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1714:in `main_loop'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1557:in `block in run'
  Thread #<Thread:0x000000011a54b3c8 ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1716 sleep> status=sleep priority=0
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:580:in `read'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:580:in `load'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:619:in `recv_request'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:931:in `recv_request'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1659:in `init_with_client'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1671:in `setup_message'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1631:in `perform'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1729:in `block (2 levels) in main_loop'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1725:in `loop'
      ../3.2.2/lib/ruby/3.2.0/drb/drb.rb:1725:in `block in main_loop'

...

markedmondson avatar Jun 14 '24 19:06 markedmondson

I think the above turned out to be a case of a bad wait/sleep loop and url_matches? - it was particularly tricky to find the trace for for some reason and it wasn't until possibly the ~100th time digging through dumps etc that an obvious line stuck out.

tl;dr: seems like ^ was user error.

markedmondson avatar Jun 19 '24 19:06 markedmondson