rails / solid_queue

Database-backed Active Job backend
MIT License
1.95k stars 130 forks source link

Error on hearbeat with SQLite3::BusyException: database is locked #385

Closed danielschnee closed 1 week ago

danielschnee commented 1 month ago

Getting SQLite3::BusyException: database is locked on heartbeat running:

Backtrace:

 sqlite3-2.1.0-x86_64-linux (gnu) lib/sqlite3/statement.rb:125:in `step'
 sqlite3-2.1.0-x86_64-linux (gnu) lib/sqlite3/statement.rb:125:in `block in each'
 <internal:kernel>:187:in `loop'
 sqlite3-2.1.0-x86_64-linux (gnu) lib/sqlite3/statement.rb:124:in `each'
 activerecord (7.2.1) lib/active_record/connection_adapters/sqlite3/database_statements.rb:42:in `to_a'
 activerecord (7.2.1) lib/active_record/connection_adapters/sqlite3/database_statements.rb:42:in `block (2 levels) in internal_exec_query'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract_adapter.rb:1004:in `block in with_raw_connection'
 activesupport (7.2.1) lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract_adapter.rb:976:in `with_raw_connection'
 activerecord (7.2.1) lib/active_record/connection_adapters/sqlite3/database_statements.rb:33:in `block in internal_exec_query'
 activesupport (7.2.1) lib/active_support/notifications/instrumenter.rb:58:in `instrument'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract_adapter.rb:1119:in `log'
 activerecord (7.2.1) lib/active_record/connection_adapters/sqlite3/database_statements.rb:32:in `internal_exec_query'
 activerecord (7.2.1) lib/active_record/connection_adapters/sqlite3/database_statements.rb:63:in `exec_delete'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/database_statements.rb:208:in `update'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/query_cache.rb:27:in `update'
 activerecord (7.2.1) lib/active_record/persistence.rb:280:in `block in _update_record'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/connection_pool.rb:389:in `with_connection'
 activerecord (7.2.1) lib/active_record/connection_handling.rb:296:in `with_connection'
 activerecord (7.2.1) lib/active_record/persistence.rb:279:in `_update_record'
 activerecord (7.2.1) lib/active_record/persistence.rb:887:in `_update_row'
 activerecord (7.2.1) lib/active_record/locking/optimistic.rb:93:in `_update_row'
 activerecord (7.2.1) lib/active_record/persistence.rb:883:in `_touch_row'
 activerecord (7.2.1) lib/active_record/locking/optimistic.rb:89:in `_touch_row'
 activerecord (7.2.1) lib/active_record/attribute_methods/dirty.rb:207:in `_touch_row'
 activerecord (7.2.1) lib/active_record/persistence.rb:808:in `touch'
 activerecord (7.2.1) lib/active_record/callbacks.rb:432:in `block in touch'
 activesupport (7.2.1) lib/active_support/callbacks.rb:101:in `run_callbacks'
 activesupport (7.2.1) lib/active_support/callbacks.rb:913:in `_run_touch_callbacks'
 activerecord (7.2.1) lib/active_record/callbacks.rb:432:in `touch'
 activerecord (7.2.1) lib/active_record/transactions.rb:370:in `block in touch'
 activerecord (7.2.1) lib/active_record/transactions.rb:418:in `block (2 levels) in with_transaction_returning_status'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/database_statements.rb:359:in `transaction'
 activerecord (7.2.1) lib/active_record/transactions.rb:414:in `block in with_transaction_returning_status'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/connection_pool.rb:389:in `with_connection'
 activerecord (7.2.1) lib/active_record/connection_handling.rb:296:in `with_connection'
 activerecord (7.2.1) lib/active_record/transactions.rb:410:in `with_transaction_returning_status'
 activerecord (7.2.1) lib/active_record/transactions.rb:370:in `touch'
 activerecord (7.2.1) lib/active_record/touch_later.rb:44:in `touch'
 activerecord (7.2.1) lib/active_record/no_touching.rb:62:in `touch'
 solid_queue (1.0.0) app/models/solid_queue/process.rb:27:in `block in heartbeat'
 activerecord (7.2.1) lib/active_record/locking/pessimistic.rb:97:in `block in with_lock'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/transaction.rb:616:in `block in within_new_transaction'
 activesupport (7.2.1) lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/transaction.rb:613:in `within_new_transaction'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/database_statements.rb:361:in `transaction'
 activerecord (7.2.1) lib/active_record/transactions.rb:234:in `block in transaction'
 activerecord (7.2.1) lib/active_record/connection_adapters/abstract/connection_pool.rb:395:in `with_connection'
 activerecord (7.2.1) lib/active_record/connection_handling.rb:296:in `with_connection'
 activerecord (7.2.1) lib/active_record/transactions.rb:233:in `transaction'
 activerecord (7.2.1) lib/active_record/transactions.rb:354:in `transaction'
 activerecord (7.2.1) lib/active_record/locking/pessimistic.rb:95:in `with_lock'
 solid_queue (1.0.0) app/models/solid_queue/process.rb:27:in `heartbeat'
 solid_queue (1.0.0) lib/solid_queue/processes/registrable.rb:56:in `heartbeat'
 solid_queue (1.0.0) lib/solid_queue/processes/registrable.rb:41:in `block (2 levels) in launch_heartbeat'
 activesupport (7.2.1) lib/active_support/execution_wrapper.rb:91:in `wrap'
 solid_queue (1.0.0) lib/solid_queue/app_executor.rb:7:in `wrap_in_app_executor'
 solid_queue (1.0.0) lib/solid_queue/processes/registrable.rb:41:in `block in launch_heartbeat'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:24:in `block in execute'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `block in synchronize'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:22:in `execute'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/timer_task.rb:339:in `execute_task'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:24:in `block in execute'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `block in synchronize'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:22:in `execute'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/ivar.rb:170:in `safe_execute'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/scheduled_task.rb:298:in `process_task'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/timer_set.rb:166:in `block (2 levels) in process_tasks'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:359:in `run_task'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:350:in `block (3 levels) in create_worker'
 <internal:kernel>:187:in `loop'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:341:in `block (2 levels) in create_worker'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `catch'
 concurrent-ruby (1.3.4) lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `block in create_worker'

Rigth before that error:

13:48:35 web.1  |   SolidQueue::Process Update (0.1ms)  UPDATE "solid_queue_processes" SET "last_heartbeat_at" = ? WHERE " solid_queue_processes"."id" = ?  [["last_heartbeat_at", "2024-10-14 11:48:35.007598"], ["id", 336]]
13:48:35 web.1  |   TRANSACTION (0.1ms)  commit transaction                                                               
13:48:35 web.1  |   SolidQueue::Process Update (0.5ms)  UPDATE "solid_queue_processes" SET "last_heartbeat_at" = ? WHERE " solid_queue_processes"."id" = ?  [["last_heartbeat_at", "2024-10-14 11:48:35.008699"], ["id", 337]]
rosa commented 3 weeks ago

This is most likely due to how you have configured SQLite. It should come with much better defaults in Rails 8. For Rails 7.2, I can recommend checking out this article and the proposed tweaks to configuration.

barefootford commented 2 weeks ago

Hoping not to add a worse headache to this, but I’ve been using Stephen’s book/blog posts and also upgraded to the Rails 8 rc and see this error too. Also using the modified Active Record adapter fwiw.

Happy to dig into this if there’s anything I can do to help or test. Solid Queue has been reliable for me, but I’m only running only dozens of jobs per day at the moment.

Error #113924008 in TubeSalt - Honeybadger.pdf

danielschnee commented 1 week ago

Is fixed with recommendations mentioned in @rosa linked article and with rails 8.