An unexpected args error confuses minitest when it looks for the source line

[onlynone]

Subject of the issue

We're using rspec-expectations, rspec-mocks with minitest. We're using the minitest_integration with both of them. For the most part everything works well. But sometimes failures cause minitest's location logic to not find where the problem really occurred.

For example, we have a test like:

class ExampleTest
  test "something" do
    expect(a_real_object).to receive(:a_method).with("these", "args")
    do_something
  end
end

And if do_something eventually results in a call to a_real_object.a_method, but with different arguments. We'll get failure output like:

Failure:
ExampleTest#test_something [/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/proxy.rb:217]:

But that source location isn't very helpful. I traced it down to the way minitest looks for a probable failure line. It looks at the backtrace of the exception and grabs the line just after a line matching the regex /in .(assert|refute|flunk|pass|fail|raise|must|wont)/ (note, this is based on the version of minitest I'm using, but the most recent version does essentially the same thing).

And the backtrace looks like:

"/Users/user/.gem/ruby/2.7.8/gems/rspec-support-3.12.0/lib/rspec/support.rb:102:in `block in <module:Support>'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-support-3.12.0/lib/rspec/support.rb:111:in `notify_failure'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/error_generator.rb:348:in `notify'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/error_generator.rb:332:in `__raise'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/error_generator.rb:55:in `raise_unexpected_message_args_error'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/message_expectation.rb:555:in `raise_unexpected_message_args_error'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/proxy.rb:217:in `message_received'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/proxy.rb:361:in `message_received'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/method_double.rb:91:in `proxy_method_invoked'",
"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/method_double.rb:67:in `block (2 levels) in define_proxy_method'",
"/Users/user/project/lib/example.rb:10:in `do_something'",
"/Users/user/project/test/unit/lib/example_test.rb:4:in `block in <class:ExampleTest>'",
"/Users/user/.gem/ruby/2.7.8/gems/minitest-5.11.3/lib/minitest/test.rb:98:in `block (3 levels) in run'",
"/Users/user/.gem/ruby/2.7.8/gems/minitest-5.11.3/lib/minitest/test.rb:195:in `capture_exceptions'"

So this line gets matched by the regex:

"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/message_expectation.rb:555:in `raise_unexpected_message_args_error'",

And then this line is the next one, where minitest thinks the error is:

"/Users/user/.gem/ruby/2.7.8/gems/rspec-mocks-3.12.5/lib/rspec/mocks/proxy.rb:217:in `message_received'",

I feel like it would be more correct for the location of the error to be:

"/Users/user/project/lib/example.rb:10:in `do_something'",

Is there some way rspec-mocks could create an exception with a backtrace that leads to the project's code rather than itself?

FYI: The actual exception being raised is a Minitest::Assertion, but it was created by rspec-mocks as a RSpec::Mocks::MockExpectationError. I'm guessing it's the minitest_integration that sets that class to Minitest::Assertion.

Your environment

• Ruby version: 2.7.8
• rspec-mocks version: 3.12.5
• rspec-expectations version: 3.12.2
• rspec version: 3.12.0

[JonRowe]

👋 This is up to minitest, we use Ruby semantics when it comes to raises errors or allowing errors to be raised. In rspec-core we filter backtraces before displaying them so this would be the responsibility of minitest here.

[onlynone]

For that to work, wouldn't minitest need to have detailed backtrace filtering heuristics for any third-party testing tool that might raise errors from deep within their own code? Minitest already does its own filtering of backtraces to weed out its own code, but after that it just looks to where the raise happened.

It seems like it could be pretty helpful if rspec could craft a backtrace that pointed to where the mock actually received the bad call.

[JonRowe]

Gem names create predictable filenames, in rspec-core we offer even an api to filter 3rd party gems from our display, we do filter out ourselves slightly differently in that we fillter out a list of lib/rspec/<gem> but you could actually use our filter_gem functionality to achieve the same. This is much less maintenance work than trying to do this at raise time, and although I've not benchmarked it I would guess its more performant.

[onlynone]

We may be misunderstanding each other.

I think the problem is that rspec isn't the one displaying the backtraces, minitest is. That library looks through the backtrace to see if they can find where something was raised or asserted. To that library, there's no difference between an exception being raised in rspec's code (or any other random assertion/expectation library) and user code.

However, when rspec creates the exception, it could pre-remove its own lines from the exception's backtrace so that the first line would point to where the problem happened in the user's code.

I created a PR to show what I mean in #1593 .

[JonRowe]

We just solve this problem with a feature to filter gems out which are considered 3rd party, it could be rspec-mocks, or shoulda, or any other library. Minitest could also implement a feature like this.

Removing the backtrace lines would duplicate our logic for filtering out lines when displaying them, and also circumvent our feature which allows you to optionally remove that filtering and see the entire stacktrace, so changing this behavious is not something we want to do.

[onlynone]

We just solve this problem with a feature to filter gems out which are considered 3rd party

Is there a way to leverage the existing code in rspec-core to do this then?

I feel like there's not a lot of duplication since the issue I'm having isn't about filtering out arbitrary third-party gems. It's just having rspec-mocks remove its own lines from backtraces. Since rspec-mocks is where the exception is created, it seems like it would be the best and most direct place to deal with removing the extra lines.

also circumvent our feature which allows you to optionally remove that filtering and see the entire stacktrace

That sounds like an essential feature, I think it would make sense to make the type of filtering I'd like configurable as well. Is there some way you could see that rspec-mocks could leverage all the existing code and configuration from rspec-core to do this. Or could the feature I'd like to see added to rspec-mocks be placed behind its own option?

[onlynone]

I'm viewing this similar to how mock expectations that don't fire a failure until teardown will set the backtrace_line so that developers can see where their code where the expectation was created, since it doesn't really help to see that an exception was raised in teardown / verify. This is a situation where rspec-mocks helps out the developer by mucking with the backtrace to put the troublesome line at the top. I was just hoping to do the same for expectations that fail during the test instead of after.