module: improve error message from asynchronicity in require(esm)

- Improve the error message that shows up when there is a race from doing require(esm) and import(esm) at the same time. - Improve error message of ERR_REQUIRE_ASYNC_MODULE by showing parent and target file names, if available. Drive-by: split the require(tla) tests since we are modifying the tests already. PR-URL: #57126 Backport-PR-URL: #59504 Refs: https://github.com/fisker/prettier-issue-17139 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com> Reviewed-By: Chengzhong Wu <legendecas@gmail.com> Refs: #52697

Author: joyeecheung

lib/internal/errors.js

@@ -1692,9 +1692,18 @@ E('ERR_PARSE_ARGS_UNKNOWN_OPTION', (option, allowPositionals) => {
 E('ERR_PERFORMANCE_INVALID_TIMESTAMP',
  '%d is not a valid timestamp', TypeError);
 E('ERR_PERFORMANCE_MEASURE_INVALID_OPTIONS', '%s', TypeError);
-E('ERR_REQUIRE_ASYNC_MODULE', 'require() cannot be used on an ESM ' +
- 'graph with top-level await. Use import() instead. To see where the' +
- ' top-level await comes from, use --experimental-print-required-tla.', Error);
+E('ERR_REQUIRE_ASYNC_MODULE', function(filename, parentFilename) {
+ let message = 'require() cannot be used on an ESM ' +
+ 'graph with top-level await. Use import() instead. To see where the' +
+ ' top-level await comes from, use --experimental-print-required-tla.';
+ if (parentFilename) {
+ message += `\n From ${parentFilename} `;
+ }
+ if (filename) {
+ message += `\n Requiring ${filename} `;
+ }
+ return message;
+}, Error);
 E('ERR_REQUIRE_CYCLE_MODULE', '%s', Error);
 E('ERR_REQUIRE_ESM',
  function(filename, hasEsmSyntax, parentPath = null, packageJsonPath = null) {

lib/internal/modules/esm/loader.js

@@ -295,20 +295,37 @@ class ModuleLoader {
  // TODO(joyeecheung): ensure that imported synchronous graphs are evaluated
  // synchronously so that any previously imported synchronous graph is already
  // evaluated at this point.
+ // TODO(joyeecheung): add something similar to CJS loader's requireStack to help
+ // debugging the the problematic links in the graph for import.
  if (job !== undefined) {
  mod[kRequiredModuleSymbol] = job.module;
+ const parentFilename = urlToFilename(parent?.filename);
+ // TODO(node:55782): this race may stop to happen when the ESM resolution and loading become synchronous.
+ if (!job.module) {
+ let message = `Cannot require() ES Module ${filename} because it is not yet fully loaded. `;
+ message += 'This may be caused by a race condition if the module is simultaneously dynamically ';
+ message += 'import()-ed via Promise.all(). Try await-ing the import() sequentially in a loop instead.';
+ if (parentFilename) {
+ message += ` (from ${parentFilename})`;
+ }
+ assert(job.module, message);
+ }
  if (job.module.async) {
- throw new ERR_REQUIRE_ASYNC_MODULE();
+ throw new ERR_REQUIRE_ASYNC_MODULE(filename, parentFilename);
  }
+ // job.module may be undefined if it's asynchronously loaded. Which means
+ // there is likely a cycle.
  if (job.module.getStatus() !== kEvaluated) {
- const parentFilename = urlToFilename(parent?.filename);
  let message = `Cannot require() ES Module ${filename} in a cycle.`;
  if (parentFilename) {
  message += ` (from ${parentFilename})`;
  }
+ message += 'A cycle involving require(esm) is disallowed to maintain ';
+ message += 'invariants madated by the ECMAScript specification';
+ message += 'Try making at least part of the dependency in the graph lazily loaded.';
  throw new ERR_REQUIRE_CYCLE_MODULE(message);
  }
- return { wrap: job.module, namespace: job.module.getNamespaceSync() };
+ return { wrap: job.module, namespace: job.module.getNamespaceSync(filename, parentFilename) };
  }
  // TODO(joyeecheung): refactor this so that we pre-parse in C++ and hit the
  // cache here, or use a carrier object to carry the compiled module script
@@ -320,7 +337,7 @@ class ModuleLoader {
  job = new ModuleJobSync(this, url, kEmptyObject, wrap, isMain, inspectBrk);
  this.loadCache.set(url, kImplicitAssertType, job);
  mod[kRequiredModuleSymbol] = job.module;
- return { wrap: job.module, namespace: job.runSync().namespace };
+ return { wrap: job.module, namespace: job.runSync(parent).namespace };
  }
 
  /**

lib/internal/modules/esm/module_job.js

@@ -31,6 +31,7 @@ const assert = require('internal/assert');
 const resolvedPromise = PromiseResolve();
 const {
  setHasStartedUserESMExecution,
+ urlToFilename,
 } = require('internal/modules/helpers');
 const { getOptionValue } = require('internal/options');
 const noop = FunctionPrototype;
@@ -371,7 +372,7 @@ class ModuleJobSync extends ModuleJobBase {
  `Status = ${status}`);
  }
 
- runSync() {
+ runSync(parent) {
  // TODO(joyeecheung): add the error decoration logic from the async instantiate.
  this.module.async = this.module.instantiateSync();
  // If --experimental-print-required-tla is true, proceeds to evaluation even
@@ -380,11 +381,13 @@ class ModuleJobSync extends ModuleJobBase {
  // TODO(joyeecheung): track the asynchroniticy using v8::Module::HasTopLevelAwait()
  // and we'll be able to throw right after compilation of the modules, using acron
  // to find and print the TLA.
+ const parentFilename = urlToFilename(parent?.filename);
+ const filename = urlToFilename(this.url);
  if (this.module.async && !getOptionValue('--experimental-print-required-tla')) {
- throw new ERR_REQUIRE_ASYNC_MODULE();
+ throw new ERR_REQUIRE_ASYNC_MODULE(filename, parentFilename);
  }
  setHasStartedUserESMExecution();
- const namespace = this.module.evaluateSync();
+ const namespace = this.module.evaluateSync(filename, parentFilename);
  return { __proto__: null, module: this.module, namespace };
  }
 }

src/module_wrap.cc

@@ -648,7 +648,7 @@ void ModuleWrap::EvaluateSync(const FunctionCallbackInfo<Value>& args) {
  FPrintF(stderr, "%s\n", reason);
  }
  }
- THROW_ERR_REQUIRE_ASYNC_MODULE(env);
+ THROW_ERR_REQUIRE_ASYNC_MODULE(env, args[0], args[1]);
  return;
  }
 
@@ -678,7 +678,7 @@ void ModuleWrap::GetNamespaceSync(const FunctionCallbackInfo<Value>& args) {
  }
 
  if (module->IsGraphAsync()) {
- return THROW_ERR_REQUIRE_ASYNC_MODULE(realm->env());
+ return THROW_ERR_REQUIRE_ASYNC_MODULE(realm->env(), args[0], args[1]);
  }
  Local<Value> result = module->GetModuleNamespace();
  args.GetReturnValue().Set(result);

src/node_errors.h

@@ -208,10 +208,6 @@ ERRORS_WITH_CODE(V)
  "creating Workers") \
  V(ERR_NON_CONTEXT_AWARE_DISABLED, \
  "Loading non context-aware native addons has been disabled") \
- V(ERR_REQUIRE_ASYNC_MODULE, \
- "require() cannot be used on an ESM graph with top-level await. Use " \
- "import() instead. To see where the top-level await comes from, use " \
- "--experimental-print-required-tla.") \
  V(ERR_SCRIPT_EXECUTION_INTERRUPTED, \
  "Script execution was interrupted by `SIGINT`") \
  V(ERR_TLS_PSK_SET_IDENTIY_HINT_FAILED, "Failed to set PSK identity hint") \
@@ -241,6 +237,28 @@ inline void THROW_ERR_SCRIPT_EXECUTION_TIMEOUT(Environment* env,
  THROW_ERR_SCRIPT_EXECUTION_TIMEOUT(env, message.str().c_str());
 }
 
+inline void THROW_ERR_REQUIRE_ASYNC_MODULE(
+ Environment* env,
+ v8::Local<v8::Value> filename,
+ v8::Local<v8::Value> parent_filename) {
+ static constexpr const char* prefix =
+ "require() cannot be used on an ESM graph with top-level await. Use "
+ "import() instead. To see where the top-level await comes from, use "
+ "--experimental-print-required-tla.";
+ std::string message = prefix;
+ if (!parent_filename.IsEmpty() && parent_filename->IsString()) {
+ Utf8Value utf8(env->isolate(), parent_filename);
+ message += "\n From ";
+ message += utf8.out();
+ }
+ if (!filename.IsEmpty() && filename->IsString()) {
+ Utf8Value utf8(env->isolate(), filename);
+ message += "\n Requiring ";
+ message += +utf8.out();
+ }
+ THROW_ERR_REQUIRE_ASYNC_MODULE(env, message.c_str());
+}
+
 inline v8::Local<v8::Object> ERR_BUFFER_TOO_LARGE(v8::Isolate* isolate) {
  char message[128];
  snprintf(message, sizeof(message),

test/common/index.js

@@ -937,6 +937,17 @@ function expectRequiredModule(mod, expectation, checkESModule = true) {
  assert.deepStrictEqual(clone, { ...expectation });
 }
 
+function expectRequiredTLAError(err) {
+ const message = /require\(\) cannot be used on an ESM graph with top-level await/;
+ if (typeof err === 'string') {
+ assert.match(err, /ERR_REQUIRE_ASYNC_MODULE/);
+ assert.match(err, message);
+ } else {
+ assert.strictEqual(err.code, 'ERR_REQUIRE_ASYNC_MODULE');
+ assert.match(err.message, message);
+ }
+}
+
 const common = {
  allowGlobals,
  buildType,
@@ -946,6 +957,7 @@ const common = {
  defaultAutoSelectFamilyAttemptTimeout,
  expectsError,
  expectRequiredModule,
+ expectRequiredTLAError,
  expectWarning,
  getArrayBufferViews,
  getBufferSources,

test/es-module/test-require-module-tla-execution.js

@@ -0,0 +1,26 @@
+'use strict';
+
+// Tests that require(esm) with top-level-await throws before execution starts
+// if --experimental-print-required-tla is not enabled.
+
+const common = require('../common');
+const assert = require('assert');
+const { spawnSyncAndExit } = require('../common/child_process');
+const fixtures = require('../common/fixtures');
+
+{
+ spawnSyncAndExit(process.execPath, [
+ fixtures.path('es-modules/tla/require-execution.js'),
+ ], {
+ signal: null,
+ status: 1,
+ stderr(output) {
+ assert.doesNotMatch(output, /I am executed/);
+ common.expectRequiredTLAError(output);
+ assert.match(output, /From .*require-execution\.js/);
+ assert.match(output, /Requiring .*execution\.mjs/);
+ return true;
+ },
+ stdout: ''
+ });
+}

test/es-module/test-require-module-tla-nested.js

@@ -0,0 +1,15 @@
+'use strict';
+
+// Tests that require(esm) throws for top-level-await in inner graphs.
+
+const common = require('../common');
+const assert = require('assert');
+
+assert.throws(() => {
+ require('../fixtures/es-modules/tla/parent.mjs');
+}, (err) => {
+ common.expectRequiredTLAError(err);
+ assert.match(err.message, /From .*test-require-module-tla-nested\.js/);
+ assert.match(err.message, /Requiring .*parent\.mjs/);
+ return true;
+});

test/es-module/test-require-module-tla-print-execution.js

@@ -0,0 +1,29 @@
+'use strict';
+
+// Tests that require(esm) with top-level-await throws after execution
+// if --experimental-print-required-tla is enabled.
+
+const common = require('../common');
+const assert = require('assert');
+const { spawnSyncAndExit } = require('../common/child_process');
+const fixtures = require('../common/fixtures');
+
+{
+ spawnSyncAndExit(process.execPath, [
+ '--experimental-print-required-tla',
+ fixtures.path('es-modules/tla/require-execution.js'),
+ ], {
+ signal: null,
+ status: 1,
+ stderr(output) {
+ assert.match(output, /I am executed/);
+ common.expectRequiredTLAError(output);
+ assert.match(output, /Error: unexpected top-level await at.*execution\.mjs:3/);
+ assert.match(output, /await Promise\.resolve\('hi'\)/);
+ assert.match(output, /From .*require-execution\.js/);
+ assert.match(output, /Requiring .*execution\.mjs/);
+ return true;
+ },
+ stdout: ''
+ });
+}

test/es-module/test-require-module-tla-rejected.js

@@ -0,0 +1,15 @@
+'use strict';
+
+// Tests that require(esm) throws for rejected top-level await.
+
+const common = require('../common');
+const assert = require('assert');
+
+assert.throws(() => {
+ require('../fixtures/es-modules/tla/rejected.mjs');
+}, (err) => {
+ common.expectRequiredTLAError(err);
+ assert.match(err.message, /From .*test-require-module-tla-rejected\.js/);
+ assert.match(err.message, /Requiring .*rejected\.mjs/);
+ return true;
+});