From b54061e53d643081a057a1512d3935351e5c7b30 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Thu, 18 Apr 2019 12:25:57 +0800 Subject: [PATCH 1/2] lib: print to stdout/stderr directly instead of using console This patch adds an internal function that prints to stdout or stderr by directly writing to the known file descriptor, and uses it internally in common cases to avoid the overhead of the console implementation. --- lib/fs.js | 20 +-------- lib/internal/fs/utils.js | 22 +++++++++- lib/internal/main/repl.js | 10 ++--- lib/internal/process/execution.js | 18 ++++----- lib/internal/util/print.js | 67 +++++++++++++++++++++++++++++++ node.gyp | 1 + 6 files changed, 103 insertions(+), 35 deletions(-) create mode 100644 lib/internal/util/print.js 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/process/execution.js b/lib/internal/process/execution.js index addd450ed3551c..93855ddbfc4b9f 100644 --- a/lib/internal/process/execution.js +++ b/lib/internal/process/execution.js @@ -35,26 +35,24 @@ 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,9 +77,9 @@ 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(); 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 3dfbe2fc7977a3..a1fc8361c5fcc9 100644 --- a/node.gyp +++ b/node.gyp @@ -183,6 +183,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', From 2332bdef7bb431c8dd075c61d209cf043c163d39 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Thu, 18 Apr 2019 12:33:58 +0800 Subject: [PATCH 2/2] benchmark: add benchmark for node -p --- benchmark/misc/print.js | 59 +++++++++++++++++++++++++++ test/benchmark/test-benchmark-misc.js | 1 + 2 files changed, 60 insertions(+) create mode 100644 benchmark/misc/print.js 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/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'