ThreadError with RSpec and Ruby 2.3/Rails 5.0

51 views
Skip to first unread message

Jack Royal-Gordon

unread,
Nov 23, 2020, 2:06:26 PM11/23/20
to rs...@googlegroups.com
After migrating from Ruby 2.2 / Rails 4.2 to Ruby 2.3 / Rails 5.0, I’m getting hundreds of “ThreadError: deadlock; recursive locking” error messages on 40% of my tests (~800 of 2000 examples). All of the failures are on ActiveRecord calls — <rec>.reload, <model>.last, <model>.find_by_<field>, etc. They happen in controller, helper, model, and feature specs.

I do not get any of these errors when exercising my app in Development, only when running tests. I saw one writeup that tied deadlock errors with Celluloid 0.17.3 and Ruby 2.2.5 and 2.3.1, but I’m not running that version of Celluloid (0.15.2).

I don’t expect that the problem is actually in RSpec, but since it only happens when running RSpec, perhaps someone on this list has seen this problem before.

BTW, I’m using RSpec 3.9.1

Phil Pirozhkov

unread,
Nov 23, 2020, 3:01:02 PM11/23/20
to Jack Royal-Gordon
Jack,

Congrats, it's a huge leap in your epic update story!

Can you please post an example trace?

--
You received this message because you are subscribed to the Google Groups "rspec" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rspec+un...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/rspec/73130943-1E26-4319-8433-3DBD5E65217B%40pobox.com.

Jack Royal-Gordon

unread,
Nov 23, 2020, 4:36:23 PM11/23/20
to rs...@googlegroups.com
Thanks, Phil. Here is a typical full traceback:

  1) AccountActivationsController GET 'edit' should have 'Account Activation' as the title
     Failure/Error: @user = User.find_by_activation_token(params[:id])

     

     ThreadError:
       deadlock; recursive locking
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/test-prof-0.7.5/lib/test_prof/recipes/active_record_shared_connection.rb:50:in `synchronize'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/test-prof-0.7.5/lib/test_prof/recipes/active_record_shared_connection.rb:50:in `exec_no_cache'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/postgresql_adapter.rb:585:in `execute_and_clear'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/postgresql/database_statements.rb:13:in `select_value'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/postgresql/schema_statements.rb:322:in `schema_search_path'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/postgresql_adapter.rb:647:in `sql_key'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/postgresql_adapter.rb:653:in `prepare_statement'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `exec_cache'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/test-prof-0.7.5/lib/test_prof/recipes/active_record_shared_connection.rb:46:in `block in exec_cache'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/test-prof-0.7.5/lib/test_prof/recipes/active_record_shared_connection.rb:46:in `synchronize'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/test-prof-0.7.5/lib/test_prof/recipes/active_record_shared_connection.rb:46:in `exec_cache'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/postgresql_adapter.rb:589:in `execute_and_clear'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/postgresql/database_statements.rb:103:in `exec_query'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/abstract/database_statements.rb:377:in `select_prepared'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/abstract/database_statements.rb:39:in `select_all'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `select_all'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/querying.rb:39:in `find_by_sql'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/statement_cache.rb:109:in `execute'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/core.rb:203:in `find_by'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/dynamic_matchers.rb:65:in `find_by_activation_token'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/dynamic_matchers.rb:19:in `method_missing'
     # ./app/controllers/account_activations_controller.rb:8:in `edit'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/abstract_controller/base.rb:188:in `process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/metal/rendering.rb:30:in `process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:126:in `call'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:455:in `call'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/callbacks.rb:90:in `run_callbacks'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/abstract_controller/callbacks.rb:19:in `process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/metal/rescue.rb:20:in `process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/notifications.rb:164:in `block in instrument'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activesupport-5.0.6/lib/active_support/notifications.rb:164:in `instrument'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/activerecord-5.0.6/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/abstract_controller/base.rb:126:in `process'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionview-5.0.6/lib/action_view/rendering.rb:30:in `process'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/metal.rb:190:in `dispatch'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/test_case.rb:547:in `process'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/test_case.rb:644:in `process_with_kwargs'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/actionpack-5.0.6/lib/action_controller/test_case.rb:389:in `get'
     # ./spec/controllers/account_activations_controller_spec.rb:11:in `block (3 levels) in <top (required)>'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:455:in `instance_exec'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:455:in `instance_exec'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:365:in `run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:529:in `block in run_owned_hooks_for'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:528:in `each'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:528:in `run_owned_hooks_for'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:615:in `block in run_example_hooks_for'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:614:in `reverse_each'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:614:in `run_example_hooks_for'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:484:in `run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:502:in `run_before_example'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:261:in `block in run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:508:in `block in with_around_and_singleton_context_hooks'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:465:in `block in with_around_example_hooks'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:486:in `block in run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:626:in `block in run_around_example_hooks_for'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:350:in `call'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-rails-3.9.1/lib/rspec/rails/example/controller_example_group.rb:191:in `block (2 levels) in <module:ControllerExampleGroup>'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:455:in `instance_exec'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:455:in `instance_exec'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:390:in `execute_with'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:628:in `block (2 levels) in run_around_example_hooks_for'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:350:in `call'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-rails-3.9.1/lib/rspec/rails/adapters.rb:127:in `block (2 levels) in <module:MinitestLifecycleAdapter>'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:455:in `instance_exec'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:455:in `instance_exec'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:390:in `execute_with'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:628:in `block (2 levels) in run_around_example_hooks_for'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:350:in `call'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:629:in `run_around_example_hooks_for'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/hooks.rb:486:in `run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:465:in `with_around_example_hooks'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:508:in `with_around_and_singleton_context_hooks'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example.rb:259:in `run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example_group.rb:644:in `block in run_examples'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example_group.rb:640:in `map'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example_group.rb:640:in `run_examples'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example_group.rb:606:in `run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example_group.rb:607:in `block in run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example_group.rb:607:in `map'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/example_group.rb:607:in `run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/runner.rb:121:in `block (3 levels) in run_specs'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/runner.rb:121:in `map'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/runner.rb:121:in `block (2 levels) in run_specs'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/configuration.rb:2061:in `with_suite_hooks'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/runner.rb:116:in `block in run_specs'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/reporter.rb:74:in `report'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/runner.rb:115:in `run_specs'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/runner.rb:89:in `run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/runner.rb:71:in `run'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/lib/rspec/core/runner.rb:45:in `invoke'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/rspec-core-3.9.3/exe/rspec:4:in `<top (required)>'
     # /Users/jackrg/.rbenv/versions/2.3.8/bin/rspec:22:in `load'
     # /Users/jackrg/.rbenv/versions/2.3.8/bin/rspec:22:in `<main>'


Frederick Cheung

unread,
Nov 25, 2020, 6:12:21 AM11/25/20
to rspec
Hi,

this is just a guess but

On Monday, November 23, 2020 at 9:36:23 PM UTC Jack R-G wrote:

     

     ThreadError:
       deadlock; recursive locking
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/test-prof-0.7.5/lib/test_prof/recipes/active_record_shared_connection.rb:50:in `synchronize'
     # /Users/jackrg/.rbenv/versions/2.3.8/lib/ruby/gems/2.3.0/gems/test-prof-0.7.5/lib/test_prof/recipes/active_record_shared_connection.rb:50:in `exec_no_cache'


test-prof is right at the top of the stack trace and the changelog for test prof 0.8 mention an issue with threading and activerecord in rails 5. 0.7.5 is the last version to support ruby 2.3 according to their docs, so maybe try disabling test-prof (and add it back in when you're on a more recent ruby?

Cheers,

Fred
 

Jack Royal-Gordon

unread,
Nov 25, 2020, 7:20:22 PM11/25/20
to rs...@googlegroups.com
Hi Fred,

Thanks for the heads-up. Unfortunately, I need TestProf for the “shared_connections” feature it has (and perhaps that is the source of my problems). See below for details on the issue that this resolves. I know that the need for this goes away with 5.1 so perhaps I will just remove TestProf in 5.0 (doing so does get rid of the error - yay!) and not test the one feature that needs the shared connections.

tl;dr When using Capybara, server code runs in a separate thread, with a separate database connection, from the test suite. This means that if I’m using transactional testing, data that I create within the test suite is not visible within the server, since the transaction is not committed (at the end of the test the transaction is rolled back).

--
You received this message because you are subscribed to the Google Groups "rspec" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rspec+un...@googlegroups.com.
Reply all
Reply to author
Forward
0 new messages