[Bug]: `ReferenceError: Export 'emit' is not defined in module` from Jest internals during suite setup.

danfuzz commented 6 months ago

Version

29.7.0

Steps to reproduce

Clone https://github.com/danfuzz/lactoserv. Note: This is a server-side project, using Node.
Build and run tests, using this command which will run the two tests that seem to conspire to trigger the problem: ./scripts/ubik run-tests --do=build CertUtil RequestDelay

Expected behavior

Both tests pass.

Actual behavior

With some regularity — but not 100% consistently — the RequestDelay test file will fail to load, with Jest writing this to the console:

  ● Test suite failed to run

    ReferenceError: Export 'emit' is not defined in module

      at ../../tester/lib/node_modules/jest-runtime/build/index.js:1567:22
          at Array.forEach (<anonymous>)

Additional context

Hi! First and foremost, I'm sorry that I haven't been able to distill this to a tiny example. But I hope I can make up for that lack by providing a lot of information about what's going on:

It turns out that that message is being reported by _importCoreModule() here https://github.com/jestjs/jest/blob/559449e5a0a87210324720b56caa55b2e0ad3c94/packages/jest-runtime/src/index.ts#L1771. Specifically, it's the call to setExport(), which is on a vm.SyntheticModule (a Node core library class). The complaint amounts to this: When the module is constructed, the name emit was not included in the list of exports, but when the callback came to provide all the exports, the code in fact tried to setExport('emit', ...).

The call to _importCoreModule() is being passed node:process for the moduleName, and indeed the core Node process module does not directly define emit. However, it indirectly defines it by inheriting from EventEmitter. This isn't quite the crux of the problem, though it's related.

The set of pre-declared exports is based on a call to Object.keys() on the module being wrapped, and the calls to setExport() are based on a call to Object.entries() on the same object. These two methods behave identically with respect to inherited properties, skipping them. So, if the module being wrapped didn't change between the two calls, then everything would be okay.

But it turns out that between the call to Object.keys() and the call to Object.entries(), something is directly setting a new emit property directly on the process module, and that's the most-direct cause of the exception, because now Object.entries() is reporting a property that the earlier Object.keys() didn't see. Near as I can tell, the actual value which was set is a transpiled version of the process.emit() wrapper in source-map-support, but I haven't yet been able to catch the system in the act of setting it.

In the runs where the problem doesn't appear, I think process.emit gets set sometime after testing has started but simply (and fortuitously) not when a test is in the middle of loading/wrapping node:process specifically. The notable "feature" of the first test in the repro case (CertUtil) is that it runs pretty slowly, which I'm guessing is significant; it runs slowly but doesn't tend to fail. I'm not sure why the second one (RequestDelay) ends up being the consistent victim.

I figured out that I can work around the problem by explicitly setting required.emit = required.emit in _importCoreModule() when it's given node:process to import. However, I suspect that the right solution is to make sure that the patching of the real global process object happens before any test suites are even loaded.

I should add: The failure often — but not always — gets accompanied by a second ReferenceError:

ReferenceError: You are trying to `import` a file after the Jest environment has been torn down. From code/node_modules/@this/webapp-builtins/tests/RequestDelay.test.js.

Note that in this case the test suite in question never actually ran, and I believe that this additional error is happening because the main problem left the test suite in a bit of an inconsistent state.

I hope this helps!

PS: Before I filed this report, I tried asking on the suggested Discord server, but nobody responded.

Environment

System:
  OS: macOS 14.3.1
  CPU: (8) arm64 Apple M1
Binaries:
  Node: 22.1.0 - /opt/homebrew/bin/node
  Yarn: 1.22.22 - /opt/homebrew/bin/yarn
  npm: 10.7.0 - /opt/homebrew/bin/npm

danfuzz commented 6 months ago

Update: I can work around the problem a bit more cleanly by putting this:

process.emit = process.emit;

in a file added to setupFilesAfterEnv in the Jest config.

unprolix commented 6 months ago

boggle at that workaround.

SimenB commented 6 months ago

This smells like a missing await somewhere 🤔

That said, I've run the provided reproduction command 10 times in a row without seeing a failure 😅

SimenB commented 6 months ago

Would it help if we did the Object.keys and Object.entries at the same time at the top rather than doing the entries one lazily?

e.g.

const allExports = Object.entries(required);
const exportNames = allExports.map(([name]) => name);

const module = new SyntheticModule(
  ['default', ...exportNames],
  function () {
    // @ts-expect-error: TS doesn't know what `this` is
    this.setExport('default', required);
    for (const [key, value] of allExports) {
      // @ts-expect-error: TS doesn't know what `this` is
      this.setExport(key, value);
    }
  },
  // should identifier be `node://${moduleName}`?
  {context, identifier: moduleName},
);

that should at least make us internally consistent.

I have no idea where emit comes from tho - it's not part of node:process (https://nodejs.org/api/process.html), so something is seemingly messing with it from somewhere.

SimenB commented 6 months ago

Hmm, source-map-support does indeed add process.emit like you say: https://github.com/evanw/node-source-map-support/blob/7b5b81eb14c9ee6c6537398262bf7dab8580621c/source-map-support.js#L602-L612

Seems there's a flag we can pass to have it not do such weird things. We already do, tho: https://github.com/jestjs/jest/blob/559449e5a0a87210324720b56caa55b2e0ad3c94/packages/jest-runner/src/runTest.ts#L235

SimenB commented 6 months ago

@danfuzz how can I run jest in your repository without going via your script? I wanna try debugging, but the layers of bash scripts is a bit much for me 😅 I just want a node node_modules/.bin/jest CertUtil RequestDelay (maybe with a --config or something if that's something you use)

danfuzz commented 6 months ago

@SimenB Sorry! The repro instructions predated (by a couple hours) my checking in of the workaround. Give me a moment, and I'll try to put together a branch that still exhibits the problem.

danfuzz commented 6 months ago

@simenb Try this branch: https://github.com/danfuzz/lactoserv/tree/demo-jest-issue-15077

Note: If you're checking it out from a repo with a pre-existing build, do rm -rf out/tester first, because the build script isn't smart enough to notice that the test harness has changed (since it rarely does).

If the run-tests script is getting in the way of your flow, you can do a separate build and then call jest more directly:

$ ubik dev build
[... build build build ...]
$ rm -rf out/tester
$ ubik run-tests
[... let it build the tester then ...]
^C
$ out/tester/bin/jest --config=/...wherever/lactoserv/src/jest.config.mjs CertUtil RequestDelay
[...]
ReferenceError: You are trying to `import` a file after the Jest environment has been torn down. From code/node_modules/@this/webapp-builtins/tests/RequestDelay.test.js.

 FAIL  out/lactoserv/lib/code/node_modules/@this/webapp-builtins/tests/RequestDelay.test.js
  ● Test suite failed to run

    ReferenceError: Export 'emit' is not defined in module

      at ../../tester/lib/node_modules/jest-runtime/build/index.js:1554:16
          at Array.forEach (<anonymous>)

If you want, I can also package up a pre-built tree for you to inspect and use.

danfuzz commented 6 months ago

I have no idea where emit comes from tho - it's not part of node:process (https://nodejs.org/api/process.html), so something is seemingly messing with it from somewhere.

I tried to explain it above, but I guess I didn't do a good enough job:

Unlike most core modules, node:process has a nontrivial prototype. Instead of being (more or less) a plain object, it (indirectly) inherits from EventEmitter:

$ node
> process.emit
[Function: emit]
> Object.getPrototypeOf(process)
EventEmitter {}
> Object.hasOwn(process, 'emit')
false
> Object.hasOwn(Object.getPrototypeOf(process), 'emit')
false
> Object.hasOwn(Object.getPrototypeOf(Object.getPrototypeOf(process)), 'emit')
true

Object.keys() and Object.entries() only return the "own" properties of an object, and so process.emit doesn't show up for those… under normal circumstances.

However, Jest installs source-map-support, which does directly store a replacement / override for process.emit directly in the process object. When the error occurs, this installation happens after the Object.keys() in _importCoreModule() but before the Object.entries(). So, the former doesn't list emit, while the latter does. And boom!

My workaround works because I'm pre-emptively storing an "own" binding of emit on process before Jest tries to do much of anything. Eventually source-map-support does its thing and overwrites what the workaround did. The reason this isn't (in effect) a true fix is that it's still the case that source-map-support only manages to do its patching sometime after testing has started. So, if there's a test failure early enough with a test that uses code that came with a source map, the line numbers would be off in the error report.

danfuzz commented 6 months ago

Update: source-map-support in Jest is a red herring. I had looked at my own project dependencies to verify that I wasn't including it before, but I failed to notice that one of my dependencies — pem[*] — "secretly" bundles it into itself (which is why what I found was a transpiled version of it). That's arguably pretty bad behavior for what should be a little self-contained module (and I will aim to stop it from happening; its bad behavior affects my system when not under test).

But in any case, this makes it less clear to me to what extent y'all want to consider it a Jest problem:

It's still the case that modifying a Node core module in the middle of a test can mess the Jest runner up, and (as was suggested above) calling Object.entries() and using that one result to derive the keys to pass to SyntheticModule would avoid the particular blow-up.
But also, this is a case of surprising cross-test interference. If Jest is trying to guarantee that each test runs in a pristine global environment, there is something worth addressing here.

Thanks in advance and arrears for your help!

[*] And, in case it's not clear, CertUtil is the only class in my system which imports pem.

danfuzz commented 6 months ago

Update to the update: I'm not the first person to catch pem messing with Jest: https://github.com/Dexus/pem/issues/389

SimenB commented 6 months ago

Great you figured it out!

It's still the case that modifying a Node core module in the middle of a test can mess the Jest runner up, and (as was suggested above) calling Object.entries() and using that one result to derive the keys to pass to SyntheticModule would avoid the particular blow-up.

We can do that to at least avoid the weird disconnect

But also, this is a case of surprising cross-test interference. If Jest is trying to guarantee that each test runs in a pristine global environment, there is something worth addressing here.

Node aren't interested in making that possible, unfortunately: https://github.com/nodejs/node/issues/31852

Update to the update: I'm not the first person to catch pem messing with Jest: Dexus/pem#389

I'd say libraries should never use support-source-maps - it's an application or runtime thing to ensure source maps are loaded if that's something they care about.

SimenB commented 6 months ago

If anybody comes to this issue for the "good first issue" label - this is what we want: https://github.com/jestjs/jest/issues/15077#issuecomment-2122676289

Code is in https://github.com/jestjs/jest/blob/559449e5a0a87210324720b56caa55b2e0ad3c94/packages/jest-runtime/src/index.ts#L1774-L1786

danfuzz commented 6 months ago

Node aren't interested in making that possible, unfortunately: nodejs/node#31852

That's unfortunate :( .

github-actions[bot] commented 5 months ago

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

jestjs / jest