From 1ae1dab7850b3813b23302820e5c767d2511d41a Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Thu, 7 Mar 2024 05:43:44 +0100 Subject: [PATCH] module: print location of unsettled top-level await in entry points When the entry point is a module and the graph it imports still contains unsettled top-level await when the Node.js instance finishes the event loop, search from the entry point module for unsettled top-level await and print their location. To avoid unnecessary overhead, we register a promise that only gets settled when the entry point graph evaluation returns from await, and only search the module graph if it's still unsettled by the time the instance is exiting. This patch only handles this for entry point modules. Other kinds of modules are more complicated so will be left for the future. Drive-by: update the terminology "unfinished promise" to the more correct one "unsettled promise" in the codebase. PR-URL: https://github.com/nodejs/node/pull/51999 Fixes: https://github.com/nodejs/node/issues/42868 Reviewed-By: Moshe Atlow Reviewed-By: Benjamin Gruenbaum Reviewed-By: Geoffrey Booth --- doc/api/process.md | 4 +-- lib/internal/modules/esm/hooks.js | 4 +-- lib/internal/modules/esm/loader.js | 8 ++--- lib/internal/modules/esm/module_job.js | 12 +++++-- lib/internal/modules/run_main.js | 27 ++++++--------- lib/internal/process/per_thread.js | 3 -- src/api/embed_helpers.cc | 15 +++++++- src/env-inl.h | 4 +++ src/env.cc | 37 ++++++++++++++++++++ src/env.h | 2 ++ src/env_properties.h | 2 ++ src/module_wrap.cc | 38 ++++++++++++++++++++ src/module_wrap.h | 1 + src/node_exit_code.h | 2 +- test/es-module/test-esm-loader-hooks.mjs | 29 ++++++++++++++-- test/es-module/test-esm-tla-unfinished.mjs | 40 ++++++++++++++++++++-- 16 files changed, 192 insertions(+), 36 deletions(-) diff --git a/doc/api/process.md b/doc/api/process.md index 9faf4432f9b9f2..e16659cd74498a 100644 --- a/doc/api/process.md +++ b/doc/api/process.md @@ -3953,8 +3953,8 @@ cases: and generally can only happen during development of Node.js itself. * `12` **Invalid Debug Argument**: The `--inspect` and/or `--inspect-brk` options were set, but the port number chosen was invalid or unavailable. -* `13` **Unfinished Top-Level Await**: `await` was used outside of a function - in the top-level code, but the passed `Promise` never resolved. +* `13` **Unsettled Top-Level Await**: `await` was used outside of a function + in the top-level code, but the passed `Promise` never settled. * `14` **Snapshot Failure**: Node.js was started to build a V8 startup snapshot and it failed because certain requirements of the state of the application were not met. diff --git a/lib/internal/modules/esm/hooks.js b/lib/internal/modules/esm/hooks.js index 60942130dd48b9..ba655116a0bb57 100644 --- a/lib/internal/modules/esm/hooks.js +++ b/lib/internal/modules/esm/hooks.js @@ -32,7 +32,7 @@ const { ERR_METHOD_NOT_IMPLEMENTED, ERR_WORKER_UNSERIALIZABLE_ERROR, } = require('internal/errors').codes; -const { exitCodes: { kUnfinishedTopLevelAwait } } = internalBinding('errors'); +const { exitCodes: { kUnsettledTopLevelAwait } } = internalBinding('errors'); const { URL } = require('internal/url'); const { canParse: URLCanParse } = internalBinding('url'); const { receiveMessageOnPort } = require('worker_threads'); @@ -615,7 +615,7 @@ class HooksProxy { } while (response == null); debug('got sync response from worker', { method, args }); if (response.message.status === 'never-settle') { - process.exit(kUnfinishedTopLevelAwait); + process.exit(kUnsettledTopLevelAwait); } else if (response.message.status === 'exit') { process.exit(response.message.body); } diff --git a/lib/internal/modules/esm/loader.js b/lib/internal/modules/esm/loader.js index fd4faa3bd4af62..1b46caf9c6412d 100644 --- a/lib/internal/modules/esm/loader.js +++ b/lib/internal/modules/esm/loader.js @@ -182,7 +182,7 @@ class ModuleLoader { } } - async eval(source, url) { + async eval(source, url, isEntryPoint = false) { const evalInstance = (url) => { const { ModuleWrap } = internalBinding('module_wrap'); const { registerModule } = require('internal/modules/esm/utils'); @@ -201,7 +201,7 @@ class ModuleLoader { const job = new ModuleJob( this, url, undefined, evalInstance, false, false); this.loadCache.set(url, undefined, job); - const { module } = await job.run(); + const { module } = await job.run(isEntryPoint); return { __proto__: null, @@ -311,9 +311,9 @@ class ModuleLoader { * module import. * @returns {Promise} */ - async import(specifier, parentURL, importAttributes) { + async import(specifier, parentURL, importAttributes, isEntryPoint = false) { const moduleJob = await this.getModuleJob(specifier, parentURL, importAttributes); - const { module } = await moduleJob.run(); + const { module } = await moduleJob.run(isEntryPoint); return module.getNamespace(); } diff --git a/lib/internal/modules/esm/module_job.js b/lib/internal/modules/esm/module_job.js index 05db7f3867efe2..108a8138443de0 100644 --- a/lib/internal/modules/esm/module_job.js +++ b/lib/internal/modules/esm/module_job.js @@ -17,10 +17,15 @@ const { StringPrototypeIncludes, StringPrototypeSplit, StringPrototypeStartsWith, + globalThis, } = primordials; const { ModuleWrap } = internalBinding('module_wrap'); - +const { + privateSymbols: { + entry_point_module_private_symbol, + }, +} = internalBinding('util'); const { decorateErrorStack, kEmptyObject } = require('internal/util'); const { getSourceMapsEnabled, @@ -213,8 +218,11 @@ class ModuleJob { return { __proto__: null, module: this.module }; } - async run() { + async run(isEntryPoint = false) { await this.instantiate(); + if (isEntryPoint) { + globalThis[entry_point_module_private_symbol] = this.module; + } const timeout = -1; const breakOnSigint = false; setHasStartedUserESMExecution(); diff --git a/lib/internal/modules/run_main.js b/lib/internal/modules/run_main.js index 6488bedb21cf6c..b134a54cfec92a 100644 --- a/lib/internal/modules/run_main.js +++ b/lib/internal/modules/run_main.js @@ -2,6 +2,7 @@ const { StringPrototypeEndsWith, + globalThis, } = primordials; const { containsModuleSyntax } = internalBinding('contextify'); @@ -16,9 +17,12 @@ const { } = require('internal/process/execution'); const { triggerUncaughtException, - exitCodes: { kUnfinishedTopLevelAwait }, } = internalBinding('errors'); - +const { + privateSymbols: { + entry_point_promise_private_symbol, + }, +} = internalBinding('util'); /** * Get the absolute path to the main entry point. * @param {string} main - Entry point path @@ -102,20 +106,10 @@ function shouldUseESMLoader(mainPath) { return type === 'module'; } -/** - * Handle a Promise from running code that potentially does Top-Level Await. - * In that case, it makes sense to set the exit code to a specific non-zero value - * if the main code never finishes running. - */ -function handleProcessExit() { - process.exitCode ??= kUnfinishedTopLevelAwait; -} - /** * @param {function(ModuleLoader):ModuleWrap|undefined} callback */ async function asyncRunEntryPointWithESMLoader(callback) { - process.on('exit', handleProcessExit); const cascadedLoader = require('internal/modules/esm/loader').getOrInitializeCascadedLoader(); try { const userImports = getOptionValue('--import'); @@ -137,8 +131,6 @@ async function asyncRunEntryPointWithESMLoader(callback) { err, true, /* fromPromise */ ); - } finally { - process.off('exit', handleProcessExit); } } @@ -152,6 +144,10 @@ async function asyncRunEntryPointWithESMLoader(callback) { */ function runEntryPointWithESMLoader(callback) { const promise = asyncRunEntryPointWithESMLoader(callback); + // Register the promise - if by the time the event loop finishes running, this is + // still unsettled, we'll search the graph from the entry point module and print + // the location of any unsettled top-level await found. + globalThis[entry_point_promise_private_symbol] = promise; return promise; } @@ -171,7 +167,7 @@ function executeUserEntryPoint(main = process.argv[1]) { const mainURL = pathToFileURL(mainPath).href; runEntryPointWithESMLoader((cascadedLoader) => { - // Note that if the graph contains unfinished TLA, this may never resolve + // Note that if the graph contains unsettled TLA, this may never resolve // even after the event loop stops running. return cascadedLoader.import(mainURL, undefined, { __proto__: null }, true); }); @@ -185,5 +181,4 @@ function executeUserEntryPoint(main = process.argv[1]) { module.exports = { executeUserEntryPoint, runEntryPointWithESMLoader, - handleProcessExit, }; diff --git a/lib/internal/process/per_thread.js b/lib/internal/process/per_thread.js index 85777c9e4a3ed5..891767da529ca0 100644 --- a/lib/internal/process/per_thread.js +++ b/lib/internal/process/per_thread.js @@ -173,9 +173,6 @@ function wrapProcessMethods(binding) { memoryUsage.rss = rss; function exit(code) { - const { handleProcessExit } = require('internal/modules/run_main'); - process.off('exit', handleProcessExit); - if (arguments.length !== 0) { process.exitCode = code; } diff --git a/src/api/embed_helpers.cc b/src/api/embed_helpers.cc index 6fac48d1b534d2..1a2cb29993057f 100644 --- a/src/api/embed_helpers.cc +++ b/src/api/embed_helpers.cc @@ -73,7 +73,20 @@ Maybe SpinEventLoopInternal(Environment* env) { env->PrintInfoForSnapshotIfDebug(); env->ForEachRealm([](Realm* realm) { realm->VerifyNoStrongBaseObjects(); }); - return EmitProcessExitInternal(env); + Maybe exit_code = EmitProcessExitInternal(env); + if (exit_code.FromMaybe(ExitCode::kGenericUserError) != + ExitCode::kNoFailure) { + return exit_code; + } + + auto unsettled_tla = env->CheckUnsettledTopLevelAwait(); + if (unsettled_tla.IsNothing()) { + return Nothing(); + } + if (!unsettled_tla.FromJust()) { + return Just(ExitCode::kUnsettledTopLevelAwait); + } + return Just(ExitCode::kNoFailure); } struct CommonEnvironmentSetup::Impl { diff --git a/src/env-inl.h b/src/env-inl.h index 666dad97b021f4..c547fc987ea508 100644 --- a/src/env-inl.h +++ b/src/env-inl.h @@ -371,6 +371,10 @@ inline void Environment::set_exiting(bool value) { exit_info_[kExiting] = value ? 1 : 0; } +inline bool Environment::exiting() const { + return exit_info_[kExiting] == 1; +} + inline ExitCode Environment::exit_code(const ExitCode default_code) const { return exit_info_[kHasExitCode] == 0 ? default_code diff --git a/src/env.cc b/src/env.cc index 9f83720fefc773..5d2ac14b29c168 100644 --- a/src/env.cc +++ b/src/env.cc @@ -4,6 +4,7 @@ #include "debug_utils-inl.h" #include "diagnosticfilename-inl.h" #include "memory_tracker-inl.h" +#include "module_wrap.h" #include "node_buffer.h" #include "node_context_data.h" #include "node_contextify.h" @@ -50,6 +51,7 @@ using v8::HeapSpaceStatistics; using v8::Integer; using v8::Isolate; using v8::Local; +using v8::Maybe; using v8::MaybeLocal; using v8::NewStringType; using v8::Number; @@ -1228,6 +1230,41 @@ void Environment::AtExit(void (*cb)(void* arg), void* arg) { at_exit_functions_.push_front(ExitCallback{cb, arg}); } +Maybe Environment::CheckUnsettledTopLevelAwait() { + HandleScope scope(isolate_); + Local ctx = context(); + Local value; + + Local entry_point_promise; + if (!ctx->Global() + ->GetPrivate(ctx, entry_point_promise_private_symbol()) + .ToLocal(&entry_point_promise)) { + return v8::Nothing(); + } + if (!entry_point_promise->IsPromise()) { + return v8::Just(true); + } + if (entry_point_promise.As()->State() != + Promise::PromiseState::kPending) { + return v8::Just(true); + } + + if (!ctx->Global() + ->GetPrivate(ctx, entry_point_module_private_symbol()) + .ToLocal(&value)) { + return v8::Nothing(); + } + if (!value->IsObject()) { + return v8::Just(true); + } + Local object = value.As(); + CHECK(BaseObject::IsBaseObject(isolate_data_, object)); + CHECK_EQ(object->InternalFieldCount(), + loader::ModuleWrap::kInternalFieldCount); + auto* wrap = BaseObject::FromJSObject(object); + return wrap->CheckUnsettledTopLevelAwait(); +} + void Environment::RunAndClearInterrupts() { while (native_immediates_interrupts_.size() > 0) { NativeImmediateQueue queue; diff --git a/src/env.h b/src/env.h index ff09da28b2cadc..cc1233050f6fb1 100644 --- a/src/env.h +++ b/src/env.h @@ -735,6 +735,7 @@ class Environment : public MemoryRetainer { // a pseudo-boolean to indicate whether the exit code is undefined. inline AliasedInt32Array& exit_info(); inline void set_exiting(bool value); + bool exiting() const; inline ExitCode exit_code(const ExitCode default_code) const; // This stores whether the --abort-on-uncaught-exception flag was passed @@ -840,6 +841,7 @@ class Environment : public MemoryRetainer { void AtExit(void (*cb)(void* arg), void* arg); void RunAtExitCallbacks(); + v8::Maybe CheckUnsettledTopLevelAwait(); void RunWeakRefCleanup(); v8::MaybeLocal RunSnapshotSerializeCallback() const; diff --git a/src/env_properties.h b/src/env_properties.h index 1ecd06e1a3546d..6f99d819ac78a8 100644 --- a/src/env_properties.h +++ b/src/env_properties.h @@ -24,6 +24,8 @@ V(transfer_mode_private_symbol, "node:transfer_mode") \ V(host_defined_option_symbol, "node:host_defined_option_symbol") \ V(js_transferable_wrapper_private_symbol, "node:js_transferable_wrapper") \ + V(entry_point_module_private_symbol, "node:entry_point_module") \ + V(entry_point_promise_private_symbol, "node:entry_point_promise") \ V(napi_type_tag, "node:napi:type_tag") \ V(napi_wrapper, "node:napi:wrapper") \ V(untransferable_object_private_symbol, "node:untransferableObject") \ diff --git a/src/module_wrap.cc b/src/module_wrap.cc index 58ebe7b837af5f..25eb79d450c807 100644 --- a/src/module_wrap.cc +++ b/src/module_wrap.cc @@ -104,6 +104,44 @@ ModuleWrap* ModuleWrap::GetFromModule(Environment* env, return nullptr; } +v8::Maybe ModuleWrap::CheckUnsettledTopLevelAwait() { + Isolate* isolate = env()->isolate(); + Local context = env()->context(); + + // This must be invoked when the environment is shutting down, and the module + // is kept alive by the module wrap via an internal field. + CHECK(env()->exiting()); + CHECK(!module_.IsEmpty()); + + Local module = module_.Get(isolate); + // It's a synthetic module, likely a facade wrapping CJS. + if (!module->IsSourceTextModule()) { + return v8::Just(true); + } + + if (!module->IsGraphAsync()) { // There is no TLA, no need to check. + return v8::Just(true); + } + auto stalled = module->GetStalledTopLevelAwaitMessage(isolate); + if (stalled.size() == 0) { + return v8::Just(true); + } + + if (env()->options()->warnings) { + for (auto pair : stalled) { + Local message = std::get<1>(pair); + + std::string reason = "Warning: Detected unsettled top-level await at "; + std::string info = + FormatErrorMessage(isolate, context, "", message, true); + reason += info; + FPrintF(stderr, "%s\n", reason); + } + } + + return v8::Just(false); +} + // new ModuleWrap(url, context, source, lineOffset, columnOffset) // new ModuleWrap(url, context, exportNames, syntheticExecutionFunction) void ModuleWrap::New(const FunctionCallbackInfo& args) { diff --git a/src/module_wrap.h b/src/module_wrap.h index e17048357feca2..6f44d722ee0b01 100644 --- a/src/module_wrap.h +++ b/src/module_wrap.h @@ -58,6 +58,7 @@ class ModuleWrap : public BaseObject { } v8::Local context() const; + v8::Maybe CheckUnsettledTopLevelAwait(); SET_MEMORY_INFO_NAME(ModuleWrap) SET_SELF_SIZE(ModuleWrap) diff --git a/src/node_exit_code.h b/src/node_exit_code.h index 07c5a94e35ee28..0ba0511b5a3de5 100644 --- a/src/node_exit_code.h +++ b/src/node_exit_code.h @@ -27,7 +27,7 @@ namespace node { /* This was intended for invalid inspector arguments but is actually now */ \ /* just a duplicate of InvalidCommandLineArgument */ \ V(InvalidCommandLineArgument2, 12) \ - V(UnfinishedTopLevelAwait, 13) \ + V(UnsettledTopLevelAwait, 13) \ V(StartupSnapshotFailure, 14) \ /* If the process exits from unhandled signals e.g. SIGABRT, SIGTRAP, */ \ /* typically the exit codes are 128 + signal number. We also exit with */ \ diff --git a/test/es-module/test-esm-loader-hooks.mjs b/test/es-module/test-esm-loader-hooks.mjs index 6f035bccb87f5c..2085ffaed1049e 100644 --- a/test/es-module/test-esm-loader-hooks.mjs +++ b/test/es-module/test-esm-loader-hooks.mjs @@ -51,7 +51,7 @@ describe('Loader hooks', { concurrency: true }, () => { }); describe('should handle never-settling hooks in ESM files', { concurrency: true }, () => { - it('top-level await of a never-settling resolve', async () => { + it('top-level await of a never-settling resolve without warning', async () => { const { code, signal, stdout, stderr } = await spawnPromisified(execPath, [ '--no-warnings', '--experimental-loader', @@ -65,7 +65,20 @@ describe('Loader hooks', { concurrency: true }, () => { assert.strictEqual(signal, null); }); - it('top-level await of a never-settling load', async () => { + it('top-level await of a never-settling resolve with warning', async () => { + const { code, signal, stdout, stderr } = await spawnPromisified(execPath, [ + '--experimental-loader', + fixtures.fileURL('es-module-loaders/never-settling-resolve-step/loader.mjs'), + fixtures.path('es-module-loaders/never-settling-resolve-step/never-resolve.mjs'), + ]); + + assert.match(stderr, /Warning: Detected unsettled top-level await at.+never-resolve\.mjs:5/); + assert.match(stdout, /^should be output\r?\n$/); + assert.strictEqual(code, 13); + assert.strictEqual(signal, null); + }); + + it('top-level await of a never-settling load without warning', async () => { const { code, signal, stdout, stderr } = await spawnPromisified(execPath, [ '--no-warnings', '--experimental-loader', @@ -79,6 +92,18 @@ describe('Loader hooks', { concurrency: true }, () => { assert.strictEqual(signal, null); }); + it('top-level await of a never-settling load with warning', async () => { + const { code, signal, stdout, stderr } = await spawnPromisified(execPath, [ + '--experimental-loader', + fixtures.fileURL('es-module-loaders/never-settling-resolve-step/loader.mjs'), + fixtures.path('es-module-loaders/never-settling-resolve-step/never-load.mjs'), + ]); + + assert.match(stderr, /Warning: Detected unsettled top-level await at.+never-load\.mjs:5/); + assert.match(stdout, /^should be output\r?\n$/); + assert.strictEqual(code, 13); + assert.strictEqual(signal, null); + }); it('top-level await of a race of never-settling hooks', async () => { const { code, signal, stdout, stderr } = await spawnPromisified(execPath, [ diff --git a/test/es-module/test-esm-tla-unfinished.mjs b/test/es-module/test-esm-tla-unfinished.mjs index 48bc4d77f42b4e..24c761042def51 100644 --- a/test/es-module/test-esm-tla-unfinished.mjs +++ b/test/es-module/test-esm-tla-unfinished.mjs @@ -6,18 +6,30 @@ import { describe, it } from 'node:test'; const commonArgs = [ - '--no-warnings', '--input-type=module', '--eval', ]; describe('ESM: unsettled and rejected promises', { concurrency: true }, () => { - it('should exit for an unsettled TLA promise via --eval', async () => { + it('should exit for an unsettled TLA promise via --eval with a warning', async () => { const { code, stderr, stdout } = await spawnPromisified(execPath, [ ...commonArgs, 'await new Promise(() => {})', ]); + assert.match(stderr, /Warning: Detected unsettled top-level await at.+\[eval1\]:1/); + assert.match(stderr, /await new Promise/); + assert.strictEqual(stdout, ''); + assert.strictEqual(code, 13); + }); + + it('should exit for an unsettled TLA promise via --eval without warning', async () => { + const { code, stderr, stdout } = await spawnPromisified(execPath, [ + '--no-warnings', + ...commonArgs, + 'await new Promise(() => {})', + ]); + assert.strictEqual(stderr, ''); assert.strictEqual(stdout, ''); assert.strictEqual(code, 13); @@ -59,7 +71,18 @@ describe('ESM: unsettled and rejected promises', { concurrency: true }, () => { assert.strictEqual(code, 1); }); - it('should exit for an unsettled TLA promise via stdin', async () => { + it('should exit for an unsettled TLA promise with warning', async () => { + const { code, stderr, stdout } = await spawnPromisified(execPath, [ + fixtures.path('es-modules/tla/unresolved.mjs'), + ]); + + assert.match(stderr, /Warning: Detected unsettled top-level await at.+unresolved\.mjs:1/); + assert.match(stderr, /await new Promise/); + assert.strictEqual(stdout, ''); + assert.strictEqual(code, 13); + }); + + it('should exit for an unsettled TLA promise without warning', async () => { const { code, stderr, stdout } = await spawnPromisified(execPath, [ '--no-warnings', fixtures.path('es-modules/tla/unresolved.mjs'), @@ -115,6 +138,17 @@ describe('ESM: unsettled and rejected promises', { concurrency: true }, () => { }); it('should be unaffected by `process.exit()` in worker thread', async () => { + const { code, stderr, stdout } = await spawnPromisified(execPath, [ + fixtures.path('es-modules/tla/unresolved-with-worker-process-exit.mjs'), + ]); + + assert.match(stderr, /Warning: Detected unsettled top-level await at.+with-worker-process-exit\.mjs:5/); + assert.match(stderr, /await new Promise/); + assert.strictEqual(stdout, ''); + assert.strictEqual(code, 13); + }); + + it('should be unaffected by `process.exit()` in worker thread without warning', async () => { const { code, stderr, stdout } = await spawnPromisified(execPath, [ '--no-warnings', fixtures.path('es-modules/tla/unresolved-with-worker-process-exit.mjs'),