Rspec-core: RSpec crashes due to bad `message` of exception

Created on 18 Aug 2020 · 6Comments · Source: rspec/rspec-core

Subject of the issue

When the message of a raised exception does not implement #to_s properly, the RSpec exception formatter crashes instead of reporting a test failure.

The lack of report output is causing downstream problems in the mutant gem.

Your environment

Ruby version: 2.7.1
rspec-core version: 3.9.2

Steps to reproduce

# frozen_string_literal: true

begin
  require "bundler/inline"
rescue LoadError => e
  $stderr.puts "Bundler version 1.10 or later is required. Please update your Bundler"
  raise e
end

gemfile(true) do
  source "https://rubygems.org"

  gem "rspec", "3.9.0"
end

puts "Ruby version is: #{RUBY_VERSION}"
require 'rspec/autorun'

class Thing
  def to_s
    raise StandardError, self
  end
end

RSpec.describe Thing do
  it 'raises an error in #to_s' do
    thing = Thing.new
    expect { thing.to_s }.to raise_error(ArgumentError)
  end
end

Expected behavior

The test should fail and output an error report similar to:

Fetching gem metadata from https://rubygems.org/...
Resolving dependencies...
Using bundler 2.1.4
Using diff-lcs 1.4.4
Using rspec-support 3.9.3
Using rspec-core 3.9.2
Using rspec-expectations 3.9.2
Using rspec-mocks 3.9.1
Using rspec 3.9.0
Ruby version is: 2.7.1
F

Failures:

  1) Thing raises an error in #to_s
     Failure/Error: expect { thing.to_s }.to raise_error(ArgumentError)

       expected ArgumentError, got #<StandardError: StandardError> with backtrace:
         # tmp.rb:21:in `to_s'
         # tmp.rb:28:in `block (3 levels) in <main>'
         # tmp.rb:28:in `block (2 levels) in <main>'
     # tmp.rb:28:in `block (2 levels) in <main>'

Finished in 0.01809 seconds (files took 0.09742 seconds to load)
1 example, 1 failure

Failed examples:

rspec tmp.rb:26 # Thing raises an error in #to_s

Actual behavior

RSpec crashes without outputting an error report:

Fetching gem metadata from https://rubygems.org/...
Resolving dependencies...
Using bundler 2.1.4
Using diff-lcs 1.4.4
Using rspec-support 3.9.3
Using rspec-core 3.9.2
Using rspec-expectations 3.9.2
Using rspec-mocks 3.9.1
Using rspec 3.9.0
Ruby version is: 2.7.1
F

tmp.rb:21:in `to_s': StandardError
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:180:in `to_s'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:180:in `message'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:180:in `exception_lines'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:155:in `block in failure_lines'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:152:in `tap'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:152:in `failure_lines'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:34:in `colorized_message_lines'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:243:in `formatted_message_and_backtrace'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:88:in `fully_formatted_lines'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/exception_presenter.rb:80:in `fully_formatted'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/notifications.rb:200:in `fully_formatted'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/notifications.rb:114:in `block in fully_formatted_failed_examples'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/notifications.rb:113:in `each'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/notifications.rb:113:in `each_with_index'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/notifications.rb:113:in `fully_formatted_failed_examples'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/formatters/base_text_formatter.rb:32:in `dump_failures'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:209:in `block in notify'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:208:in `each'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:208:in `notify'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:178:in `block in finish'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:194:in `close_after'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:174:in `finish'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/reporter.rb:76:in `report'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:115:in `run_specs'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:89:in `run'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:71:in `run'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:45:in `invoke'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:38:in `perform_at_exit'
    from /Users/tom/.gem/ruby/2.7.1/gems/rspec-core-3.9.2/lib/rspec/core/runner.rb:24:in `block in autorun'

Source

tomdalling

Most helpful comment

👍 Thanks for taking a look at this. I was a little over-optimistic about how quickly I could get to it.

tomdalling on 25 Aug 2020

😄2

All 6 comments

I'd like to sharpen the following point:

Yes, raise StandardError, self is clearly invalid code. But as this code is the subject under test, it should not make rspec crash. And yes, rspec needs to reflect expected and actual exceptions to produce a report, so this is a bit of a catch 22.

I'm aware that at the moment rspec produces a report, its "test exception capture" is not active anymore. So the question is: Should rspec capture exceptions when interacting with the test subjects on generating its report? And report them as "report generation errors"? IMO yes, as interacting with the test subject, even for report generation is still "testing the test subjects".

RSpec also captures errors during boot of the test suite and turns them into reports, so it to me makes sense to do the same for report generation.

Curious about other opinions here. I can handle this from the mutant side also and have users whitelist integration failures in the future on a case by case basis.

mbj on 18 Aug 2020

It is incorrect code, but still a valid one syntax-wise, in the same category as 1 / 0. This case is deeper since as you mention, we're in reporter when the problem comes up.

I guess the problem is in raise_error matcher in this case. It doesn't evaluate @actual_error.message until it's too late.
There's no big difference between:

expect { thing.to_s }.to raise_error(ArgumentError).with_message('foo')
expect { thing.to_s }.to raise_error(StandardError).with_message('foo')

By adding with_message I'm trying to force the check of the message that is

        def verify_message
          return true if @expected_message.nil?
          values_match?(@expected_message, @actual_error.message.to_s)
        end

and by using the same StandardError, I'm satisfying the first part of this conditional:

            if values_match?(@expected_error, @actual_error) ||
               values_match?(@expected_error, @actual_error.message)

In any case, it still fails.

Would you like to hack on raise_error so it's careful and less restrictive with the exception message?

pirj on 18 Aug 2020

Sure, I'll take a look soon.

tomdalling on 19 Aug 2020

@pirj I transferred this back to rspec-core because I took a quick look at addressing this in the matcher when it was reported but simply checking for to_s on message et al doesn't solve it and I don't think a crash in the exception presenter should crash RSpec., there might be another issue to be opened with the matcher, but rspec shouldn't crash if we can't print the message

JonRowe on 23 Aug 2020

👍1

Fair enough.

I've split fully_formatted_lines to two methods (having hard times to

def fully_formatted_lines(failure_number, colorizer)
  lines = exception_details(failure_number, colorizer).compact.flatten

  lines = indent_lines(lines, failure_number)
  lines.unshift("")
  lines
end

private

def exception_details(failure_number, colorizer)
  lines = []
  lines << encoded_description(description)
  lines << detail_formatter.call(example, colorizer)
  lines << formatted_message_and_backtrace(colorizer)
  lines << extra_detail_formatter.call(failure_number, colorizer)
  lines
rescue
  lines << "(unable to show formatted exception)"
  lines
end

and the resulting output looks like: