node icon indicating copy to clipboard operation
node copied to clipboard

Indirectly static import cjs with error will cause an uncaughtException

Open LongTengDao opened this issue 5 months ago • 14 comments

Version

v20.10.0

Platform

No response

Subsystem

No response

What steps will reproduce the bug?

// ./main.mjs
process.on('uncaughtException', ()=>console.log('uncaught'));
try {
    await import(`data:text/javascript,
        import "data:text/javascript,console.log('before')";
        import "${import.meta.url}.cjs";
    `);
}
catch { console.log('caught'); }
// ./main.mjs.cjs
throw Error('abc');

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

every time

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

before
caught

same with dynamic await import('./main.mjs.cjs') directly or indirectly.

also intuitive.

What do you see instead?

before
uncaught

and the wrapper dynamic import promise will be forever pending

Additional information

No response

LongTengDao avatar Jan 30 '24 03:01 LongTengDao

For the sake of completeness, if the error is thrown from an ES module, the error is caught

process.on('uncaughtException', ()=>console.log('uncaught'));
try {
    await import(`data:text/javascript,
        import "data:text/javascript,console.log('before')";
        import "data:text/javascript,throw new Error";
    `);
} catch {
  console.log('caught');
}
before
caught

/cc @nodejs/loaders

aduh95 avatar Jan 30 '24 09:01 aduh95

I wasn't able to reproduce the issue. Weirdly, I got both caught and uncaught. https://github.com/duncanchiu409/node-issue-51603

duncanchiu409 avatar Jan 30 '24 23:01 duncanchiu409

I have tried this on the following platforms: Ubuntu 22.04 with node.js 21.6.1 Ubuntu 22.04 with node.js 20.10.0 Ubuntu 22.04 with node.js 18.19 Ubuntu 20.04 with node.js 16.19 Windows 11 with node.js 21.6.1 Windows 10 with node.js 21.6.1

And I get the same result as @duncanchiu409 , getting both caught and uncaught.

My question to @LongTengDao is, could you please provide more information about how you got the bug to appear? e.g. platform, flags such as experimental-modules, etc.

Also, I have done some messing around and discovered the following: It doesn't seem to matter so much that it is an dynamic path, as the below code produces the same result as above, console logging both caught and uncaught.

process.on('uncaughtException', ()=>console.log('uncaught'));
try {
    await import(`data:text/javascript,
        import "data:text/javascript,console.log('before')";
        import "file:///home/john/Documents/github/issue51603/main.mjs.cjs";
    `);
}
catch(error) { console.log('caught'); }

Thanks.

JohnCampbellroyceayr avatar Jan 31 '24 02:01 JohnCampbellroyceayr

FWIW I'm also seeing the same thing as you all (before\ncaught\nuncaught), but I think that's precisely the bug that is being reported (i.e. that throwing an error in CJS is treated different than in ESM). It seems to me you both are able to reproduce the issue.

aduh95 avatar Jan 31 '24 08:01 aduh95

Ok, thank you for the clarification @aduh95, I would like to tackle this issue, I just have a couple questions/ideas:

  1. Is anyone already working on this issue?

  2. The error seems to be the various functions in /lib/internal/modules/cjs/loader, based on the error logs:

throw Error('abc');
      ^

Error: abc
    at Object.<anonymous> (/home/john/Documents/github/issue51603/main.mjs.cjs:1:7)
    at Module._compile (node:internal/modules/cjs/loader:1378:14)
    at Module._extensions..js (node:internal/modules/cjs/loader:1437:10)
    at Module.load (node:internal/modules/cjs/loader:1212:32)
    at Module._load (node:internal/modules/cjs/loader:1028:12)
    at cjsLoader (node:internal/modules/esm/translators:359:17)
    at ModuleWrap.<anonymous> (node:internal/modules/esm/translators:308:7)
    at ModuleJob.run (node:internal/modules/esm/module_job:218:25)
    at async ModuleLoader.import (node:internal/modules/esm/loader:323:24)
    at async file:///home/john/Documents/github/issue51603/main.mjs:3:5

My current plan is to compare it to how the module (/lib/internal/modules/esm/loader.js) correctly handles the import / error handling, and make the necessary changes.

  1. since I don't know the codebase as well as some of you might (given this is my first time attempting to solve an issue in node.js) I would be happy to hear any critiques/suggestions/ideas.

JohnCampbellroyceayr avatar Feb 01 '24 02:02 JohnCampbellroyceayr

  1. Probably not; go for it.

2-3. I would actually start at esm/translators.js. That’s the file that’s common to both flows, though the CommonJS flow uses the CommonJS “translator” function in there whereas the ESM flow uses the module one. Maybe there’s something different between the two translator functions that explains it (like differing uses of try/catch). If you don’t see anything here then sure, go down into the cjs/ files; but be warned that we almost never touch those files anymore, as the CommonJS module loader is essentially frozen.

GeoffreyBooth avatar Feb 01 '24 04:02 GeoffreyBooth

don't know why, now I get before+caught+uncaught. maybe I was too sleepy.

in my just test, I found the uncaughtException came from unhandledRejection event, if any helps.

LongTengDao avatar Feb 01 '24 18:02 LongTengDao

the problem seems just because the outest stack is not catched. the inside caller stacks seems normal and correct, like any normal thrown commonjs module evaluating.

the problem even maybe in the cpp side, any way, I can't trace it's root stack for useful information.

in my test, if the entry file named *.cjs, here would be one more caller stack, hopes helpful.

LongTengDao avatar Feb 01 '24 18:02 LongTengDao

For the sake of completeness, if the error is thrown from an ES module, the error is caught

process.on('uncaughtException', ()=>console.log('uncaught'));
try {
    await import(`data:text/javascript,
        import "data:text/javascript,console.log('before')";
        import "data:text/javascript,throw new Error";
    `);
} catch {
  console.log('caught');
}
before
caught

/cc @nodejs/loaders

also, dynamic import won't make uncaught too:

// main.cjs
(async function(){
    Error.stackTraceLimit=20;
    process.on('unhandledRejection', (error)=>console.log('uncaught',error.stack));
    try {
        await import(`data:text/javascript,
            import "data:text/javascript,console.log('before')";
            await import("${import.meta.url}.cjs");// <- here different
        `);
    }
    catch { console.log('caught'); }
})();

LongTengDao avatar Feb 01 '24 18:02 LongTengDao

I have done some further probing on the error an here is what I have found: The following code will produce the original error, before and then uncaught without caught :

process.on('uncaughtException', () => console.log("uncaught"));
try {
    await import(`data:text/javascript,
        import "data:text/javascript,console.log('before')";
        import("${import.meta.url}.cjs");
    `);
}
catch { console.log('caught'); }

I have followed the flow from the start of the file until something appears different between the above code that produces before-uncaught and @LongTengDao's example with await import("${import.meta.url}.cjs"); that produces the correct result, before-caught.

Where the flows start to differ is in the async run() function in the ModuleJob class in the /lib/modules/esm/module_job.js file. The function runs:

  1. for the initial (main.mjs),
  2. for the entire import string: "data:text/javascript, import "data:text/javascript,console.log('before')"; import("file:///home/john/Documents/github/issue51603/main.mjs.cjs");" ('before' is then logged to the console)

Here are where things start to differ:

In the before-caught version, the async run() function is called again, only for the file main.mjs.cjs, which throws the error abc, which is correct.

In the before-uncaught version, the async run() function continues for the import string: "data:text/javascript, import "data:text/javascript,console.log('before')"; import("file:///home/john/Documents/github/issue51603/main.mjs.cjs");" and returns the module without any errors.

THEN it calls the async run() function again, this time for the main.mjs.cjs file. Here is a part I don't 100% understand: It returns no errors, and I am pretty sure that this is because the module.modulePromise = Promise{<pending>} It then calls the run function again for the main.mjs.cjs file, only this time when the module.modulePromise is fulfilled? And this time it does throw the error abc. I am just not sure why it is calling it twice.

My question is, now that I have provided more light on the problem, does that give anyone a better idea as to where the problem is? Being a newbie at debugging node.js, it took me a little while to find this, so I would appreciate any ideas that will help me further investigate the problem :)

JohnCampbellroyceayr avatar Feb 04 '24 04:02 JohnCampbellroyceayr

@JohnCampbellroyceayr thats the expected behavior, if you don’t await a dynamic import, you won’t catch the error, that’s what the ECMAScript spec requires.

aduh95 avatar Feb 04 '24 08:02 aduh95

I also test --experimental-vm-modules just now, here are interesting things:

import vm from 'node:vm';

process.on('unhandledRejection', () => console.log('unhandledRejection'));

try {
	const mjs = new vm.SourceTextModule(`import's'`);
	await mjs.link(async function myLinker () {
		const cjs = new vm.SyntheticModule([], function myCB () {
			throw Error();
		});
		await cjs.link(() => {});
		//await cjs.evaluate();
		return cjs;
	});
	await mjs.evaluate();
} catch { console.log('caught'); }
caught
unhandledRejection
import vm from 'node:vm';

process.on('unhandledRejection', () => console.log('unhandledRejection'));

try {
	const mjs = new vm.SourceTextModule(`import's'`);
	await mjs.link(async function myLinker () {
		const cjs = new vm.SyntheticModule([], function myCB () {
			throw Error();
		});
		await cjs.link(() => {});
		await cjs.evaluate();//
		return cjs;
	});
	await mjs.evaluate();
} catch { console.log('caught'); }
caught
  1. the results are different
  2. the above one follows the spec
  3. the under one got right error caught

Does default loader internally use same code parts with --experimental-vm-modules?

LongTengDao avatar Feb 07 '24 18:02 LongTengDao

Been a while since I commented on my progress, I am pretty sure I found the problem.

process.on('uncaughtException', ()=>console.log('uncaught'));
try {
    await import(`data:text/javascript,
        import "data:text/javascript,console.log('before')";
        import "${import.meta.url}.cjs"; // this imports correctly if it is .mjs
    `);
}
catch { console.log('caught'); }

When the main.mjs.cjs file throws the error, it goes into the lib/internal/process/promises.js file, calls the promiseRejectHandler, function, which calls the unhandledRejection function, pushes the rejected promise into the pendingUnhandledRejections array, and sets the maybeUnhandledPromises to the promise.

When the main.mjs.mjs file throws the error, it does the same as above, except after it calls the promiseRejectHandler again, this time the it calls the handledRejection function, which deletes the promise from the maybeUnhandledPromises WeakMap.

This comes into play after the console.log('caught');, when the processTicksAndRejections function is called. It calls a function that checks the pendingUnhandledRejections and maybeUnhandledPromises. If the maybeUnhandledPromises is undefined, then it does nothing, as in the case when importing main.mjs.mjs. If it is not, as in the case when importing main.mjs.cjs, then it has a switch statement to see what error should be called, in this case, kThrowUnhandledRejections, which calls triggerUncaughtException, passing in the error.

If this is not the cause of the problem, please let me know!! :)

JohnCampbellroyceayr avatar Feb 10 '24 14:02 JohnCampbellroyceayr

I have not been able to find where the code for the this.module.evaluate function is, called from the /lib/internal/modules/esm/module_job.js file, line 218. This is called regardless if the function is a mjs or cjs, and in the mjs case, the error handling it treated differently. Does anyone know where the function is located? Maybe a silly question, but I can't seem to figure it out. Thanks in advance for the help!

JohnCampbellroyceayr avatar Feb 13 '24 01:02 JohnCampbellroyceayr

Hello, all Been a couple weeks since the last message, and I haven't really made any progress since then. I feel as if I don't fully understand the problem / codebase.

Is there any documentation I should read before continuing? (other than https://github.com/nodejs/node/tree/main/doc/contributing, that is) I thought maybe I could just jump in and fix the problem, but it is more difficult then I had imagined. :) Any help is much appreciated! Thanks.

JohnCampbellroyceayr avatar Feb 26 '24 17:02 JohnCampbellroyceayr