Closed voxik closed 1 year ago
I'm very confused by those messages, they are not at all what I would expect from an rspec-mocks
failure, if you check the source of these changes you'll see you should actually get a diff of args with keyword or hash added to the output to differentiate between them... and indeed running guard master locally I get proper failures:
1) Guard::Commands::Scope with a valid Guard group scope sets up the scope with the given scope
Failure/Error: session.interactor_scopes = scopes
#<Guard::Internals::Session:21520> received :interactor_scopes= with unexpected arguments
expected: ({:groups=>[:frontend], :plugins=>[]}) (keyword arguments)
got: ({:groups=>[:frontend], :plugins=>[]}) (options hash)
Diff:
# ./lib/guard/commands/scope.rb:36:in `process'
# ./spec/lib/guard/commands/scope_spec.rb:34:in `block (3 levels) in <top (required)>'
2) Guard::Commands::Scope with a valid Guard plugin scope runs the :scope= action with the given scope
Failure/Error: session.interactor_scopes = scopes
#<Guard::Internals::Session:21660> received :interactor_scopes= with unexpected arguments
expected: ({:groups=>[], :plugins=>[:dummy]}) (keyword arguments)
got: ({:groups=>[], :plugins=>[:dummy]}) (options hash)
Diff:
# ./lib/guard/commands/scope.rb:36:in `process'
# ./spec/lib/guard/commands/scope_spec.rb:43:in `block (3 levels) in <top (required)>'
3) Guard::Interactor#options & #options= options set after interactor is instantiated set the options and initialize a new interactor job
Failure/Error: @_idle_job ||= _job_klass.new(engine, options)
#<Guard::Jobs::PryWrapper (class)> received :new with unexpected arguments
expected: (#<Guard::Engine:22260 @options={:watchdirs=>"/Users/jon/Code/Scratch/guard", :inline=>"guard :dummy", :no_interactions=>true}>, {:foo=>:bar}) (keyword arguments)
got: (#<Guard::Engine:22260 @options={:watchdirs=>"/Users/jon/Code/Scratch/guard", :inline=>"guard :dummy", :no_interactions=>true}>, {:foo=>:bar}) (options hash)
Diff:
# ./lib/guard/interactor.rb:60:in `_idle_job'
# ./spec/lib/guard/interactor_spec.rb:57:in `block (4 levels) in <top (required)>'
4) Guard::Engine#start listener initialization initializes the listener
Failure/Error:
expect(Listen).to receive(:to)
.with("/foo", latency: 2, wait_for_delay: 1).and_return(listener)
Listen received :to with unexpected arguments
expected: ("/foo", {:latency=>2, :wait_for_delay=>1}) (keyword arguments)
got: ("/foo", {:latency=>2, :wait_for_delay=>1}) (options hash)
Diff:
# ./spec/lib/guard/engine_spec.rb:41:in `block (4 levels) in <top (required)>'
5) Guard::Notifier.notify with multiple parameters notifies
Failure/Error:
expect(notifier).to receive(:notify)
.with("A", priority: 2, image: :failed)
#<InstanceDouble(Notiffany::Notifier) (anonymous)> received :notify with unexpected arguments
expected: ("A", {:image=>:failed, :priority=>2}) (keyword arguments)
got: ("A", {:image=>:failed, :priority=>2}) (options hash)
Diff:
# ./spec/lib/guard/notifier_spec.rb:64:in `block (4 levels) in <top (required)>'
Finished in 4.26 seconds (files took 0.25036 seconds to load)
523 examples, 5 failures
We do use pp
to pretty print objects to diff them, and we delay loading it until its needed to avoid someoverheads (if you never fail you never load pp
) but it feels like prehaps this issue doesn't lie within RSpec, but in something guard is doing?
I'm having similar issue, but not on 3.12. It was when I was updating to rspec-mocks 3.11.2 from 3.11.1
ruby 3.1.2p20 (2022-04-12 revision 4491bb740a) [x86_64-darwin21] macOS Ventura 13.0 rspec-core 3.11.0 rspec-expectations 3.11.1 rspec-rails 6.0.1 (this is what caused the bump to rspec-mocks 3.11.1 to 3.11.2 in my case, I was on 6.0.0)
Example of failing expectation:
expect(described_class.tracker).to receive(:track).with(
user_id: user.id,
event: event,
properties: properties.merge(common_event_properties),
timestamp: timestamp,
anonymous_id: nil
)
Failure output:
RSpec::Mocks::MockExpectationError #<...snip...>
Failure/Error: tracker.track(payload)
#<Client:0x00007fe9bd2adc90 @config=#<...snip...>> received :track with unexpected arguments
expected: ({ user_id: 612, event: "non", properties: { fake_property: "fake value", has_primary: true, track_id: 131, track_assignment_id: 129, product_id: nil, product_subscription_id: nil, product_subscription_assignment_id: nil, deployment_type: "standard", hubspot_contact_id: nil }, timestamp: #<DateTime 2020-01-01 00:00:00 +00:00 (+00:00)>, anonymous_id: nil, integrations: ["Amplitude"] })
got: ({ user_id: 612, anonymous_id: nil, event: "non", properties: { fake_property: "fake value", has_primary: true, track_id: 131, track_assignment_id: 129, product_id: nil, product_subscription_id: nil, product_subscription_assignment_id: nil, deployment_type: "standard", hubspot_contact_id: nil }, timestamp: #<DateTime 2020-01-01 00:00:00 +00:00 (+00:00)>, integrations: ["Amplitude"] })
When trying to debug the above, I switched to the .receive(...)
block syntax, but that seemed to fix it with no additional changes to the failing spec or underlying code:
expect(described_class.tracker).to receive(:track) do |args|
expected_args = {
user_id: user.id,
event: event,
properties: properties.merge(common_event_properties),
timestamp: timestamp,
anonymous_id: nil
}
# I used .eq() and .match() and both seem to work and pass.
expect(args).to match(expected_args)
end
Would you please update to rspec-mocks
3.12.0, @cfurrow to see some additional information introduced here?
It would be helpful to see how you pass arguments to .track
in your code under test.
Ok, updated rspec-mocks to 3.12.0 (had to bump rspec, rspec-core, rspec-expectations, etc, to 3.12.0 first)
The syntax to call this .track
method when under test is nothing special. Here's an example of one of the spec examples I updated to use .receive(...) do; end
. Note that described_class.track
is a convenience method that delegates to described_class.tracker.track
:
# NOTE: this example passes when I converted it to the block-form of .receive(...) from .receive(...).with(...)
it do
expect(described_class.tracker).to receive(:track) do |args|
expected_args = {
user_id: user.id,
event: event,
properties: properties.merge(common_event_properties),
timestamp: timestamp,
anonymous_id: nil
}
expect(args).to match(expected_args)
end
described_class.track(user: user, event: event, properties: properties, timestamp: timestamp)
end
I have not converted all of my examples in this file to use the block form of .receive(...)
, so some spec examples still fail with the original error message I saw under rspec-mocks 3.11.2.
This failure is for this example:
it do
expect(described_class.tracker).to receive(:track).with(
user_id: user.id,
event: event,
properties: properties.merge(common_event_properties),
timestamp: timestamp,
anonymous_id: nil
)
described_class.track(user: user, event: event, properties: properties, timestamp: timestamp)
end
1) AnalyticsService.track when ...snip
Failure/Error: tracker.track(payload)
#<Client:...snip...> received :track with unexpected arguments
expected: ({ user_id: 16, event: "voluptatem", properties: { fake_property: "fake value", has_primary: true, track_id: 4, track_assignment_id: 4, product_id: nil, product_subscription_id: nil, product_subscription_assignment_id: nil, deployment_type: "standard", hubspot_contact_id: nil, app_version: nil, app_build: nil, platform_name: "Android", platform_version: nil, browser_name: "okhttp", browser_version: "1.23.4" }, timestamp: #<DateTime 2020-01-01 00:00:00 +00:00 (+00:00)>, anonymous_id: nil })
got: ({ user_id: 16, anonymous_id: nil, event: "voluptatem", properties: { fake_property: "fake value", has_primary: true, track_id: 4, track_assignment_id: 4, product_id: nil, product_subscription_id: nil, product_subscription_assignment_id: nil, deployment_type: "standard", hubspot_contact_id: nil, app_version: nil, app_build: nil, platform_name: "Android", platform_version: nil, browser_name: "okhttp", browser_version: "1.23.4" }, timestamp: #<DateTime 2020-01-01 00:00:00 +00:00 (+00:00)> })
Diff:
# ./app/services/analytics_service.rb:67:in `track'
# ./spec/services/analytics_service_spec.rb:1740:in `block (5 levels) in <main>'
That does not seem like a different error under rspec + rspec-mocks 3.12.0, which makes me think it was introduced as part of rspec-mocks 3.11.2.
An obvious difference is properties: properties.merge(common_event_properties)
vs properties: properties
. Can it cause the failure?
Nope, same failure when changing the call to .track
to use properties.merge(...)
it do
expect(described_class.tracker).to receive(:track).with(
user_id: user.id,
event: event,
properties: properties.merge(common_event_properties),
timestamp: timestamp,
anonymous_id: nil
)
described_class.track(user: user, event: event, properties: properties.merge(common_event_properties), timestamp: timestamp)
end
1) AnalyticsService.track when ...snip...
Failure/Error: tracker.track(payload)
#<Client:0x00007ff0d8022940 ...snip...> received :track with unexpected arguments
expected: ({ user_id: 20, event: "commodi", properties: { fake_property: "fake value", has_primary: true, track_id: 5, track_assignment_id: 5, product_id: nil, product_subscription_id: nil, product_subscription_assignment_id: nil, deployment_type: "standard", hubspot_contact_id: nil, app_version: nil, app_build: nil, platform_name: "Android", platform_version: nil, browser_name: "okhttp", browser_version: "1.23.4" }, timestamp: #<DateTime 2020-01-01 00:00:00 +00:00 (+00:00)>, anonymous_id: nil })
got: ({ user_id: 20, anonymous_id: nil, event: "commodi", properties: { fake_property: "fake value", has_primary: true, track_id: 5, track_assignment_id: 5, product_id: nil, product_subscription_id: nil, product_subscription_assignment_id: nil, deployment_type: "standard", hubspot_contact_id: nil, app_version: nil, app_build: nil, platform_name: "Android", platform_version: nil, browser_name: "okhttp", browser_version: "1.23.4" }, timestamp: #<DateTime 2020-01-01 00:00:00 +00:00 (+00:00)> })
Diff:
# ./app/services/analytics_service.rb:67:in `track'
# ./spec/services/analytics_service_spec.rb:1740:in `block (5 levels) in <main>'
Update Converting this failing spec example to the block-form of .receive(...)
seems to "fix" the failure, similar to the previous failures and fixes I've done.
it do
expect(described_class.tracker).to receive(:track) do |args|
expected_args = {
user_id: user.id,
event: event,
properties: properties.merge(common_event_properties),
timestamp: timestamp,
anonymous_id: nil
}
expect(args).to match(expected_args)
end
described_class.track(user: user, event: event, properties: properties.merge(common_event_properties), timestamp: timestamp)
end
By the way, @pirj, I appreciate your quick replies here. I was simply commenting initially help build a context of the possible bug that the original poster was seeing. I was hoping it may be enough to realize what recent change may have caused this. Thanks for sticking with it.
I'd rather take the merge
part out, as this adds some volatility.
And would incrementally reduce the list of keys starting with properties
, then timestamp
to narrow it down to what is causing the failure.
I understand that the block form doesn't have this failure, but it doesn't help much to track the problem.
My initial assumption was that on the code you pass it in as a hash, but pass kwargs to .with
, but it doesn't seem to be the case, 3.12.0 would detect and report this.
Changes to rspec-mocks from 3.11.2 -> 3.12.0 that seem related, but I've not completely understood them yet:
lib/rspec/mocks/argument_list_matcher.rb: https://github.com/rspec/rspec-mocks/compare/v3.11.1...v3.12.0#diff-ae171e2be1f799a6704fcbadb353721dda4d078185aa265671e07b14594c72e5L49-R74
lib/rspec/mocks/error_generator.rb: https://github.com/rspec/rspec-mocks/compare/v3.11.1...v3.12.0#diff-5b28aeeb36e96d3d3567364a3c0dff29001eae3a81bce2752e29b9d3bca04fbeR271-R281
lib/rspec/mocks/matchers/receive.rb: https://github.com/rspec/rspec-mocks/compare/v3.11.1...v3.12.0#diff-8efd45e556df39ba1efa67c1086d56aba98e46a6a4fb31e9d9246505caf4451cL65-R65
lib/rspec/mocks/message_expectation.rb: https://github.com/rspec/rspec-mocks/compare/v3.11.1...v3.12.0#diff-afc11368b62c27a5bd155b766ec9cf4e96a9331d073b6123a9bce36a270de640L142-R810
lib/rspec/mocks/method_double.rb: https://github.com/rspec/rspec-mocks/compare/v3.11.1...v3.12.0#diff-df0ec6501cb8ef91a9806b4a90bb265b7d4affbbf4994bde7033f02b9ca92827R66-R82
lib/rspec/mocks/method_reference.rb: https://github.com/rspec/rspec-mocks/compare/v3.11.1...v3.12.0#diff-68b5edb44e7a864abc3329011e7186acd8ec5895890682dda8e6f986af1584dcL188-R204
There may be more.
@voxik This change is reasonable:
- expect(Guard::LiveReload::Reactor).to receive(:new).with(
+ expect(Guard::LiveReload::Reactor).to receive(:new).with({
As options
is a regular Hash, and you pass it to Reactor.new
. On Ruby 3+, there is a difference.
rspec-mocks
3.12.0 is supposed to point at this kind of failures, marking expected and actual with their internal type ("(keyword arguments)" vs "(options hash)").
The same seem to be the case for your other PR:
- .with(groups: [:frontend], plugins: [])
+ .with({ groups: [:frontend], plugins: [] })
session.interactor_scopes = scopes
and scopes
initialization:
scopes, = session.convert_scopes([])
If e.g. Reactor.initialize
or Session#interactor_scope=
would really have kwargs in their method signature, on Ruby 3+ you would get an error message:
ArgumentError: wrong number of arguments (given 1, expected 0; required keyword: ...)
I might be mistaken, but an option is to pass them there as such:
Reactor.new(**options)
but that won't work with attr_accessor :interactor_scopes
like session.interactor_scopes=(**scopes)
.
If this is the culprit, I'm uncertain if we should check if the stub's method signature has kwargs, and if it doesn't, skip checking for hash vs kwargs difference on Ruby 3+.
@cfurrow It's hard to say that there is anything wrong with rspec-mocks
here to start bisecting it.
I'd rather narrow down your use case to have a minimal reproduction example. Can you help out with this?
This repo demonstrates the failure exactly: https://github.com/cfurrow/rspec-mocks-fail-example
bin/rspec
AnalyticsService
.track
does not fail when I use .receive().with() (FAILED - 1)
does not fail when I use .receive() block-form
Failures:
1) AnalyticsService.track does not fail when I use .receive().with()
Failure/Error: tracker.track(payload)
#<Tracker:0x0000000107ddf510> received :track with unexpected arguments
expected: ({:anonymous_id=>nil, :event=>"foobar", :properties=>{:deployment_type=>"standard", :fake_property=>"f...9}, :timestamp=>#<DateTime: 2020-01-01T00:00:00+00:00 ((2458850j,0s,0n),+0s,2299161j)>, :user_id=>1}) (keyword arguments)
got: ({:anonymous_id=>nil, :event=>"foobar", :properties=>{:deployment_type=>"standard", :fake_property=>"f...9}, :timestamp=>#<DateTime: 2020-01-01T00:00:00+00:00 ((2458850j,0s,0n),+0s,2299161j)>, :user_id=>1}) (options hash)
Diff:
# ./lib/analytics_service.rb:26:in `track'
# ./spec/lib/analytics_service_spec.rb:31:in `block (3 levels) in <top (required)>'
Finished in 0.03275 seconds (files took 0.15496 seconds to load)
2 examples, 1 failure
Failed examples:
rspec ./spec/lib/analytics_service_spec.rb:23 # AnalyticsService.track does not fail when I use .receive().with()
I'm trying to setup a branch on https://github.com/cfurrow/rspec-mocks-fail-example that changes rspec-mocks back to v3.11.1, but doing so has not given me the same failure I saw in my main repo. It fails the same way that rspec-mocks 3.12.0 is failing.
https://github.com/cfurrow/rspec-mocks-fail-example/compare/rspec-mocks-3.11.1?expand=1
I still only get one passing and one failing spec example, like I do in v3.12.0. Hmm.
Surrounding the args in {}
, seems to fix it, which makes me think it's a kwargs vs hash issue. But this was not coming up in our repo prior to the change to rspec, rspec-mocks, etc, today (we were on 3.11.0 or 3.11.1 for all related rspec gems).
Puzzling.
it 'does not fail when I use .receive().with()' do
- expect(described_class.tracker).to receive(:track).with(
+ expect(described_class.tracker).to receive(:track).with({
user_id: user.id,
event: event,
properties: properties.merge(common_event_properties),
timestamp: timestamp,
anonymous_id: nil
- )
+ })
Our CI environment is still setup with rspec 3.11.0, rspec-mocks 3.11.1, rspec-expectations 3.11.1, etc, and is not showing failures for the specs I've shown in this issue.
The original error and your error are different, RSpec is providing a diff but it seems the order has changed for you, where as the original error in this issue provides no details at all as to whats gone wrong
Same for your example as for original one, you pass an options hash, and Ruby doesn't unfold that to kwargs. The following fixes it:
- tracker.track(payload)
+ tracker.track(**payload)
I'm not sure why you didn't see the "(keyword arguments)" vs "(options hash)" in the failure message, but I see it on Ruby 3.1.0.
If you're still inclined to think that rspec-mocks
is misbehaving, a PR, at least with a failing spec is welcome.
(re opened because the original poster has not got a sensible error output, I don't think RSpec is at fault see my earlier reproduction but I'd like to hear from the orignal poster again before closing)
The frustrating thing is, the specs were passing before the gem version changes. Below is a diff of the extent of my PR changes that was primarily made to bump rspec-rails from 6.0.0 to 6.0.1, and the specs that I've outlined above were passing, but now are not. The specs have not been modified, and continue to pass on other branches within our CI environment.
diff --git a/Gemfile.lock b/Gemfile.lock
- rspec (3.11.0)
- rspec-core (~> 3.11.0)
- rspec-expectations (~> 3.11.0)
- rspec-mocks (~> 3.11.0)
- rspec-core (3.11.0)
- rspec-support (~> 3.11.0)
- rspec-expectations (3.11.1)
+ rspec (3.12.0)
+ rspec-core (~> 3.12.0)
+ rspec-expectations (~> 3.12.0)
+ rspec-mocks (~> 3.12.0)
+ rspec-core (3.12.0)
+ rspec-support (~> 3.12.0)
+ rspec-expectations (3.12.0)
- rspec-support (~> 3.11.0)
- rspec-mocks (3.11.1)
+ rspec-support (~> 3.12.0)
+ rspec-mocks (3.12.0)
- rspec-support (~> 3.11.0)
- rspec-rails (6.0.0)
+ rspec-support (~> 3.12.0)
+ rspec-rails (6.0.1)
- rspec-support (3.11.1)
+ rspec-support (3.12.0)
- zeitwerk (2.6.1)
+ zeitwerk (2.6.5)
So, with this ^ context, my assumption was something in the realm of rspec, or rspec-* seems to have caused a previously "fine" behavior and code to now come back as failing. That's when I found this current issue that seemed like a possible lead.
I understand that it seems to be some issue between passing a Hash or kwargs, but my point is that my code has not changed. The code may be passing kwargs when it should be passing a Hash, or it should be splatting it **payload
into kwargs, I agree, but my original point is that this was passing and is still passing on other branches without changes being made.
Something seems to have altered beyond my current understanding in one, or more, rspec gems. My guess was it's centered around mocks because we're dealing with .receive(...).with(...)
, but I could be mistaken.
Sorry, I have not received notifications from GH up until now 😖
Well, the Guard test suite is doing (or did, there were some big changes) heavy mocking and this is where it actually fails:
https://github.com/guard/guard/blob/v2.18.0/spec/spec_helper.rb#L229-L231
Yes, there is abort
call which quits the execution. However, this was not an issue, as long as the test case was passing. But due to kwargs checking, the test fails and therefore the pp
is required, making this very confusing.
Please note that I am not related to Guard project in any way. I was just trying to fix Fedora package, which suddenly started to fail with RSpec update. Therefore I am not familiar with the test suite to understand on the first look that ENV
was mocked.
IOW one concern is that ENV
cannot be freely mocked, because pp
depends on ENV
.
The guard-livereload fails here:
Again, there is abort. But the issue is that something is newly using File.expand_path
during the evaluation of the test double. I have not digger deeper into this, once I was sure that fixing the test avoids this issue.
@cfurrow I believe it is this small change that now makes your specs fail. It is correct, as you expect (with
with kwargs) kwargs, but the code is actually passing an options hash argument.
@voxik There's an open issue about abort
/exit
in rspec-core
Do you think there's anything actionable left for rspec-mocks
?
I still think that rspec-mocks could "do less" during the double call evaluation. Loading library once the failure is identified is probably too much (although when I suggested the preloading of pp
, that would have different side effects on the runtime. Therefore that was probably not the best idea).
Possibly the stubs should not affect the evaluation. The failure was due to kwargs, then there was an attempt to construct some error message and this should not be affected by the test doubles.
Or maybe use some "less verbose mode" be default. Don't provide the details of the failure, just provide the line of failure. I.e. better to say less then to provide misinformation.
Or maybe use some "less verbose mode" be default. Don't provide the details of the failure, just provide the line of failure. I.e. better to say less then to provide misinformation.
Or just don't use pp
:)
@cfurrow I believe it is this small change that now makes your specs fail. It is correct, as you expect (with with kwargs) kwargs, but the code is actually passing an options hash argument.
Thanks for the note, @pirj -- that was the bit of code I'd not fully understood, but assumed it was the cause of my current frustration. I'll continue cleaning up my code to correct how we pass Hash or kwargs to .with()
.
I appreciate all the help and context on this.
I still think that rspec-mocks could "do less" during the double call evaluation.
You can turn off verifying doubles if you want RSpec to do "less", although with projects outside your control thats more difficult.
Or just don't use
pp
We can't provide diffs without pp
as it stands. There is an open discussion on rspec-support about a future differ that could not rely on printing objects.
Given that it does seem that the weird ENV stubbing is actually to blame here, I'm going to close this now.
Subject of the issue
I have just sent several PR to fix test suites of Guard projects:
https://github.com/guard/guard/pull/986 https://github.com/guard/guard-livereload/pull/194
What is problematic is that RSpec breaks the test suite in incomprehensible way. E.g. the guard test suite failed like this:
which does not even look like failure, except the return code. Please note that there is not
COLUMNS
string in the whole guard code base.The guard-livereload was failing in following way:
This is frustrating, because if you check the fixes, they really fix the kwargs. One might say that Guard is using some unorthodox ways of stubbing some calls. But OTOH, it is not nice that it really is not obvious what is going on. And surprisingly, in both cases the error is related to loading/using
pp
.I don't know if there is anything actionable here. Maybe the
pp
could be preloaded or it would not need to be used at all. Maybe there is a way to release changes like this when they are more polished. Maybe you can distill some bits of this report into separate tickets. I leave it to your consideration and will not be super sad if you just nod and close the ticket :)