diff --git a/benchmark/misc/print.js b/benchmark/misc/print.js new file mode 100644 index 00000000000000..e048d22f7b76ab --- /dev/null +++ b/benchmark/misc/print.js @@ -0,0 +1,59 @@ +'use strict'; +const common = require('../common.js'); +const { spawn } = require('child_process'); + +const bench = common.createBenchmark(main, { + dur: [1], + code: ['1', '"string"', 'process.versions', 'process'] +}); + +function spawnProcess(code) { + const cmd = process.execPath || process.argv[0]; + const argv = ['-p', code]; + return spawn(cmd, argv); +} + +function start(state, code, bench, getNode) { + const node = getNode(code); + let stdout = ''; + let stderr = ''; + + node.stdout.on('data', (data) => { + stdout += data; + }); + + node.stderr.on('data', (data) => { + stderr += data; + }); + + node.on('exit', (code) => { + if (code !== 0) { + console.error('------ stdout ------'); + console.error(stdout); + console.error('------ stderr ------'); + console.error(stderr); + throw new Error(`Error during node startup, exit code ${code}`); + } + state.throughput++; + + if (state.go) { + start(state, code, bench, getNode); + } else { + bench.end(state.throughput); + } + }); +} + +function main({ dur, code }) { + const state = { + go: true, + throughput: 0 + }; + + setTimeout(() => { + state.go = false; + }, dur * 1000); + + bench.start(); + start(state, code, bench, spawnProcess); +} diff --git a/lib/fs.js b/lib/fs.js index 38c13613cb352a..9effb93acb9b72 100644 --- a/lib/fs.js +++ b/lib/fs.js @@ -74,7 +74,8 @@ const { validateOffsetLengthRead, validateOffsetLengthWrite, validatePath, - warnOnNonPortableTemplate + warnOnNonPortableTemplate, + handleErrorFromBinding } = require('internal/fs/utils'); const { CHAR_FORWARD_SLASH, @@ -117,23 +118,6 @@ function showTruncateDeprecation() { } } -function handleErrorFromBinding(ctx) { - if (ctx.errno !== undefined) { // libuv error numbers - const err = uvException(ctx); - // eslint-disable-next-line no-restricted-syntax - Error.captureStackTrace(err, handleErrorFromBinding); - throw err; - } - if (ctx.error !== undefined) { // Errors created in C++ land. - // TODO(joyeecheung): currently, ctx.error are encoding errors - // usually caused by memory problems. We need to figure out proper error - // code(s) for this. - // eslint-disable-next-line no-restricted-syntax - Error.captureStackTrace(ctx.error, handleErrorFromBinding); - throw ctx.error; - } -} - function maybeCallback(cb) { if (typeof cb === 'function') return cb; diff --git a/lib/internal/fs/utils.js b/lib/internal/fs/utils.js index ca8328f553d283..dde78654e0f992 100644 --- a/lib/internal/fs/utils.js +++ b/lib/internal/fs/utils.js @@ -12,7 +12,8 @@ const { ERR_INVALID_OPT_VALUE_ENCODING, ERR_OUT_OF_RANGE }, - hideStackFrames + hideStackFrames, + uvException } = require('internal/errors'); const { isUint8Array, @@ -444,7 +445,26 @@ function warnOnNonPortableTemplate(template) { } } +// This handles errors following the convention of the fs binding. +function handleErrorFromBinding(ctx) { + if (ctx.errno !== undefined) { // libuv error numbers + const err = uvException(ctx); + // eslint-disable-next-line no-restricted-syntax + Error.captureStackTrace(err, handleErrorFromBinding); + throw err; + } + if (ctx.error !== undefined) { // Errors created in C++ land. + // TODO(joyeecheung): currently, ctx.error are encoding errors + // usually caused by memory problems. We need to figure out proper error + // code(s) for this. + // eslint-disable-next-line no-restricted-syntax + Error.captureStackTrace(ctx.error, handleErrorFromBinding); + throw ctx.error; + } +} + module.exports = { + handleErrorFromBinding, assertEncoding, copyObject, Dirent, diff --git a/lib/internal/main/repl.js b/lib/internal/main/repl.js index 980893f9c34e20..58afb2be9879fa 100644 --- a/lib/internal/main/repl.js +++ b/lib/internal/main/repl.js @@ -11,7 +11,7 @@ const { evalScript } = require('internal/process/execution'); -const console = require('internal/console/global'); +const { print, kStderr, kStdout } = require('internal/util/print'); const { getOptionValue } = require('internal/options'); @@ -21,14 +21,12 @@ markBootstrapComplete(); // --input-type flag not supported in REPL if (getOptionValue('--input-type')) { - // If we can't write to stderr, we'd like to make this a noop, - // so use console.error. - console.error('Cannot specify --input-type for REPL'); + print(kStderr, 'Cannot specify --input-type for REPL'); process.exit(1); } -console.log(`Welcome to Node.js ${process.version}.\n` + - 'Type ".help" for more information.'); +print(kStdout, `Welcome to Node.js ${process.version}.\n` + + 'Type ".help" for more information.'); const cliRepl = require('internal/repl'); cliRepl.createInternalRepl(process.env, (err, repl) => { diff --git a/lib/internal/modules/cjs/loader.js b/lib/internal/modules/cjs/loader.js index a1e5046d406a1a..96b5e8b7b881b6 100644 --- a/lib/internal/modules/cjs/loader.js +++ b/lib/internal/modules/cjs/loader.js @@ -819,13 +819,9 @@ Module.runMain = function() { true /* fromPromise */ ); }); - // Handle any nextTicks added in the first tick of the program - process._tickCallback(); return; } Module._load(process.argv[1], null, true); - // Handle any nextTicks added in the first tick of the program - process._tickCallback(); }; Module.createRequireFromPath = (filename) => { diff --git a/lib/internal/process/execution.js b/lib/internal/process/execution.js index addd450ed3551c..c95567c506237f 100644 --- a/lib/internal/process/execution.js +++ b/lib/internal/process/execution.js @@ -35,26 +35,22 @@ function tryGetCwd() { } } -function evalModule(source, print) { - const { log, error } = require('internal/console/global'); +function evalModule(source, printResult) { const { decorateErrorStack } = require('internal/util'); const asyncESM = require('internal/process/esm_loader'); + const { kStdout, kStderr, print } = require('internal/util/print'); asyncESM.loaderPromise.then(async (loader) => { const { result } = await loader.eval(source); - if (print) { - log(result); - } + if (printResult) { print(kStdout, result); } }) .catch((e) => { decorateErrorStack(e); - error(e); + print(kStderr, e); process.exit(1); }); - // Handle any nextTicks added in the first tick of the program. - process._tickCallback(); } -function evalScript(name, body, breakFirstLine, print) { +function evalScript(name, body, breakFirstLine, printResult) { const CJSModule = require('internal/modules/cjs/loader'); const { kVmBreakFirstLineSymbol } = require('internal/util'); @@ -79,12 +75,10 @@ function evalScript(name, body, breakFirstLine, print) { [kVmBreakFirstLineSymbol]: ${!!breakFirstLine} });\n`; const result = module._compile(script, `${name}-wrapper`); - if (print) { - const { log } = require('internal/console/global'); - log(result); + if (printResult) { + const { kStdout, print } = require('internal/util/print'); + print(kStdout, result); } - // Handle any nextTicks added in the first tick of the program. - process._tickCallback(); } const exceptionHandlerState = { captureFn: null }; diff --git a/lib/internal/process/task_queues.js b/lib/internal/process/task_queues.js index 12e34b7ff79068..309e27e6ecd0fa 100644 --- a/lib/internal/process/task_queues.js +++ b/lib/internal/process/task_queues.js @@ -49,6 +49,7 @@ function setHasTickScheduled(value) { const queue = new FixedQueue(); +// Should be in sync with RunNextTicksNative in node_task_queue.cc function runNextTicks() { if (!hasTickScheduled() && !hasRejectionToWarn()) runMicrotasks(); diff --git a/lib/internal/util/print.js b/lib/internal/util/print.js new file mode 100644 index 00000000000000..4c9327502ebad2 --- /dev/null +++ b/lib/internal/util/print.js @@ -0,0 +1,67 @@ +'use strict'; + +// This implements a light-weight printer that writes to stdout/stderr +// directly to avoid the overhead in the console abstraction. + +const { formatWithOptions } = require('internal/util/inspect'); +const { writeString } = internalBinding('fs'); +const { handleErrorFromBinding } = require('internal/fs/utils'); +const { guessHandleType } = internalBinding('util'); +const { log } = require('internal/console/global'); + +const kStdout = 1; +const kStderr = 2; +const handleType = [undefined, undefined, undefined]; +function getFdType(fd) { + if (handleType[fd] === undefined) { + handleType[fd] = guessHandleType(fd); + } + return handleType[fd]; +} + +function formatAndWrite(fd, obj, ignoreErrors, colors = false) { + const str = `${formatWithOptions({ colors }, obj)}\n`; + const ctx = {}; + writeString(fd, str, null, undefined, undefined, ctx); + if (!ignoreErrors) { + handleErrorFromBinding(ctx); + } +} + +let colors; +function getColors() { + if (colors === undefined) { + colors = require('internal/tty').getColorDepth() > 2; + } + return colors; +} + +// TODO(joyeecheung): replace more internal process._rawDebug() +// and console.log() usage with this if possible. +function print(fd, obj, ignoreErrors = true) { + switch (getFdType(fd)) { + case 'TTY': + formatAndWrite(fd, obj, ignoreErrors, getColors()); + break; + case 'FILE': + formatAndWrite(fd, obj, ignoreErrors); + break; + case 'PIPE': + case 'TCP': + // Fallback to console.log to handle IPC. + if (process.channel && process.channel.fd === fd) { + log(obj); + } else { + formatAndWrite(fd, obj, ignoreErrors); + } + break; + default: + log(obj); + } +} + +module.exports = { + print, + kStderr, + kStdout +}; diff --git a/node.gyp b/node.gyp index 53bd954afb3e39..3cf47ffc255531 100644 --- a/node.gyp +++ b/node.gyp @@ -184,6 +184,7 @@ 'lib/internal/url.js', 'lib/internal/util.js', 'lib/internal/util/comparisons.js', + 'lib/internal/util/print.js', 'lib/internal/util/debuglog.js', 'lib/internal/util/inspect.js', 'lib/internal/util/inspector.js', diff --git a/src/node.cc b/src/node.cc index 10ef0d5bc7c522..636a92eab3f760 100644 --- a/src/node.cc +++ b/src/node.cc @@ -379,9 +379,13 @@ MaybeLocal StartExecution(Environment* env, const char* main_script_id) { ->GetFunction(env->context()) .ToLocalChecked()}; - MaybeLocal result = - ExecuteBootstrapper(env, main_script_id, ¶meters, &arguments); - return scope.EscapeMaybe(result); + Local result; + if (!ExecuteBootstrapper(env, main_script_id, ¶meters, &arguments) + .ToLocal(&result) || + !task_queue::RunNextTicksNative(env)) { + return MaybeLocal(); + } + return scope.Escape(result); } MaybeLocal StartMainThreadExecution(Environment* env) { diff --git a/src/node_process.h b/src/node_process.h index cb6ad85828b608..f01445b3c515d0 100644 --- a/src/node_process.h +++ b/src/node_process.h @@ -36,6 +36,16 @@ v8::MaybeLocal CreateProcessObject( const std::vector& args, const std::vector& exec_args); void PatchProcessObject(const v8::FunctionCallbackInfo& args); + +namespace task_queue { +// Handle any nextTicks added in the first tick of the program. +// We use the native version here for once so that any microtasks +// created by the main module is then handled from C++, and +// the call stack of the main script does not show up in the async error +// stack trace. +bool RunNextTicksNative(Environment* env); +} // namespace task_queue + } // namespace node #endif // defined(NODE_WANT_INTERNALS) && NODE_WANT_INTERNALS #endif // SRC_NODE_PROCESS_H_ diff --git a/src/node_task_queue.cc b/src/node_task_queue.cc index b125f5d01ece66..af1d96fab22810 100644 --- a/src/node_task_queue.cc +++ b/src/node_task_queue.cc @@ -2,6 +2,7 @@ #include "node.h" #include "node_errors.h" #include "node_internals.h" +#include "node_process.h" #include "v8.h" #include @@ -38,6 +39,20 @@ static void EnqueueMicrotask(const FunctionCallbackInfo& args) { isolate->EnqueueMicrotask(args[0].As()); } +// Should be in sync with runNextTicks in internal/process/task_queues.js +bool RunNextTicksNative(Environment* env) { + TickInfo* tick_info = env->tick_info(); + if (!tick_info->has_tick_scheduled() && !tick_info->has_rejection_to_warn()) + env->isolate()->RunMicrotasks(); + if (!tick_info->has_tick_scheduled() && !tick_info->has_rejection_to_warn()) + return true; + + Local callback = env->tick_callback_function(); + CHECK(!callback.IsEmpty()); + return !callback->Call(env->context(), env->process_object(), 0, nullptr) + .IsEmpty(); +} + static void RunMicrotasks(const FunctionCallbackInfo& args) { args.GetIsolate()->RunMicrotasks(); } diff --git a/test/benchmark/test-benchmark-misc.js b/test/benchmark/test-benchmark-misc.js index b88415280833bc..13bd41e54016f5 100644 --- a/test/benchmark/test-benchmark-misc.js +++ b/test/benchmark/test-benchmark-misc.js @@ -10,6 +10,7 @@ runBenchmark('misc', [ 'method=', 'n=1', 'type=', + 'code=1', 'val=magyarország.icom.museum', 'script=test/fixtures/semicolon', 'mode=worker' diff --git a/test/fixtures/async-error.js b/test/fixtures/async-error.js new file mode 100644 index 00000000000000..48b19b40d8fb54 --- /dev/null +++ b/test/fixtures/async-error.js @@ -0,0 +1,27 @@ +'use strict'; + +async function one() { + throw new Error('test'); +} + +async function breaker() { + return true; +} + +async function stack() { + await breaker(); +} + +async function two() { + await stack(); + await one(); +} +async function three() { + await two(); +} + +async function four() { + await three(); +} + +module.exports = four; diff --git a/test/message/async_error_eval_cjs.js b/test/message/async_error_eval_cjs.js new file mode 100644 index 00000000000000..a2caaa0937745e --- /dev/null +++ b/test/message/async_error_eval_cjs.js @@ -0,0 +1,39 @@ +'use strict'; + +require('../common'); +const { spawnSync } = require('child_process'); + +const four = require('../common/fixtures') + .readSync('async-error.js') + .toString() + .split('\n') + .slice(2, -2) + .join('\n'); + +const main = `${four} + +async function main() { + try { + await four(); + } catch (e) { + console.log(e); + } +} + +main(); +`; + +// --eval CJS +{ + const child = spawnSync(process.execPath, [ + '-e', + main + ], { + env: { ...process.env } + }); + + if (child.status !== 0) { + console.error(child.stderr.toString()); + } + console.error(child.stdout.toString()); +} diff --git a/test/message/async_error_eval_cjs.out b/test/message/async_error_eval_cjs.out new file mode 100644 index 00000000000000..a8d89eebcb6ada --- /dev/null +++ b/test/message/async_error_eval_cjs.out @@ -0,0 +1,6 @@ +Error: test + at one ([eval]:2:9) + at two ([eval]:15:9) + at async three ([eval]:18:3) + at async four ([eval]:22:3) + at async main ([eval]:28:5) \ No newline at end of file diff --git a/test/message/async_error_eval_esm.js b/test/message/async_error_eval_esm.js new file mode 100644 index 00000000000000..33675b5a9db286 --- /dev/null +++ b/test/message/async_error_eval_esm.js @@ -0,0 +1,42 @@ +'use strict'; + +require('../common'); +const { spawnSync } = require('child_process'); + +const four = require('../common/fixtures') + .readSync('async-error.js') + .toString() + .split('\n') + .slice(2, -2) + .join('\n'); + +const main = `${four} + +async function main() { + try { + await four(); + } catch (e) { + console.log(e); + } +} + +main(); +`; + +// --eval ESM +{ + const child = spawnSync(process.execPath, [ + '--experimental-modules', + '--input-type', + 'module', + '-e', + main + ], { + env: { ...process.env } + }); + + if (child.status !== 0) { + console.error(child.stderr.toString()); + } + console.error(child.stdout.toString()); +} diff --git a/test/message/async_error_eval_esm.out b/test/message/async_error_eval_esm.out new file mode 100644 index 00000000000000..91ce0ce21cd456 --- /dev/null +++ b/test/message/async_error_eval_esm.out @@ -0,0 +1,7 @@ +Error: test + at one (eval:1:2:9) + at two (eval:1:15:9) + at processTicksAndRejections (internal/process/task_queues.js:*:*) + at async three (eval:1:18:3) + at async four (eval:1:22:3) + at async main (eval:1:28:5) diff --git a/test/message/async_error_microtask_main.js b/test/message/async_error_microtask_main.js new file mode 100644 index 00000000000000..5520c650addeac --- /dev/null +++ b/test/message/async_error_microtask_main.js @@ -0,0 +1,13 @@ +'use strict'; +require('../common'); +const four = require('../fixtures/async-error'); + +async function main() { + try { + await four(); + } catch (e) { + console.error(e); + } +} + +queueMicrotask(main); diff --git a/test/message/async_error_microtask_main.out b/test/message/async_error_microtask_main.out new file mode 100644 index 00000000000000..9512270730a976 --- /dev/null +++ b/test/message/async_error_microtask_main.out @@ -0,0 +1,6 @@ +Error: test + at one (*fixtures*async-error.js:4:9) + at two (*fixtures*async-error.js:17:9) + at async three (*fixtures*async-error.js:20:3) + at async four (*fixtures*async-error.js:24:3) + at async main (*message*async_error_microtask_main.js:7:5) diff --git a/test/message/async_error_nexttick_main.js b/test/message/async_error_nexttick_main.js new file mode 100644 index 00000000000000..ecd0531852da8f --- /dev/null +++ b/test/message/async_error_nexttick_main.js @@ -0,0 +1,13 @@ +'use strict'; +require('../common'); +const four = require('../fixtures/async-error'); + +async function main() { + try { + await four(); + } catch (e) { + console.error(e); + } +} + +process.nextTick(main); diff --git a/test/message/async_error_nexttick_main.out b/test/message/async_error_nexttick_main.out new file mode 100644 index 00000000000000..c6ac1e418086ac --- /dev/null +++ b/test/message/async_error_nexttick_main.out @@ -0,0 +1,7 @@ +Error: test + at one (*fixtures*async-error.js:4:9) + at two (*fixtures*async-error.js:17:9) + at processTicksAndRejections (internal/process/task_queues.js:*:*) + at async three (*fixtures*async-error.js:20:3) + at async four (*fixtures*async-error.js:24:3) + at async main (*message*async_error_nexttick_main.js:7:5) diff --git a/test/message/async_error_sync_esm.mjs b/test/message/async_error_sync_esm.mjs new file mode 100644 index 00000000000000..86a901a1225572 --- /dev/null +++ b/test/message/async_error_sync_esm.mjs @@ -0,0 +1,14 @@ +// Flags: --experimental-modules +/* eslint-disable node-core/required-modules */ +import '../common/index.mjs'; +import four from '../fixtures/async-error.js'; + +async function main() { + try { + await four(); + } catch (e) { + console.error(e); + } +} + +main(); diff --git a/test/message/async_error_sync_esm.out b/test/message/async_error_sync_esm.out new file mode 100644 index 00000000000000..99ce9ed0b21c2f --- /dev/null +++ b/test/message/async_error_sync_esm.out @@ -0,0 +1,7 @@ +(node:*) ExperimentalWarning: The ESM module loader is experimental. +Error: test + at one (*fixtures*async-error.js:4:9) + at two (*fixtures*async-error.js:17:9) + at async three (*fixtures*async-error.js:20:3) + at async four (*fixtures*async-error.js:24:3) + at async main (*message*async_error_sync_esm.mjs:8:5) diff --git a/test/message/async_error_sync_main.js b/test/message/async_error_sync_main.js new file mode 100644 index 00000000000000..fa33c86d2cf911 --- /dev/null +++ b/test/message/async_error_sync_main.js @@ -0,0 +1,13 @@ +'use strict'; +require('../common'); +const four = require('../fixtures/async-error'); + +async function main() { + try { + await four(); + } catch (e) { + console.error(e); + } +} + +main(); diff --git a/test/message/async_error_sync_main.out b/test/message/async_error_sync_main.out new file mode 100644 index 00000000000000..565affbaf750d9 --- /dev/null +++ b/test/message/async_error_sync_main.out @@ -0,0 +1,6 @@ +Error: test + at one (*fixtures*async-error.js:4:9) + at two (*fixtures*async-error.js:17:9) + at async three (*fixtures*async-error.js:20:3) + at async four (*fixtures*async-error.js:24:3) + at async main (*message*async_error_sync_main.js:7:5) diff --git a/test/message/events_unhandled_error_nexttick.out b/test/message/events_unhandled_error_nexttick.out index ddb13807eea5b5..f592d91b52c099 100644 --- a/test/message/events_unhandled_error_nexttick.out +++ b/test/message/events_unhandled_error_nexttick.out @@ -13,6 +13,3 @@ Error Emitted 'error' event at: at *events_unhandled_error_nexttick.js:*:* at processTicksAndRejections (internal/process/task_queues.js:*:*) - at process.runNextTicks [as _tickCallback] (internal/process/task_queues.js:*:*) - at Function.Module.runMain (internal/modules/cjs/loader.js:*:*) - at internal/main/run_main_module.js:*:* diff --git a/test/message/nexttick_throw.out b/test/message/nexttick_throw.out index f180c4ab55a7c0..d0a45b3cec0f2b 100644 --- a/test/message/nexttick_throw.out +++ b/test/message/nexttick_throw.out @@ -5,6 +5,3 @@ ReferenceError: undefined_reference_error_maker is not defined at *test*message*nexttick_throw.js:*:* at processTicksAndRejections (internal/process/task_queues.js:*:*) - at process.runNextTicks [as _tickCallback] (internal/process/task_queues.js:*:*) - at Function.Module.runMain (internal/modules/cjs/loader.js:*:*) - at internal/main/run_main_module.js:*:* diff --git a/test/message/unhandled_promise_trace_warnings.out b/test/message/unhandled_promise_trace_warnings.out index 13778fb798aa6c..c9fff40efb72bd 100644 --- a/test/message/unhandled_promise_trace_warnings.out +++ b/test/message/unhandled_promise_trace_warnings.out @@ -9,9 +9,6 @@ at * at * at * - at * - at * - at * (node:*) Error: This was rejected at * (*test*message*unhandled_promise_trace_warnings.js:*) at * @@ -25,9 +22,6 @@ at * at * at * - at * - at * - at * (node:*) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 1) at handledRejection (internal/process/promises.js:*) at promiseRejectHandler (internal/process/promises.js:*)