VCR has stopped matching a recorded transaction in a cassette?

1,128 views
Skip to first unread message

Jonathan Rochkind

unread,
Mar 29, 2013, 1:18:44 PM3/29/13
to vcr-...@googlegroups.com
I can't figure out what's going on. VCR has stopped matching a
transaction in a recorded cassette... that it used to match.

I actually no longer have access to the thing that was recorded, so it's
hard for me to re-record. I can't figure out why it's stopped
recognizing it.

I get:

VCR::Errors::UnhandledHTTPRequestError:

================================================================================
An HTTP request has been made that VCR does not know how to handle:
GET
http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2/w9Gjg%2BwmkWnBdUv3As=

VCR is currently using the following cassette:
-
/home/rochkind/bento_search/test/vcr_cassettes/eds/basic_search_smoke_test.yml
- :record => :once
- :match_requests_on => [:method, :uri]

***************

However, if I look in the basic_search_smoke_test.yml cassette, I see
this excerpt:

- request:
method: get
uri:
http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf851d-9a36-435b-a50a-14a5aea15338.KErj2NrKZC8UxoZu2SfB28G2/w9Gjg+wmkWnBdUv3As=



That sure looks like the same method/uri, doesn't it? The
'sessiontoken' parameter looks identical.

Why is VCR not matching the recorded transaction in the cassette? Any
tips for how I'd go about debugging why it may not be matching?

I did just update dependencies in my Gemfile.lock, so it's possible that
somehow a change in HTTPClient or WebMock led to this.... I'll try
rolling back my Gemfile.lock to try and find out... but even if so, I'm
not quite sure what I'd do about it, unless it's a bug of some kind in
VCR that can be fixed.

Thanks for any advice!

Jason Ronallo

unread,
Mar 29, 2013, 1:24:02 PM3/29/13
to vcr-...@googlegroups.com

What version of web mock are you using? IIRC the most recent version of webmock may not work with the latest version of VCR.

Jason

--
You received this message because you are subscribed to the Google Groups "VCR Rubygem" group.
To unsubscribe from this group and stop receiving emails from it, send an email to vcr-ruby+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.


Jonathan Rochkind

unread,
Mar 29, 2013, 1:24:49 PM3/29/13
to vcr-...@googlegroups.com
Answer to myself is, rolling back to WebMock 1.9 seems to have fixed
things.

I had inadvertantly upgraded to WebMock 1.11.0. Although VCR warns
that anything beyond WebMock "< 1.8.0" is unverified -- 1.9.0 works
fine, but 1.11.0 results in the UnhandledHTTPRequestError, even though
there's a recorded transaction that ought to match.

Why it only does this with this one particular transaction, you got me.

But okay, I'll lock to WebMock 1.9.0 until a subsequent version of VCR
says it's verified with something higher.

Hooray for bundler and Gemfile.lock making it reasonable to figure out
what happened here.

Jonathan Rochkind

unread,
Mar 29, 2013, 1:27:42 PM3/29/13
to vcr-...@googlegroups.com
Ha, and to correct myself AGAIN... I had VCR locked to 2.3.0.

Updating VCR to 2.4.0, now it DOES work with most recent Webmock, 1.9.0.
Hooray.

Since vcr uses semver (I think?), I was probably in error to have vcr
locked to "~> 2.3.0" in my gemfile, I will change it to "~> 2.4", to
allow future 2.x updates silently.

Jonathan

Myron Marston

unread,
Mar 29, 2013, 1:44:15 PM3/29/13
to VCR Rubygem
We try to follow SemVer as much as we can, but sometimes it's hard,
and there are situations with VCR where I'm not sure what SemVer
requires: for example, if one of the libraries VCR hooks into changes
their APIs such that VCR has to be updated, it's a lot of work for VCR
to maintain compatibility with both the old and new versions, even
though I suspect that SemVer would dictate that VCR shouldn't update
increment it's version requirement without a major release (since
requiring a newer version than it did previously could be considered a
backwards-incompatibility). So we (imperfectly) follow SemVer.

FWIW, I have a VCR branch that has updates against the lastest WebMock
and Excon:

https://github.com/vcr/vcr/pull/276

I'm waiting to merge until there are some upstream changes in Excon,
though, since it will vastly simplify the VCR/Excon integration.

BTW, anytime you don't understand what VCR is doing, I highly
recommend you try the debug_logger option to get detailed output of
how it's matching requests; that'll usually pinpoint the failure for
you:

https://relishapp.com/vcr/vcr/v/2-4-0/docs/configuration/debug-logging!

HTH,
Myron
> >>http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf...
>
> >> VCR is currently using the following cassette:
> >>    -
> >> /home/rochkind/bento_search/test/vcr_cassettes/eds/basic_search_smoke_test. yml
>
> >>    - :record => :once
> >>    - :match_requests_on => [:method, :uri]
>
> >> ***************
>
> >> However, if I look in the basic_search_smoke_test.yml cassette, I see
> >> this excerpt:
>
> >> - request:
> >>      method: get
> >>      uri:
> >>http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf...

Jonathan Rochkind

unread,
Mar 29, 2013, 1:50:35 PM3/29/13
to vcr-...@googlegroups.com, Myron Marston
Awesome, I did not know about debug-logging.

Understand "semver" is tricky to interpret/implement in practice.

What's your personal recommendation for what to lock to? "~> 2.4" or
"~> 2.4.0"? Allow transparent update to 2.x, figuring it will be rare
that has backwards incompat, and usually only by mistake on VCR's part?
Or only allow transparent update to 2.4.x, because 2.5 may well have
backwards breaking changes?

Myron Marston

unread,
Mar 29, 2013, 2:26:07 PM3/29/13
to Jonathan Rochkind, vcr-...@googlegroups.com
Personally, I tend to use `>=` (e.g. no upper constraints) for most gems in the Gemfile of my applications.  My Gemfile.lock locks to an exact version.  I want to be able to `bundle update` all gems and get latest of everything...then, after running my tests, if there's an incompatibility, I'll lock the version constraint for that one gem down using `~>` appropriately until I can spend more time upgrading it properly.

This workflow doesn't work for everyone, though.  (I have an uncommonly high level of test coverage that runs quite fast).

If you like to specify versions using the `~>` operator, I'd recommend locking using `~> 2.4`.  I make the effort to follow SemVer.

Jonathan Rochkind

unread,
Apr 22, 2013, 1:43:37 PM4/22/13
to vcr-...@googlegroups.com, Myron Marston
Okay, I'm actually still having trouble with this.  I think I got confused before, thinking 1.9.0 was the latest WebMock. 

What version of WebMock is VCR 2.4.0 confirmed to work with?

If you update versions of WebMock and VCR, with existing cassettes, is there any known reason it should stop finding transactions in existing cassettes?

I have some tests using VCR that work fine with VCR 2.4.0 and WebMock 1.9.0.  With casettes that were probably recorded with even earlier versions of vcr/webmock, and kept working. 

If I update to webmock 1.11.0, still using VCR 2.4.0 -- suddenly it can't find some of the existing transactions. It doesn't seem to lose all of them, but it loses some of them. 

I've tried to turn on debug-logging as previously recommended by Myron. There is a LOT of info there, I _think_ this is the suspicious line:


Hmm, looks like maybe in one version of WebMock the URL was stored with a "+" escaped as "%2B", and in another version of WebMock, it was not -- so it can't find the transaction. 

Do I have that right?  Is this a bug? Or just a hazard of VCR, when updating VCR/webmock, you might lose access to previously recorded transactions and have to manually alter them and/or re-record them?

In this case, the recorded transaction is for a vendor API behind a paywall that I actually don't currently have access to -- VCR was great in letting me continue running tests against it's recorded output anyway. Any suggestions for how to proceed?

Jonathan Rochkind

unread,
Apr 22, 2013, 1:46:58 PM4/22/13
to vcr-...@googlegroups.com
And now I'm wondering if that "+" is really _supposed_ to be an encoded
space, or a literal "+". I'm honestly not sure what it's supposed to
be in this convoluted code using a convolunted vendor API, that I
recorded transactions for months ago. %2B is an encoded "+", not an
encoded space. Bah, so confusing. I wonder if there actually is a bug
here somewhere.
> <https://relishapp.com/vcr/vcr/v/2-4-0/docs/configuration/debug-logging>!
> <http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf.>..
>
> >>
> >>>> VCR is currently using the following cassette:
> >>>> -
> >>>>
> /home/rochkind/bento_search/test/vcr_cassettes/eds/basic_search_smoke_test.
> yml
> >>
> >>>> - :record => :once
> >>>> - :match_requests_on => [:method, :uri]
> >>
> >>>> ***************
> >>
> >>>> However, if I look in the basic_search_smoke_test.yml
> cassette, I see
> >>>> this excerpt:
> >>
> >>>> - request:
> >>>> method: get
> >>>> uri:
> >>>>
> http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf.
> <http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf.>..
>
> >>
> >>>> That sure looks like the same method/uri, doesn't it? The
> >>>> 'sessiontoken' parameter looks identical.
> >>
> >>>> Why is VCR not matching the recorded transaction in the
> cassette? Any
> >>>> tips for how I'd go about debugging why it may not be matching?
> >>
> >>>> I did just update dependencies in my Gemfile.lock, so it's
> possible that
> >>>> somehow a change in HTTPClient or WebMock led to this.... I'll
> try
> >>>> rolling back my Gemfile.lock to try and find out... but even
> if so, I'm
> >>>> not quite sure what I'd do about it, unless it's a bug of some
> kind in
> >>>> VCR that can be fixed.
> >>
> >>>> Thanks for any advice!
> >
>
> --
> You received this message because you are subscribed to the Google
> Groups "VCR Rubygem" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to vcr-ruby+u...@googlegroups.com.

Myron Marston

unread,
Apr 22, 2013, 2:07:43 PM4/22/13
to vcr-...@googlegroups.com
What version of WebMock is VCR 2.4.0 confirmed to work with?


1.8.x and 1.9.x.

If you update versions of WebMock and VCR, with existing cassettes, is there any known reason it should stop finding transactions in existing cassettes?

I was originally going to say "no" but then read the rest of your email and it reminded me of a recent WebMock change related to the way it treats `+`:


Due to these changes (I think it actually changed one way, then changed back after it was discovered it was a regression), it's possible to have VCR cassettes that can't playback after upgrading WebMock.  You could re-record them and/or surgically "fix" the URIs in them to be what the new WebMock sends VCR.

As for the confusion about "+" -- trust me, pretty much everyone is confused.  The RFCs are not very clear on this manner.  There was recent confusion about how Sinatra should treat `+` as well.  You can read the whole discussion here:


HTH,
Myron

Jonathan Rochkind

unread,
Apr 22, 2013, 2:13:14 PM4/22/13
to vcr-...@googlegroups.com
Aha, thanks, so basically, with VCR 2.4.0, it's NOT verified to work
with WebMock 1.11.0, so I'm safest just using WebMock 1.9.0.

(Not sure why I wasn't seeing/noticing any warning from VCR on this,
might have just missed it, I remember seeing other warnings in the past).

But once I do at some point in the future update to WebMock 1.11
(presumably some future version of VCR will be verified with this) --
I'm still going to have to manually update my cassettes or re-record
them to deal with the +/%2B issue, due to a change in WebMock, so it
goes. Sigh.
> http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf <http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf>.
>
> >
> <http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf
> <http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf>.>..
>
> >
> > >>
> > >>>> VCR is currently using the following cassette:
> > >>>> -
> > >>>>
> >
> /home/rochkind/bento_search/test/vcr_cassettes/eds/basic_search_smoke_test.
>
> > yml
> > >>
> > >>>> - :record => :once
> > >>>> - :match_requests_on => [:method, :uri]
> > >>
> > >>>> ***************
> > >>
> > >>>> However, if I look in the basic_search_smoke_test.yml
> > cassette, I see
> > >>>> this excerpt:
> > >>
> > >>>> - request:
> > >>>> method: get
> > >>>> uri:
> > >>>>
> >
> http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf <http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf>.
>
> >
> <http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf
> <http://eds-api.ebscohost.com/edsapi/rest/endsession?sessiontoken=26cf>.>..
> <https://groups.google.com/groups/opt_out>.

tylerc...@gmail.com

unread,
Jul 2, 2014, 6:03:35 PM7/2/14
to vcr-...@googlegroups.com
The debug_logger is awesome. However, it truncates its comparison ("vs") output for me, which is a few hundred characters but it's being truncated to around 75. Myron, is there a way to force it to output the whole thing?

Also, I think the following should be added taken from this article and added to this documentation:

VCR.configure do |c| c.debug_logger = $stdout

Myron Marston

unread,
Jul 2, 2014, 6:09:52 PM7/2/14
to vcr-...@googlegroups.com, tylerc...@gmail.com
The truncation is by design, to avoid the log being excessively verbose, when the first 80 characters of the body is generally sufficient.  You can see the code that does the truncation here:


Consider that request/response bodies can be arbitrarily large (megabytes or gigabytes, even) and you can imagine that if that printed off the whole body, we'd quickly have a very low signal-to-noise ratio.

There's currently no API provided to get the whole thing.  You're the first to ask for one.

Myron

Myron Marston

unread,
Jul 2, 2014, 6:12:31 PM7/2/14
to vcr-...@googlegroups.com, tylerc...@gmail.com
Also, I think the following should be added taken from this article and added to this documentation:

Sorry, didn't notice this line when I wrote up my last response.  Why do you think it should be added?  The docs you link to try to make it clear that any IO-like object can be used (in fact, the only API required is `puts`, as it explicitly says).  The docs aren't to exhaustively show every possible value `debug_logger` can be set to.  I don't see the documentation value in adding an example for `$stdout`.

Myron   

On Wednesday, July 2, 2014 3:03:35 PM UTC-7, tylerc...@gmail.com wrote:
...

tylerc...@gmail.com

unread,
Jul 2, 2014, 6:19:18 PM7/2/14
to vcr-...@googlegroups.com, tylerc...@gmail.com
I think the value is for newbs. I guess I wouldn't consider myself a newb, and yet I didn't know about $stdout so I'm glad I found that. It only took a few seconds on google, but I thought it might be easy to add to the documentation.

How would you feel if I added the ability to configure the truncation length? Since I'm the only one to request this, I won't get too fancy with options around it, but allowing the truncation length to be configured would be a start.
...

Myron Marston

unread,
Jul 2, 2014, 6:24:41 PM7/2/14
to vcr-...@googlegroups.com, tylerc...@gmail.com
Well, $stdout is a general ruby thing, not a VCR thing, so I'm not sure VCR's docs are the right place to educate new ruby users that $stdout exists.  I don't want the burden of an additional cucumber scenario for $stdout (as each scenario adds to VCR's build time) but if you want to open a PR updating the narrative (the prose part above the scenario) specifically mentioning $stdout and $stderr as possibilities, I'd merge that.

The truncation config option sounds fine.


--
You received this message because you are subscribed to the Google Groups "VCR Rubygem" group.
To unsubscribe from this group and stop receiving emails from it, send an email to vcr-ruby+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Reply all
Reply to author
Forward
0 new messages