segfault when running jest tests in fastify with esm mode

[dlemperFuchs]

Version

v16.15.0

Platform

Linux main-deb 5.10.0-0.bpo.11-amd64 #1 SMP Debian 5.10.92-1~bpo10+1 (2022-02-03) x86_64 GNU/Linux

Subsystem

No response

What steps will reproduce the bug?

git clone https://github.com/dlemperFuchs/fastify-jest-esm-segfault
cd fastify-jest-esm-segfault
npm install
NODE_OPTIONS=--experimental-vm-modules npx jest

How often does it reproduce? Is there a required condition?

reproducible every time

What is the expected behavior?

Jest runs tests in the repo

What do you see instead?

(node:249708) ExperimentalWarning: VM Modules is an experimental feature. This feature could change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
(node:249708) [FST_MODULE_DEP_FASTIFY-AUTOLOAD] FastifyWarning.fastify-autoload: fastify-autoload has been deprecated. Use @fastify/autoload@4.0.0 instead.

 RUNS  test/routes/root.test.js
PID 249708 received SIGSEGV for address: 0x10
/home/dlemper/Dokumente/src/fsttest/node_modules/segfault-handler/build/Release/segfault-handler.node(+0x2e37)[0x7fe9d5a75e37]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7fe9d572b730]
node[0xa19eba]
node(_ZN2v88internal7Isolate38RunHostImportModuleDynamicallyCallbackENS0_6HandleINS0_6ScriptEEENS2_INS0_6ObjectEEENS0_11MaybeHandleIS5_EE+0xad)[0xe42d1d]
node(_ZN2v88internal25Runtime_DynamicImportCallEiPmPNS0_7IsolateE+0xba)[0x1203d8a]
node[0x15f2254]
Segmentation fault

Additional information

Sorry, I'm quite unsure if this is a node problem or a jest or fastify problem. I tried several things within about 40 hours but nothing worked and in my opinion a segfault shouldn't happen while JS code gets executed.

[tniessen]

I can repro. I don't know if any of your dependencies make use of native addons. If they don't, then this is most likely a bug in node or one of its dependencies (e.g., V8).

[tniessen]

cc @nodejs/vm

[dlemperFuchs]

Thank you for looking into it!
I just removed and reinstalled all node_modules and I got no message about building native addons. Then I grepped for node-gyp in the whole repo: it's only used in segfault-handler, which I installed to get a better traceback of the segfault (and segfault also appears without segfault-handler).

[bnoordhuis]

@dlemperFuchs What does find node_modules -name \*.node print?

[dlemperFuchs]

@bnoordhuis

$ find node_modules -name \*.node
node_modules/segfault-handler/build/Release/obj.target/segfault-handler.node
node_modules/segfault-handler/build/Release/segfault-handler.node

I have the same problem, but with testing.

If I run npm run test for the first time, it works:

stanley in ~/dev/app-api on main λ npm run test                                

> stix-fastify@1.0.0 test
> node --experimental-vm-modules node_modules/jest/bin/jest.js test/

(node:8929) ExperimentalWarning: VM Modules is an experimental feature. This feature could change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
 PASS  test/routes/root.test.ts
  ✓ default root route (111 ms)

Test Suites: 1 passed, 1 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        3.334 s
Ran all test suites matching /test\//i.

But after a second attempt, it fails:

stanley in ~/dev/app-api on main λ npm run test

> stix-fastify@1.0.0 test
> node --experimental-vm-modules node_modules/jest/bin/jest.js test/

(node:8967) ExperimentalWarning: VM Modules is an experimental feature. This feature could change at any time
(Use `node --trace-warnings ...` to show where the warning was created)

 RUNS  test/routes/root.test.ts
[1]    8956 segmentation fault (core dumped)  npm run test

---

find node_modules -name \*.node yields nothing.

[xbc5]

PID 201777 received SIGSEGV for address: 0x10
/home/xbc5/projects/foo/node_modules/.pnpm/segfault-handler@1.3.0/node_modules/segfault-handler/build/Release/segfault-handler.node(+0x31d6)[0x7852db1311d6]
/lib64/libc.so.6(+0x55350)[0x7852d79d1350]
/lib64/libnode.so.93(+0xcbaf65)[0x7852d883ef65]
/lib64/libnode.so.93(_ZN2v88internal7Isolate38RunHostImportModuleDynamicallyCallbackENS0_6HandleINS0_6ScriptEEENS2_INS0_6ObjectEEENS0_11MaybeHandleIS5_EE+0xb5)[0x7852d8fb5565]
/lib64/libnode.so.93(_ZN2v88internal25Runtime_DynamicImportCallEiPmPNS0_7IsolateE+0xdd)[0x7852d93233cd]
/lib64/libnode.so.93(+0xf86c54)[0x7852d8b0ac54]

I'm getting a very similar stack trace for Node v16.14.0 + v14, and Jest v27.5.1. I would make it cleaner if I knew how -- I think I am missing some debug symbols. If someone can help?

I get this error intermittently: but it's generally when loading https://github.com/seriousme/fastify-openapi-glue -- which uses ESM. But it's ALWAYS when using Jest. This library loads fine when I run the server outside of tests.

Also, there's no find ./node_module -name '*.node' files.

[xbc5]

I am doing some further testing:

Test order matters. Could it be a race condition?

When running unit tests (no ESM) first and service tests (ESM) after in the same session, no crashes occur.

1. doing service tests alone causes crashes: ~20 tests; 50% crash;
2. doing unit tests does not cause crashes: ~20 test; 100% pass;
3. doing unit test + service tests in that order does not cause crashes: ~20 tests; 100% pass;
4. unit tests do not use ESM; service tests do;
5. test order is a) unit b) service;

[xbc5]

Fixed the issue by properly loading ESM, and everything that entails in doing so.

Simply put: I wasn't handling ESM at all. I was simply using a normal import in TypeScript, which transpiles to a CJS require.

I changed my project to handle ESM, and used top-level await on a dynamic import().

This is still obviously a bug because Node should properly handle this and error.

That maybe gives some insight into the problem.

[dlemperFuchs]

@xbc5 you fixed it by simply using a dynamic import instead of a "normal" import? Would you mind having a look at my repo and tell me, what I can change to get it working? I tried several changes of the imports and didn't get it working.

As I already invested many hours, my company wants me to switch to a working solution (node-tap in this case), so this bug will not affect me any longer.