Using custom loaders results in a load loop / OOM #47566

merceyz · 2023-04-14T21:59:12Z

Version

v20.0.0-nightly20230414c94be4125b

Platform

Linux server 5.15.0-69-generic #76-Ubuntu SMP Fri Mar 17 17:19:29 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Subsystem

No response

What steps will reproduce the bug?

touch loader.js
echo "setInterval(() => {}, 1000);" > test.cjs
node --loader ./loader.js test.cjs

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

No response

What is the expected behavior? Why is that the expected behavior?

Node.js starts up without loading the provided loader over and over again.

What do you see instead?

Node.js spams the console with the following warning while the memory and CPU usage climbs until it's stopped / OOMs.

(node:5652) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use `node --trace-warnings ...` to show where the warning was created)

Additional information

Possibly relevant #44710

The text was updated successfully, but these errors were encountered:

aduh95 · 2023-04-15T13:55:29Z

@nodejs/loaders

aduh95 · 2023-04-17T13:59:12Z

I'm able to reproduce with the suggested code snippet, but it looks like there's more to it than just combining --require and --loader, here's what I get when running the following at the root of the node repo:

$ out/Release/node --no-warnings --require ./test/fixtures/printA.js --import ./test/fixtures/printB.js --loader ./test/fixtures/empty.js ./test/fixtures/printC.js
A
A
B
C

It looks like the reported bug only happens on REPL. Worth noting that we also another bug that makes the --required script run twice instead of once.

merceyz · 2023-04-17T14:07:22Z

It looks like the reported bug only happens on REPL

I can also reproduce the issue without the REPL:

touch require.cjs
touch loader.mjs
echo "setInterval(() => {}, 1000);" > test.cjs
node --require ./require.cjs --loader ./loader.mjs test.cjs

aduh95 · 2023-04-17T14:08:30Z

I don't think it has much to do with --require:

$ out/Release/node --loader ./test/fixtures/empty.js
[…never ending output of experimental warning…]

merceyz · 2023-04-17T14:13:20Z

Indeed, I've updated the issue to reflect that 👍

Worth noting that we also another bug that makes the --required script run twice instead of once

That's expected behaviour in my opinion, once in the main process and once in the Worker for the loaders.

JakobJingleheimer · 2023-04-17T18:10:16Z

I can't repro at all (admittedly on macOS ARM, but I don't see how this could be OS-related):

At main's current HEAD (e050cec), the OP's

snippet

touch loader.mjs
echo "setInterval(() => {}, 1000);" > test.cjs
node --loader ./loader.mjs test.cjs

runs endlessly (as expected) and memory stays constant (at 20.2 MB, after start-up), with only 1 experimental warning.

I get the same behaviour on v20.0.0-proposal's current HEAD (bb533f7), but with slightly less memory consumption (20.1 MB after start-up).

The code that controls whether the warning is emitted is quite simple and handles multiple instances of the module loader:

node/lib/internal/modules/esm/loader.js

Lines 405 to 420 in b342a1b

    
           let emittedExperimentalWarning = false; 
        
           /** 
        
            * A loader instance is used as the main entry point for loading ES modules. Currently, this is a singleton; there is 
        
            * only one used for loading the main module and everything in its dependency graph, though separate instances of this 
        
            * class might be instantiated as part of bootstrap for other purposes. 
        
            * @param {boolean} useCustomLoadersIfPresent If the user has provided loaders via the --loader flag, use them. 
        
            * @returns {DefaultModuleLoader | CustomizedModuleLoader} 
        
            */ 
        
           function createModuleLoader(useCustomLoadersIfPresent = true) { 
        
             if (useCustomLoadersIfPresent) { 
        
               const userLoaderPaths = getOptionValue('--experimental-loader'); 
        
               if (userLoaderPaths.length > 0) { 
        
                 if (!emittedExperimentalWarning) { 
        
                   emitExperimentalWarning('Custom ESM Loaders'); 
        
                   emittedExperimentalWarning = true; 
        
                 }

(emittedExperimentalWarning lives at the top level of esm/loader.js)

Am I missing something?

aduh95 · 2023-04-17T18:33:07Z

I think this is happening because the loader is going to try to spawn a worker thread from within the worker thread, which is also going to do the same thing, and that's how we end up with Mr Meeseeks situation until the system is out of memory or the process terminates. I'm working on a fix.

bmeck · 2023-04-17T19:50:30Z

I'd note that some systems like ServiceWorkers / SharedWorkers avoid this by having a shared cache based upon URL of the entrypoint. That would also reduce overall burden.

…

On Mon, Apr 17, 2023 at 1:33 PM Antoine du Hamel ***@***.***> wrote: I think this is happening because the loader is going to try to spawn a worker thread from within the worker thread, which is also going to do the same thing, and that's how we end up with Mr Meeseeks situation until the system is out of memory or the process terminates. I'm working on a fix. — Reply to this email directly, view it on GitHub <#47566 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AABZJI4ZGXW3P53XYIGMCPDXBWEHBANCNFSM6AAAAAAW66HUD4> . You are receiving this because you are on a team that was mentioned.Message ID: ***@***.***>

kirrg001 · 2023-04-19T08:17:41Z

Experiencing the same. The loader is loaded over and over again as soon as I import specific libraries.

node --experimental-loader ./esm-loader.mjs index.mjs

esm-loader.mjs

// works
import { get } from 'node:https';

// both do not work and restart the loader in a loop
import CoffeeScript from 'coffeescript';
import mysql from 'mysql';

(node:9286) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use node --trace-warnings ... to show where the warning was created)
(node:9286) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use node --trace-warnings ... to show where the warning was created)
(node:9286) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use node --trace-warnings ... to show where the warning was created)
(node:9286) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use node --trace-warnings ... to show where the warning was created)

Works fine with Node v18

merceyz · 2023-04-19T09:55:30Z

Indeed, I've updated the issue to reflect that 👍
#47566 (comment)

@aduh95 I tested again and the --require flag is required to reproduce, I've updated the reproduction again.
Seems I forgot that the terminal in VSCode adds NODE_OPTIONS with a --require flag for it's auto attach feature.

jacobq · 2023-04-19T21:30:07Z

Indeed, I've updated the issue to reflect that +1
#47566 (comment)

@aduh95 I tested again and the --require flag is required to reproduce, I've updated the reproduction again. Seems I forgot that the terminal in VSCode adds NODE_OPTIONS with a --require flag for it's auto attach feature.

How so? I am seeing the following in v20.0.0 (release) on x86_64 GNU/Linux, running from CLI and NODE_OPTIONS is not set, using blank/empty loader and script that just waits indefinitely so the process doesn't exit immediately:

$ touch empty.cjs # (does it / should it matter if we use .js .cjs or .mjs here??)
$ echo "setInterval(() => null, 1000);" > wait.js
$ node --loader ./empty.cjs wait.js
(node:668264) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
(node:668264) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
(node:668264) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
(node:668264) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
(node:668264) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
....

Passing --trace-warnings just add stack traces to each message:

(node:668371) ExperimentalWarning: Custom ESM Loaders is an experimental feature and might change at any time
    at emitExperimentalWarning (node:internal/util:273:11)
    at createModuleLoader (node:internal/modules/esm/loader:418:9)
    at loadESM (node:internal/process/esm_loader:18:19)
    at runMainESM (node:internal/modules/run_main:53:21)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:79:5)
    at node:internal/main/run_main_module:23:47
...

I mean....I guess the message did say that the feature could change at any time, but I am sure that this kind of change was not on purpose :)

aduh95 · 2023-04-19T21:35:25Z

FWIW I'm also able to reproduce without --require. We already have a fix ready FYI.

merceyz · 2023-04-19T22:21:17Z

How so?

@jacobq Interestingly it depends on the extensions used.

# OK
node --loader ./loader.mjs
# KO
node --loader ./loader.cjs
node --loader ./loader.js
node --require ./require.cjs --loader ./loader.mjs

JakobJingleheimer · 2023-04-20T19:22:52Z

How so?

@jacobq Interestingly it depends on the extensions used.

# OK
node --loader ./loader.mjs
# KO
node --loader ./loader.cjs
node --loader ./loader.js
node --require ./require.cjs --loader ./loader.mjs

The reason is it must invoke the CJS module loader to repro (the default is CJS, so node --loader ./loader.js will default to CJS when nothing tells it otherwise, and the other 2 are explicitly CJS).

Use the default loader as the cascaded loader in the loader worker. Otherwise we spawn loader workers in the loader workers indefinitely. PR-URL: #47620 Fixes: #47566 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com> Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Jacob Smith <jacob@frende.me> Reviewed-By: Geoffrey Booth <webadmin@geoffreybooth.com> Reviewed-By: Michaël Zasso <targos@protonmail.com>

joacub · 2023-04-25T19:28:35Z

FWIW I'm also able to reproduce without --require. We already have a fix ready FYI.

when is this fix will be released ?, we are experiencing the same and we want to go over node 20 to have the improvements in cold imports that I already saw.

thanks

checkrcarter · 2023-04-26T00:43:09Z

Ditto here! Also curious when this will be released.

GeoffreyBooth · 2023-04-26T01:23:04Z

Ditto here! Also curious when this will be released.

With 20.1.0 on 2023-05-02 per nodejs/Release#855, or in a patch release if one is done before then.

Use the default loader as the cascaded loader in the loader worker. Otherwise we spawn loader workers in the loader workers indefinitely. PR-URL: #47620 Fixes: #47566 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com> Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Jacob Smith <jacob@frende.me> Reviewed-By: Geoffrey Booth <webadmin@geoffreybooth.com> Reviewed-By: Michaël Zasso <targos@protonmail.com>

TomasHubelbauer · 2023-05-04T07:27:07Z

FYI 20.1.0 is out and the PR for this issue, #47620, is included in it.

aheissenberger · 2023-05-05T06:39:02Z

I tested with node 20.1.0 and the problem still exists without any changes:
cyco130/vavite#39 (comment)

TomasHubelbauer · 2023-05-05T11:38:12Z

Just in case this is useful to anyone - in my case it actually did fix the issue… But it also revealed another one which I think is related: #47880.

kirrg001 · 2023-05-08T11:50:49Z

Thank you. 20.1.0 fixed the issue for us.

Use the default loader as the cascaded loader in the loader worker. Otherwise we spawn loader workers in the loader workers indefinitely. PR-URL: nodejs#47620 Fixes: nodejs#47566 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com> Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Jacob Smith <jacob@frende.me> Reviewed-By: Geoffrey Booth <webadmin@geoffreybooth.com> Reviewed-By: Michaël Zasso <targos@protonmail.com>

Use the default loader as the cascaded loader in the loader worker. Otherwise we spawn loader workers in the loader workers indefinitely. PR-URL: #47620 Backport-PR-URL: #50669 Fixes: #47566 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com> Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Jacob Smith <jacob@frende.me> Reviewed-By: Geoffrey Booth <webadmin@geoffreybooth.com> Reviewed-By: Michaël Zasso <targos@protonmail.com>

Use the default loader as the cascaded loader in the loader worker. Otherwise we spawn loader workers in the loader workers indefinitely. PR-URL: nodejs/node#47620 Backport-PR-URL: nodejs/node#50669 Fixes: nodejs/node#47566 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com> Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Jacob Smith <jacob@frende.me> Reviewed-By: Geoffrey Booth <webadmin@geoffreybooth.com> Reviewed-By: Michaël Zasso <targos@protonmail.com>

merceyz changed the title ~~Combining --require and --loader results in a load loop~~ Combining --require and --loader results in a load loop / OOM Apr 14, 2023

merceyz mentioned this issue Apr 15, 2023

Flaky es-module/test-esm-loader-side-effect (and other ESM loader tests) #47571

Closed

VoltrexKeyva added the loaders Issues and PRs related to ES module loaders label Apr 15, 2023

aduh95 added the repl Issues and PRs related to the REPL subsystem. label Apr 17, 2023

merceyz changed the title ~~Combining --require and --loader results in a load loop / OOM~~ Using custom loaders results in a load loop / OOM Apr 17, 2023

aduh95 removed the repl Issues and PRs related to the REPL subsystem. label Apr 17, 2023

aduh95 mentioned this issue Apr 17, 2023

esm: do not lazy instantiate loaders to avoid infinite loop #47599

Closed

aduh95 added the confirmed-bug Issues with confirmed bugs. label Apr 17, 2023

merceyz mentioned this issue Apr 19, 2023

Endlessly spawning loaders in node 20.0.0 leading to large memory leak TypeStrong/ts-node#1995

Closed

merceyz changed the title ~~Using custom loaders results in a load loop / OOM~~ Combining --require and --loader results in a load loop / OOM Apr 19, 2023

aduh95 mentioned this issue Apr 19, 2023

Error when: node v20, --test --loader, await import #47614

Closed

joyeecheung mentioned this issue Apr 19, 2023

loader: use default loader as cascaded loader in the in loader worker #47620

Merged

merceyz changed the title ~~Combining --require and --loader results in a load loop / OOM~~ Using custom loaders results in a load loop / OOM Apr 19, 2023

jacobq mentioned this issue Apr 20, 2023

Loaders that use childProcess.fork lead to endless recursion of processes #47615

Open

giltayar mentioned this issue Apr 21, 2023

The simplest loader results in an infinite loop of module loading #47655

Closed

nodejs-github-bot closed this as completed in #47620 Apr 21, 2023

arcanis mentioned this issue Apr 21, 2023

Running Jest with yarn pnp enabled and node v20 leaks memory yarnpkg/berry#5399

Closed

1 task

merceyz mentioned this issue Apr 24, 2023

On intel Mac node endless starts new threads and consumes more and more memory until killed. #47697

Closed

gtm-nayan mentioned this issue Apr 26, 2023

[BUG] Node 20: Test timeouts do not exit gracefully microsoft/playwright#22641

Closed

1 task

merceyz mentioned this issue Apr 28, 2023

v20.0.0 Unlimited increase in memory #47761

Closed

LangLangBart mentioned this issue Apr 28, 2023

Memory leak on Node v20 privatenumber/tsx#229

Closed

1 task

privatenumber mentioned this issue May 2, 2023

tsx doesn't stop spawning threads with node 20 privatenumber/tsx#232

Closed

1 task

hongaar mentioned this issue May 2, 2023

feat: update node.js versions hongaar/moker#166

Merged

cyco130 mentioned this issue May 2, 2023

--use-loader fails with NodeJS 20.0.0 cyco130/vavite#39

Open

TomasHubelbauer mentioned this issue May 3, 2023

Release plan - v20.x Maintenance LTS nodejs/Release#855

Open

merceyz mentioned this issue May 3, 2023

ci: run tests on Node.js v20 yarnpkg/berry#5422

Closed

3 tasks

leeoniya mentioned this issue May 6, 2023

JavaScript heap out of memory using tsx with node v20.0.0 privatenumber/tsx#238

Closed

1 task

merceyz mentioned this issue May 9, 2023

“Unexpected early exit” when building with Node 20 and Yarn PnP vitejs/vite#13106

Closed

7 tasks

joyeecheung mentioned this issue Mar 26, 2024

Proposal for a simple, universal module loader hooks API to replace require() monkey-patching #52219

Closed

WSINTRA mentioned this issue Apr 25, 2024

nx and yarn pnp memory leak nrwl/nx#23015

Closed

4 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Using custom loaders results in a load loop / OOM #47566

Using custom loaders results in a load loop / OOM #47566

merceyz commented Apr 14, 2023 •

edited

Loading

aduh95 commented Apr 15, 2023

aduh95 commented Apr 17, 2023 •

edited

Loading

merceyz commented Apr 17, 2023

aduh95 commented Apr 17, 2023

merceyz commented Apr 17, 2023 •

edited

Loading

JakobJingleheimer commented Apr 17, 2023

aduh95 commented Apr 17, 2023

bmeck commented Apr 17, 2023 via email

kirrg001 commented Apr 19, 2023

merceyz commented Apr 19, 2023 •

edited

Loading

jacobq commented Apr 19, 2023 •

edited

Loading

aduh95 commented Apr 19, 2023

merceyz commented Apr 19, 2023 •

edited

Loading

JakobJingleheimer commented Apr 20, 2023 •

edited

Loading

joacub commented Apr 25, 2023

checkrcarter commented Apr 26, 2023

GeoffreyBooth commented Apr 26, 2023

TomasHubelbauer commented May 4, 2023

aheissenberger commented May 5, 2023

TomasHubelbauer commented May 5, 2023

kirrg001 commented May 8, 2023

Using custom loaders results in a load loop / OOM #47566

Using custom loaders results in a load loop / OOM #47566

Comments

merceyz commented Apr 14, 2023 • edited Loading

Version

Platform

Subsystem

What steps will reproduce the bug?

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

What is the expected behavior? Why is that the expected behavior?

What do you see instead?

Additional information

aduh95 commented Apr 15, 2023

aduh95 commented Apr 17, 2023 • edited Loading

merceyz commented Apr 17, 2023

aduh95 commented Apr 17, 2023

merceyz commented Apr 17, 2023 • edited Loading

JakobJingleheimer commented Apr 17, 2023

aduh95 commented Apr 17, 2023

bmeck commented Apr 17, 2023 via email

kirrg001 commented Apr 19, 2023

merceyz commented Apr 19, 2023 • edited Loading

jacobq commented Apr 19, 2023 • edited Loading

aduh95 commented Apr 19, 2023

merceyz commented Apr 19, 2023 • edited Loading

JakobJingleheimer commented Apr 20, 2023 • edited Loading

joacub commented Apr 25, 2023

checkrcarter commented Apr 26, 2023

GeoffreyBooth commented Apr 26, 2023

TomasHubelbauer commented May 4, 2023

aheissenberger commented May 5, 2023

TomasHubelbauer commented May 5, 2023

kirrg001 commented May 8, 2023

merceyz commented Apr 14, 2023 •

edited

Loading

aduh95 commented Apr 17, 2023 •

edited

Loading

merceyz commented Apr 17, 2023 •

edited

Loading

merceyz commented Apr 19, 2023 •

edited

Loading

jacobq commented Apr 19, 2023 •

edited

Loading

merceyz commented Apr 19, 2023 •

edited

Loading

JakobJingleheimer commented Apr 20, 2023 •

edited

Loading