Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Check call count type #2410

Merged
merged 5 commits into from Jan 20, 2022
Merged

Conversation

cincodenada
Copy link
Contributor

@cincodenada cincodenada commented Nov 3, 2021

Purpose (TL;DR)

Fix #2408 by checking the type of the argument to callCount and emitting a specfic error message if it is not a number

Details

I also refactored the assert tests a bit while I was here - the current code is manually removing the stack traces in each individual test, but since we already have a message() helper function to extract the message, I moved the stack trace stripping up into that, which streamlines the rest of the test cases quite a bit.

I also modified the regex to be more specific, and avoid accidentally stripping the end of messages that happen to have the word "at" in them.

How to verify

  1. Check out this branch
  2. npm install
  3. Run the following test case:
const sinon = require('sinon');
const n = '10',
      s = sinon.spy();
for(let i=0; i < n; ++i) s();

sinon.assert.callCount(s, n);

You should get expected '10' to be a number but was of type string, rather than the current message which is expected spy to be called 10 times but was called 10 times

Checklist for author

  • npm run lint passes
  • References to standard library functions are cached.

This saves us from having to do it every time, and makes things much
nicer. Also use a little bit more specific regex, to avoid issues with
messages that happen to contain the word "at"

Also, fix typo that inverted the meaning of a comment :)
This is to fixes sinonjs#2408, which could result in error messages like
"expected spy to be called 10 times but was called 10 times".

Now we will instead say "expected '10' to be a number, but was of type
string", which is much clearer!
@cincodenada
Copy link
Contributor Author

I would like to backport this to all current releases, as this bug exists in all released versions - what's the procedure for doing that? Should I just open a separate PRs for each version once this is approved?

@fatso83
Copy link
Contributor

fatso83 commented Nov 4, 2021

Truth be told, we don't have a procedure for backporting ... 🤔 This would involve creating release branches for every major release to accept PRs, so I think it might be just as fast just cherry picking it manually after merging. What would you suggest?

The biggest "consumer" is probably Sinon, and that is a bit more tricky to get right. Due to creating bundles it won't distribute the fix as efficiently.

EDIT: It was 3AM when I wrote this, so not everything makes sense in hindsight. I somehow mixed this with a PR in the fake-timers project.

@fatso83
Copy link
Contributor

fatso83 commented Nov 5, 2021

all current releases,

We don't actually have something like "LTS" releases, so in the sense that we need to support different use cases it would be:

  • Sinon 1.x (if you really can't handle the breaking 2.x changes)
  • Sinon 9 (if you cannot use ES2017+)
  • Latest version

What versions would you like to fix this for? I would probably not bother with anything else than Sinon 7-12. I can probs do it if you are fine with that.

@cincodenada
Copy link
Contributor Author

cincodenada commented Nov 5, 2021

EDIT: It was 3AM when I wrote this, so not everything makes sense in hindsight. I somehow mixed this with a PR in the fake-timers project.

Ha! No worries, and thanks, that part was a bit confusing 😅

I didn't have any grand designs on backporting, but I did get carried away ("this seems like the job for a simple bash script...") and backported it to all the versions - my fork now has a -backport branch for each version, so feel free to grab from those whatever makes sense! It's certainly not a critical issue, it just seemed like it's would be relatively easy to do, so the cost/benefit ratio was still low, and it was, more or less! I did end up backporting just the fix/test, and not the test refactoring.

Anyway, I'll defer to you on what backports make sense, just the last couple versions plus 1.x sounds fine to me, or not at all! For my part I was mostly just offering to do the legwork of backporting - I don't know what your release process looks like and things, so I say do what makes sense on your end 👍

(Also if the commit does end up changing before merging that's fine, I did make the bash script so at this point it's pretty straightforward to port whatever backwards again, ha!)

Copy link
Contributor

@fatso83 fatso83 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Wondering if the fixup of one comment actually turns right to wrong.

@@ -220,7 +220,7 @@ var callProto = {
}
}
if (this.stack) {
// Omit the error message and the two top stack frames in sinon itself:
// Emit the error message and the two top stack frames in sinon itself:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this change/fix is wrong. Looking at the code, it does omit the first three elements of this.stack, which would be [message, stackframe1, stackframe2]`, so I think it was correct.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Okay, yes upon investigation you're totally right here, thanks! I misunderstood what was going on here. I misread in a couple ways:

  • I read this as a comment about what the code is doing, not how it's doing it. (It's adding things, not omitting them - but it is omitting things from the things that it's adding. Phew!)
  • I read "in sinon itself" as "add the stack frame to sinon's output" when I now realize it probably means "omit the top two stack frames, which will be in sinon itself".

After re-orienting myself, I do still think it's a little confusing. One more small bit, we're actually just pulling out only the third stack frame, right? We're not just stripping off the first two and leaving the rest, I think?

Anyway, this is a lot of focus on a small change, and the comment as it was is certainly more accurate than my replacement now that I understand it correctly. So we could revert and leave well enough alone and that would be fine! But what do you think of something like:

          if (this.stack) {
            // If present, add the third stack frame to the output for context
            // Skip the first two stack frames because they will be within Sinon code
            callStr += (this.stack.split("\n")[3] || "unknown").replace(
                /^\s*(?:at\s+|@)?/,
                " at "
            );
          }

(Code is the same, I just left it there for context)

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Definitely an improvement!

@fatso83
Copy link
Contributor

fatso83 commented Jan 19, 2022

Hi, Joel. I was about to do something about this which has been lingering for way too long, but then realized one of the commits might not be doing the right thing. Could you have a quick look at my comment and decide if I am right?

The previous "fix" was wrong, I misunderstood this code and the comment.
What's actually happening here is that we want to add a frame of context
to `callStr`, but the first two stack frames will be within Sinon code
and thus probably not helpful to the end-user.

So, we skip the first two stack frames, and append the third stack
frame, which should contain a meaningful location to the end-user.
This ensures that if at some point we end up with another Sinon layer in
the stack at some point, we'll catch it and hopefully adjust accordingly

For reference, as of this commit, the Sinon portion of the stack is:
lib/sinon/proxy-invoke.js:65:15
lib/sinon/proxy.js:265:26

Also convert a neighboring test to async while we're at it
function run() {
return stub1().then(stub2);
}
await stub2(await stub1());
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This could be

const val = await stub1();
await stub2(val);

if that seems better, I couldn't decide which was less confusing 😄

Copy link
Contributor

@fatso83 fatso83 Jan 20, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

TBH I find Promise chaining more understandable, as in await stub1().then(stub2), but I do not really care all that much either :p Whatever rocks your boat :) Either is fine.

@@ -220,7 +220,8 @@ var callProto = {
}
}
if (this.stack) {
// Omit the error message and the two top stack frames in sinon itself:
// If we have a stack, add the first frame that's in end-user code
// Skip the first two frames because they will refer to Sinon code
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I put this through another round of editing, hopefully this is still clear


assert.equals(name, "doIt()");
assert.contains(stackFrame, __filename);
});
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This test should make sure we're always returning the first end-user stack, even if the internals change. I use __filename here because for the test's purposes proxy-call-test.js is the "end-user" code, and the variable ensures we're safe from renames or what have you. Let me know if that seems unreasonable/weird.

@@ -1176,29 +1176,44 @@ describe("sinonSpy.call", function () {

// https://github.com/sinonjs/sinon/issues/1066
/* eslint-disable consistent-return */
it("does not throw when the call stack is empty", function (done) {
it("does not throw when the call stack is empty", async function () {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This test doesn't have anything to do with the rest of the PR, other than being next to the test I was adding.

I figured since it's just in tests async should be fine to use, but I also just did a search and realized the only other async tests are in promise-test.js and an es2015-specific test, so if y'all don't do async tests generally, let me know and I'll revert this bit.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We just changed target browsers to evergreen last year, so it's not all that much that has changed since. Adding async is fine, as I believe ES2018 is our current ES level.

@cincodenada
Copy link
Contributor Author

Okay, thanks for catching the comment - I decided to go ahead and add a test for the frame-appending bit too, since I didn't see one already, and converted a test to async while I was there. At this point the test cleanup outweighs the original fix I think, so if it makes more sense to split this into two PRs, let me know and I can rewrite accordingly, ha!

@fatso83 fatso83 merged commit 56b0612 into sinonjs:master Jan 20, 2022
@fatso83
Copy link
Contributor

fatso83 commented Jan 20, 2022

Great stuff, thanks for the addition!

@fatso83
Copy link
Contributor

fatso83 commented Jan 20, 2022

Ajajaj, seems that did not pan out that well as it failed when running the browser tests on SauceLabs. These 11 breaking tests are for Firefox:

  1464 passing (3s)
  13 pending
  11 failing

  1) assert
       message
         assert.notCalled exception message one call:

      [assert.equals] 'expected doSomething to not have been called but was called once\n    doSomething() at callFn@about:blank line 2 > injectedScript:47353:21' expected to be equal to 'expected doSomething to not have been called but was called once\n    doSomething()'
      + expected - actual

       expected doSomething to not have been called but was called once
      -    doSomething() at callFn@about:blank line 2 > injectedScript:47353:21
      +    doSomething()
      
  fail@about:blank line 2 > injectedScript:8641:21
  fail@about:blank line 2 > injectedScript:8801:17
  assertion@about:blank line 2 > injectedScript:8819:11
  defineAssertion/referee[type][name]@about:blank line 2 > injectedScript:8846:22
  require<[248]</</</<@about:blank line 2 > injectedScript:25036:20
      -    doSomething(1, 3, 'hey') at callFn@about:blank line 2 > injectedScript:47353:21
      -    doSomething(1, 3) at callFn@about:blank line 2 > injectedScript:47353:21
      +    doSomething(1, 3, 'hey')
      +    doSomething(1, 3)
      
  fail@about:blank line 2 > injectedScript:8641:21
  fail@about:blank line 2 > injectedScript:8801:17
  assertion@about:blank line 2 > injectedScript:8819:11
  defineAssertion/referee[type][name]@about:blank line 2 > injectedScript:8846:22
  require<[248]</</</<@about:blank line 2 > injectedScript:25748:20
  callFn@about:blank line 2 > injectedScript:47353:21
  require<[277]</<[32]</</Runnable.prototype.run@about:blank line 2 > injectedScript:47345:13
  require<[277]</<[33]</</Runner.prototype.runTest@about:blank line 2 > injectedScript:47881:10
  next/<@about:blank line 2 > injectedScript:47999:12
  next@about:blank line 2 > injectedScript:47795:14
  next/<@about:blank line 2 > injectedScript:47805:11
  next@about:blank line 2 > injectedScript:47729:14
  next/<@about:blank line 2 > injectedScript:47768:11
  done@about:blank line 2 > injectedScript:47300:7
  callFn@about:blank line 2 > injectedScript:47376:7
  require<[277]</<[32]</</Runnable.prototype.run@about:blank line 2 > injectedScript:47345:13
  next@about:blank line 2 > injectedScript:47743:10
  require<[277]</<[33]</</Runner.prototype.hook/<@about:blank line 2 > injectedScript:47773:9
  timeslice@about:blank line 2 > injectedScript:42885:27
  

  11) assert
       message
         assert.alwaysThrew exception message:

      [assert.equals] 'doSomething did not always throw exception\n    doSomething(1, 3, \'hey\') at callFn@about:blank line 2 > injectedScript:47353:21\n    doSomething(1, 3) at callFn@about:blank line 2 > injectedScript:47353:21' expected to be equal to 'doSomething did not always throw exception\n    doSomething(1, 3, \'hey\')\n    doSomething(1, 3)'
      + expected - actual

       doSomething did not always throw exception
      -    doSomething(1, 3, 'hey') at callFn@about:blank line 2 > injectedScript:47353:21
      -    doSomething(1, 3) at callFn@about:blank line 2 > injectedScript:47353:21
      +    doSomething(1, 3, 'hey')
      +    doSomething(1, 3)
      
  fail@about:blank line 2 > injectedScript:8641:21
  fail@about:blank line 2 > injectedScript:8801:17
  assertion@about:blank line 2 > injectedScript:8819:11
  defineAssertion/referee[type][name]@about:blank line 2 > injectedScript:8846:22
  require<[248]</</</<@about:blank line 2 > injectedScript:25758:20
  callFn@about:blank line 2 > injectedScript:47353:21
  require<[277]</<[32]</</Runnable.prototype.run@about:blank line 2 > injectedScript:47345:13
  require<[277]</<[33]</</Runner.prototype.runTest@about:blank line 2 > injectedScript:47881:10
  next/<@about:blank line 2 > injectedScript:47999:12
  next@about:blank line 2 > injectedScript:47795:14
  next/<@about:blank line 2 > injectedScript:47805:11
  next@about:blank line 2 > injectedScript:47729:14
  next/<@about:blank line 2 > injectedScript:47768:11
  done@about:blank line 2 > injectedScript:47300:7
  callFn@about:blank line 2 > injectedScript:47376:7
  require<[277]</<[32]</</Runnable.prototype.run@about:blank line 2 > injectedScript:47345:13
  next@about:blank line 2 > injectedScript:47743:10
  require<[277]</<[33]</</Runner.prototype.hook/<@about:blank line 2 > injectedScript:47773:9
  timeslice@about:blank line 2 > injectedScript:42885:27

@fatso83
Copy link
Contributor

fatso83 commented Jan 23, 2022

@cincodenada any chance of having a look at the Firefox issue? Otherwise I need to revert the change to unblock releases.

@cincodenada
Copy link
Contributor Author

@fatso83 Yes, sorry I intended to get to this yesterday and then got sidetracked. I'll take a look this evening (Pacific Time) - is there a way for me to run the tests in Firefox myself? If not that's fine, I'm sure I can reproduce manually, but if there's an easier way I'll take it 😄

And as a Firefox user myself, I appreciate SauceLabs' dilligence!

@cincodenada
Copy link
Contributor Author

cincodenada commented Jan 23, 2022

Okay, yeah I see what's happening here, should hopefully be a pretty simple fix - I wasn't able to test against Firefox yet, I got as far as convincing Mochify to start Firefox, but the tests didn't seem to run.

But after investigating the issue seems clear enough that I put up #2425, which reverts a small part of this PR that is causing the Firefox tests to fail, due to Firefox having a different stack trace format that breaks some assumptions I had made.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Asserting on callCount with a numeric string results in very confusing failure message
2 participants