hang while reporting error occurring outside of specs

delj commented 6 years ago

A syntax error in a non-spec file caused a SyntaxError to be raised outside of specs. Getting a stacktrace of the rspec process during the hang gave this:

rspec pid: 11529     

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

Main thread backtrace:                                                                                                                       
repos/myapp/spec/spec_helper.rb:41:in `backtrace'                                                                                      
repos/myapp/spec/spec_helper.rb:41:in `block (2 levels) in <top (required)>'                                    
repos/myapp/spec/spec_helper.rb:37:in `each'                                                                                                                        
repos/myapp/spec/spec_helper.rb:37:in `block in <top (required)>'                                                       
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-support-3.6.0/lib/rspec/support/source/token.rb:36:in `call'                               
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-support-3.6.0/lib/rspec/support/source/token.rb:36:in `type'                                 
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-support-3.6.0/lib/rspec/support/source/token.rb:68:in `opening_delimiter?'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-support-3.6.0/lib/rspec/support/source/token.rb:58:in `opening?'                   
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/snippet_extractor.rb:76:in `block in unclosed_tokens_in_line_range'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/snippet_extractor.rb:75:in `each'   
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/snippet_extractor.rb:75:in `each_with_object'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/snippet_extractor.rb:75:in `unclosed_tokens_in_line_range'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/snippet_extractor.rb:63:in `line_range_of_expression'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/snippet_extractor.rb:42:in `expression_lines'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/snippet_extractor.rb:31:in `extract_expression_lines_at'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:218:in `read_failed_lines'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:163:in `failure_slash_error_lines'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:150:in `block in failure_lines'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:149:in `tap'               
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:149:in `failure_lines'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:34:in `colorized_message_lines'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:240:in `formatted_message_and_backtrace'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:86:in `fully_formatted_lines'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/formatters/exception_presenter.rb:78:in `fully_formatted'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/reporter.rb:166:in `notify_non_example_exception'                                                   
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/configuration.rb:1925:in `rescue in load_spec_file_handling_errors'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/configuration.rb:1922:in `load_spec_file_handling_errors'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/configuration.rb:1494:in `block in load_spec_files'
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/configuration.rb:1492:in `each'                                      
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/configuration.rb:1492:in `load_spec_files'               
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/runner.rb:100:in `setup'                                 
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/runner.rb:86:in `run'                                                        
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/runner.rb:71:in `run'                                                  
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/lib/rspec/core/runner.rb:45:in `invoke'                                                                            
.rvm/gems/ruby-2.2.4@myapp/gems/rspec-core-3.6.0/exe/rspec:4:in `<top (required)>'

Setting a breakpoint here:

From: ~/.rvm/gems/ruby-2.2.4@gemset/gems/rspec-core-3.6.0/lib/rspec/core/reporter.rb @ line 167 RSpec::Core::Reporter#notify_non_example_exception:

    160: def notify_non_example_exception(exception, context_description)
    161:   @configuration.world.non_example_failure = true
    162:   @non_example_exception_count += 1
    163:
    164:   example = Example.new(AnonymousExampleGroup, context_description, {})
    165:   presenter = Formatters::ExceptionPresenter.new(exception, example, :indentation => 0)
    166:   require 'pry'; binding.pry
 => 167:   message presenter.fully_formatted(nil)
    168: end

allowed finding the underlying cause by inspecting exception.

Symptom: rspec hangs and loads up 100% of the CPU on which it is running

Environment:

ruby 2.2.4
rspec 3.6.0
rspec-rails 3.6.1
rails 4.2.5

JonRowe commented 6 years ago

Hi, thanks for reporting this, can you spin up a reproducible snippet for us? A backtrace doesn't help much :) @yujinakayama this looks like it's coming from the snippet extractor, any thoughts as to cause?

delj commented 6 years ago

I can give examples of what triggered the problem, but cannot post code. I am not familiar enough with rspec-core to zero-in on a potential cause that may let me write (efficiently) a toy example that fails =/

The syntax error was:

MyModel.where(keyword: )

(no value for the named argument on the Rails model)

JonRowe commented 6 years ago

If you could produce a little spec suite that causes the problem that would be ideal, no knowledge of rspec required, just vanilla install and a spec / file combo that causes the problem!

mikebaldry commented 3 years ago

I have experienced this today. Running a rails 6 app, running rspec it just hangs. I think it is down to the dependency loading failing because of the syntax error, maybe happening during initialization phase, and rspec just hangs. We found the issue by commenting out trap_interrupt in runner.rb, then ^C the hung process which not only revealed the backtrace but also the error some how.

pirj commented 3 years ago

That's very interesting, @mikebaldry. Do you mind to share your findings?

rspec / rspec-core

hang while reporting error occurring outside of specs #2514