search

jchayan / bakery

Artisanal digital bakery
0 stars 0 forks source link

Bug: RSpec freezes when running tests #9

Open jchayan opened 4 years ago

jchayan commented 4 years ago

Background

RSpec freezes since ActionController::Live was composed into the OvensController

Replication Steps

  1. Run rspec spec

Result

These are the last lines printed to stdout:

OvensController
  GET index
    when not authenticated
      blocks access (FAILED - 1)
    when authenticated
      allows access
      assigns the user's ovens
  GET show
    when not authenticated

Here's what I get from the thread's stack-trace:

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

Main thread backtrace: 
/Users/jorgechayan/dev/flowspace-bakery/spec/spec_helper.rb:94:in `backtrace'
/Users/jorgechayan/dev/flowspace-bakery/spec/spec_helper.rb:94:in `block (2 levels) in <top (required)>'
/Users/jorgechayan/dev/flowspace-bakery/spec/spec_helper.rb:90:in `each'
/Users/jorgechayan/dev/flowspace-bakery/spec/spec_helper.rb:90:in `block in <top (required)>'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_controller/metal/live.rb:211:in `pop'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_controller/metal/live.rb:211:in `block (2 levels) in each_chunk'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/dependencies/interlock.rb:46:in `block in permit_concurrent_loads'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/concurrency/share_lock.rb:185:in `yield_shares'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/dependencies/interlock.rb:45:in `permit_concurrent_loads'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_controller/metal/live.rb:210:in `block in each_chunk'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_controller/metal/live.rb:208:in `loop'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_controller/metal/live.rb:208:in `each_chunk'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_dispatch/http/response.rb:126:in `each'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_dispatch/http/response.rb:107:in `body'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_dispatch/http/response.rb:302:in `body'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_dispatch/testing/assertions/response.rb:86:in `response_body_if_short'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_dispatch/testing/assertions/response.rb:82:in `generate_response_message'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_dispatch/testing/assertions/response.rb:29:in `assert_response'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/actionpack-5.1.7/lib/action_dispatch/testing/assertions/response.rb:54:in `assert_redirected_to'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/turbolinks-5.2.0/lib/turbolinks/assertions.rb:9:in `assert_redirected_to'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/shoulda-matchers-4.0.1/lib/shoulda/matchers/action_controller/redirect_to_matcher.rb:79:in `redirects_to_url?'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/shoulda-matchers-4.0.1/lib/shoulda/matchers/action_controller/redirect_to_matcher.rb:68:in `matches?'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-expectations-3.8.2/lib/rspec/expectations/handler.rb:50:in `block in handle_matcher'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-expectations-3.8.2/lib/rspec/expectations/handler.rb:27:in `with_matcher'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-expectations-3.8.2/lib/rspec/expectations/handler.rb:48:in `handle_matcher'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-expectations-3.8.2/lib/rspec/expectations/expectation_target.rb:65:in `to'
/Users/jorgechayan/dev/flowspace-bakery/spec/controllers/ovens_controller_spec.rb:43:in `block (4 levels) in <top (required)>'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:254:in `instance_exec'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:254:in `block in run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:500:in `block in with_around_and_singleton_context_hooks'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:457:in `block in with_around_example_hooks'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:464:in `block in run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:604:in `block in run_around_example_hooks_for'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:342:in `call'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-rails-3.8.2/lib/rspec/rails/example/controller_example_group.rb:191:in `block (2 levels) in <module:ControllerExampleGroup>'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:447:in `instance_exec'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:447:in `instance_exec'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:373:in `execute_with'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:606:in `block (2 levels) in run_around_example_hooks_for'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:342:in `call'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-rails-3.8.2/lib/rspec/rails/adapters.rb:127:in `block (2 levels) in <module:MinitestLifecycleAdapter>'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:447:in `instance_exec'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:447:in `instance_exec'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:373:in `execute_with'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:606:in `block (2 levels) in run_around_example_hooks_for'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:342:in `call'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-wait-0.0.9/lib/rspec/wait.rb:46:in `block (2 levels) in <top (required)>'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:447:in `instance_exec'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:447:in `instance_exec'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:373:in `execute_with'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:606:in `block (2 levels) in run_around_example_hooks_for'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:342:in `call'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:607:in `run_around_example_hooks_for'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/hooks.rb:464:in `run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:457:in `with_around_example_hooks'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:500:in `with_around_and_singleton_context_hooks'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example.rb:251:in `run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:629:in `block in run_examples'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:625:in `map'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:625:in `run_examples'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:591:in `run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:592:in `block in run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:592:in `map'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:592:in `run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:592:in `block in run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:592:in `map'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/example_group.rb:592:in `run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/runner.rb:116:in `block (3 levels) in run_specs'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/runner.rb:116:in `map'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/runner.rb:116:in `block (2 levels) in run_specs'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/configuration.rb:1989:in `with_suite_hooks'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/runner.rb:111:in `block in run_specs'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/reporter.rb:74:in `report'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/runner.rb:110:in `run_specs'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/runner.rb:87:in `run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/runner.rb:71:in `run'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/rspec/core/runner.rb:45:in `invoke'
/Users/jorgechayan/.rbenv/versions/2.6.2/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/exe/rspec:4:in `<top (required)>'
/Users/jorgechayan/.rbenv/versions/2.6.2/bin/rspec:23:in `load'
/Users/jorgechayan/.rbenv/versions/2.6.2/bin/rspec:23:in `<main>'
================================================================================

Seems related to: https://api.rubyonrails.org/classes/ActionController/Live.html

jchayan commented 3 years ago

While digging, I found this related problem: https://github.com/rails/rails/issues/31200. It appears that RSpec runs only on a single thread

I thought our issue was also probably related to threads, since Puma is configured to allow for concurrency for ActionController::Live to work.

This specific comment provides a solution:

https://github.com/rails/rails/issues/31200#issuecomment-462218514

I tried it but it doesn't seem to work. So it's probably not related.

We need more debugging efforts