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

switch from source-map-support to @cspotcode/source-map-support #12786

Open
wants to merge 21 commits into
base: main
Choose a base branch
from

Conversation

cspotcode
Copy link
Contributor

@cspotcode cspotcode commented May 1, 2022

Summary

Per comments here: #12485 (comment)

For a list of fixes and improvements compared to source-map-support:
cspotcode/node-source-map-support#24

Supercedes and closes #12486

Test plan

@cspotcode
Copy link
Contributor Author

Oops, I accidentally submitted this before finishing running tests locally. Test failures are not intentional; I'll try to figure out what's going on.

@cspotcode cspotcode force-pushed the cspotcode-source-map-support branch from 432bfa1 to 62dcc9c Compare May 1, 2022 19:39
@SimenB
Copy link
Member

SimenB commented May 1, 2022

Might be #9147

@cspotcode
Copy link
Contributor Author

Is there a way to attach a debugger to some of these tests, to step through what's happening? The build process and test suite bootstrapping are quite complex. I've tried opening node_modules/@cspotcode/source-map-support/source-map-support.js, changing stuff, re-running the tests, but it doesn't seem to make a difference.

@cspotcode
Copy link
Contributor Author

If I'm reading that issue correctly, jest is relying on incorrect stack traces, ones that do not match V8 / node's behavior?

@SimenB
Copy link
Member

SimenB commented May 1, 2022

essentially, yeah. I haven't bothered to attempt to work around it yet, but it might be time now. Should do that first, before landing this PR.

Semi related: #10633, facebook/react#20026

@SimenB
Copy link
Member

SimenB commented May 1, 2022

Is there a way to attach a debugger to some of these tests, to step through what's happening?

As long as you run a single test, debugging should work perfectly fine. Multiple tests spawns processes which at least chrome debugger has issues hitting. Can add --run-in-band to avoid

@SimenB
Copy link
Member

SimenB commented May 2, 2022

I've updated the snapshots in #9147, might be interesting to apply this diff on top to see if the stacks then agree

@SimenB
Copy link
Member

SimenB commented May 2, 2022

one single change, which seems sorta reasonable?

@cspotcode
Copy link
Contributor Author

There was another test failure where jest was expecting Error:\n at but we're giving it Error\n at on newer node. The latter matches vanilla node/v8. Looks like I've fixed this bug in source-map-support when running against node 16 and newer. On node 14 and older the bug still exists, but I know what to fix, so I'll do that.

@SimenB
Copy link
Member

SimenB commented May 2, 2022

Taking a look at #10633, this PR (or rather #9147), but this doesn't fix it makes the stack trace wrong.

// hubba.test.js
function BadCode() {
  throw new Error('noo');
}

function run(fn) {
  fn();
}

run(BadCode);
$ node hubba.test.js
/Users/simen/repos/jest/hubba.test.js:2
  throw new Error('noo');
  ^

Error: noo
    at BadCode (/Users/simen/repos/jest/hubba.test.js:2:9)
    at run (/Users/simen/repos/jest/hubba.test.js:6:3)
    at Object.<anonymous> (/Users/simen/repos/jest/hubba.test.js:9:1)
    at Module._compile (node:internal/modules/cjs/loader:1105:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1159:10)
    at Module.load (node:internal/modules/cjs/loader:981:32)
    at Function.Module._load (node:internal/modules/cjs/loader:822:12)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:77:12)
    at node:internal/main/run_main_module:17:47

$  deno run hubba.test.js
error: Uncaught Error: noo
  throw new Error('noo');
        ^
    at BadCode (file:///Users/simen/repos/jest/hubba.test.js:2:9)
    at run (file:///Users/simen/repos/jest/hubba.test.js:6:3)
    at file:///Users/simen/repos/jest/hubba.test.js:9:1

$  yarn jest hubba
 FAIL  ./hubba.test.js
  ● Test suite failed to run

    noo

      1 | function BadCode() {
    > 2 |   throw new Error('noo');
        |         ^
      3 | }
      4 |
      5 | function run(fn) {

      at fn (hubba.test.js:2:9)
      at run (hubba.test.js:6:3)
      at Object.<anonymous> (hubba.test.js:9:1)

Test Suites: 1 failed, 1 total
Tests:       0 total
Snapshots:   0 total
Time:        0.537 s
Ran all test suites matching /hubba/i.

If I run the same test on main

$ yarn jest hubba
 FAIL  ./hubba.test.js
  ● Test suite failed to run

    noo

      1 | function BadCode() {
    > 2 |   throw new Error('noo');
        |         ^
      3 | }
      4 |
      5 | function run(fn) {

      at BadCode (hubba.test.js:2:9)
      at fn (hubba.test.js:6:3)
      at Object.run (hubba.test.js:9:1)

Test Suites: 1 failed, 1 total
Tests:       0 total
Snapshots:   0 total
Time:        0.468 s
Ran all test suites matching /hubba/i.

Note that it's also correct if I disable code transformation (meaning no source map) or just remove the install call. Not sure if the issue is Babel's source maps (which is the transform we use in this repo) or in applying it.

@SimenB
Copy link
Member

SimenB commented May 2, 2022

Yeah, might be a bug in Babel actually. The code produced by babel-jest for hubba.test.js above:

"use strict";

function BadCode() {
  throw new Error('noo');
}

function run(fn) {
  fn();
}

run(BadCode);
//# sourceMappingURL=data:application/json;charset=utf-8;base64,eyJ2ZXJzaW9uIjozLCJuYW1lcyI6WyJCYWRDb2RlIiwiRXJyb3IiLCJydW4iLCJmbiJdLCJzb3VyY2VzIjpbImh1YmJhLnRlc3QuanMiXSwic291cmNlc0NvbnRlbnQiOlsiZnVuY3Rpb24gQmFkQ29kZSgpIHtcbiAgdGhyb3cgbmV3IEVycm9yKCdub28nKTtcbn1cblxuZnVuY3Rpb24gcnVuKGZuKSB7XG4gIGZuKCk7XG59XG5cbnJ1bihCYWRDb2RlKTtcbiJdLCJtYXBwaW5ncyI6Ijs7QUFBQSxTQUFTQSxPQUFULEdBQW1CO0VBQ2pCLE1BQU0sSUFBSUMsS0FBSixDQUFVLEtBQVYsQ0FBTjtBQUNEOztBQUVELFNBQVNDLEdBQVQsQ0FBYUMsRUFBYixFQUFpQjtFQUNmQSxFQUFFO0FBQ0g7O0FBRURELEdBQUcsQ0FBQ0YsT0FBRCxDQUFIIn0=

If I run that file with node

$ node -v
v16.15.0
$ node hubba2.js
/Users/simen/repos/jest/hubba2.js:4
  throw new Error('noo');
  ^

Error: noo
    at BadCode (/Users/simen/repos/jest/hubba2.js:4:9)
    at run (/Users/simen/repos/jest/hubba2.js:8:3)
    at Object.<anonymous> (/Users/simen/repos/jest/hubba2.js:11:1)
    at Module._compile (node:internal/modules/cjs/loader:1105:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1159:10)
    at Module.load (node:internal/modules/cjs/loader:981:32)
    at Function.Module._load (node:internal/modules/cjs/loader:822:12)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:77:12)
    at node:internal/main/run_main_module:17:47
$ node --enable-source-maps hubba2.js
/Users/simen/repos/jest/hubba.test.js:2
  throw new Error('noo');
        ^

Error: noo
    at fn (/Users/simen/repos/jest/hubba.test.js:2:9)
    at run (/Users/simen/repos/jest/hubba.test.js:6:3)
    at Object.<anonymous> (/Users/simen/repos/jest/hubba.test.js:9:1)
    at Module._compile (node:internal/modules/cjs/loader:1105:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1159:10)
    at Module.load (node:internal/modules/cjs/loader:981:32)
    at Function.Module._load (node:internal/modules/cjs/loader:822:12)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:77:12)
    at node:internal/main/run_main_module:17:47

The interesting part is the second one, running node with --enable-source-maps - you can see the stack is broken in the same way (should be at BadCode, is at fn). Not sure if this bug is in Node's implementation of source maps or in the one's coming out of Babel. Likely culprit is the latter as it's broken in newer source-map-support as well as @cspotcode/source-map-support?

@jridgewell would you be able to comment on this?

@cspotcode
Copy link
Contributor Author

cspotcode commented May 2, 2022

I noticed the package.json version declaration was 0.5.13 as opposed to ^0.5.13. Is one preferred, caret or not? Was going to change it to ^0.8.1

@SimenB
Copy link
Member

SimenB commented May 2, 2022

@cspotcode caret generally, it is locked due the the issue with names I commented about above 🙂

@SimenB
Copy link
Member

SimenB commented May 2, 2022

My hubba script btw has the correct trace in Chrome

image

So it might be a bug in the algorithm of source-map-support which both Node and @cspotcode/source-map-support has inherited

@SimenB
Copy link
Member

SimenB commented May 2, 2022

Hmm, the flag in node is supposed to come from chromium: nodejs/node#29564

EDIT: Sorry @cspotcode, it's unlikely this has anything to do with your PR, but I do think it's blocked by it

@cspotcode
Copy link
Contributor Author

What's the likely culprit? Does this still seem like a flaw in the sourcemaps coming from babel? Is jest currently relying on a bug in the old source-map-support implementation?

@cspotcode
Copy link
Contributor Author

If we keep the callsite fallback enabled by default, should we add an optional flag to disable that behavior? @SimenB will that work for jest?

@SimenB
Copy link
Member

SimenB commented May 5, 2022

That sounds very reasonable!

@cspotcode
Copy link
Contributor Author

I tried teaching source-map-support to map names at getEnclosingLineNumber and getEnclosingColumnNumber the way node does. This highlighted another problem with node's sourcemap implementation -- another place where we should be deviating from node. Thankfully, we're already there, because stable @cspotcode/source-map-support never attempts to map enclosing position.

In this example:

it('should fail', done => {
  throw new Error();
});

The first stack frame's getEnclosing*Number() gives us the location of the done identifier, because that is where the function declaration starts. If we attempt to source-map the name at that position, we erroneously believe that the function's name is done. It is not; that is the name of the first argument to the function.

This example is great, because it shows how bad it can be to attempt these imperfect sourcemap checks. In the examples we looked at several days ago, we were mapping to the name of a function at its callsite, not its declared name. Both names referred to the same function. So it was imperfect, but semantically it sorta made sense.

But today's example is much worst: we are mapping to the name of an entirely different function. This isn't merely imperfect, it's flat-out wrong and misleading. done refers to a different function with a different purpose.

The fix is: never attempt to map names at the "enclosing" position. The sourcemap spec, as it is today, can't do that.

@cspotcode
Copy link
Contributor Author

I've updated this pull request to use a pre-built tarball of cspotcode/node-source-map-support#41 because I don't want to publish to npm till it has passed all code reviews, and because trying to use a git dependency was failing some yarn integrity checks on CI.

Here is the diff of my changes against #9147
https://github.com/SimenB/jest/compare/bump-source-map-support..cspotcode:cspotcode-source-map-support

@SimenB
Copy link
Member

SimenB commented May 9, 2022

Thanks @cspotcode! I'm still unsure if this is safe to land due to the naming error - for better or worse the current stack traces seems more useful to me, even if the new stacks are more correct. "sourcemap doesn't support this" is an unsatisfying answer when the current behavior of Jest does not have the issue (although it has other issues).

Not sure what the best tradeoff here is... And regardless of the stack itself, the potential performance benefit of this migration is appealing, so that alone might be worth it (although I've not run any sort of benchmarks).

@cspotcode
Copy link
Contributor Author

Yeah, that's fair, though I still think jest needs to align with the JS language and find a way to convey that useful information with accurate stack traces.

When I talked about avoiding the enclosing position lookup, jest already does not do that. So you're not actually losing anything there.

These changes do not necessarily suppress helpful function names from appearing in stack traces. They merely move which stack frame they appear on.

For example:

function it(fn) {
  fn(); /*B*/
}
it(() => { /*C*/
  throw new Error() /*A*/
});

In this example, we'll still see it in the stack trace. But this bugfix corrects it to appear on the second stack frame instead of the third.

  at fn (line 5) /*A*/
  at it (line 2) /*B*/
  at <anonymous> (line 4) /*C*/

Another hypothetical example: when jest says at Object.strictEqual (__tests__/asset-metadata-tests.js:24:17) and when a developer knows it should say at verifyAssetMetadataTestMacro, there should be a stack trace above this one that says at strictEqual. The useful info is there in the stack, just on a different (correct) frame. Granted, I bet functions in tests are usually anonymous, they don't have descriptive names like this hypothetical.

@bcoe
Copy link
Contributor

bcoe commented Jun 5, 2022

showing the callsite name instead of the function name -- is arguably wrong. If we change @cspotcode/source-map-support to stop doing the wrong thing, we fix jest but diverge from node. Which I think is a good thing. But it would be nice to have a couple second opinions before I go down this route.

Node's implementation is largely my best guess at what would be a good user experience. If there's consensus in a large community like Jest, that the behavior in source-map-support is better, I think we'd be smart to align the built-in source map support in Node.js with source-map-support (tldr; perhaps you could make a patch proposing the same updates to Node's implementation?).

aside...

I'm also pretty convinced that trying to provide additional context , in the form of a snippet of source code, was a mistake in Node.js' --enable-source-map implementation. I'm pretty sure it's one of the causes of performance issues.

CC: @cspotcode

@cspotcode
Copy link
Contributor Author

For aggressively minified code, source-mapping the callsite name might be better, If the minifier mangled the name. But since minifiers usually don't mangle property names, that is not always true.

For un-minified code, the runtime name is likely to be best all the time. Even when the name is changed, it'll typically be something like foo becomes foo1 or _foo, something like that.

So that was my thinking: in the majority of cases, source-mapping callsite name is worse than using runtime name. For minified code it's a toss-up which is better; for unminified code, the runtime name is better.

And I was thinking specifically about the most likely use-cases. Where we want source-mapped stack traces: testing, debugging, server-side stuff. So minified code is not the norm.

In ts-node, the focus is unminified code, since it's TS->JS. I suspect that's usually the focus in jest as well.

@github-actions
Copy link

github-actions bot commented Sep 3, 2022

This PR is stale because it has been open 90 days with no activity. Remove stale label or comment or this will be closed in 30 days.

@github-actions github-actions bot added the Stale label Sep 3, 2022
@SimenB SimenB added Pinned and removed Stale labels Sep 5, 2022
@github-actions
Copy link

This PR is stale because it has been open 90 days with no activity. Remove stale label or comment or this will be closed in 30 days.

@github-actions github-actions bot added the Stale label Dec 23, 2022
@github-actions
Copy link

This PR was closed because it has been stalled for 30 days with no activity. Please open a new PR if the issue is still relevant, linking to this one.

@github-actions github-actions bot closed this Jan 22, 2023
@github-actions

This comment was marked as outdated.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Feb 22, 2023
@SimenB SimenB reopened this Sep 10, 2023
@SimenB SimenB removed the Stale label Sep 10, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants