From e6341a4a732a1edde8cac5f5ef4ca6ac93f053de Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Wed, 6 Mar 2019 12:33:09 +0100 Subject: [PATCH 1/3] lib: move format and formatWithOptions into internal/util/inspect.js So these can be required without requiring the whole `util.js`. --- lib/internal/util/inspect.js | 133 +++++++++++++++++++++++++++++++++- lib/util.js | 134 ++--------------------------------- 2 files changed, 137 insertions(+), 130 deletions(-) diff --git a/lib/internal/util/inspect.js b/lib/internal/util/inspect.js index c1fc1944f136b2..b30a4e4a4ae53a 100644 --- a/lib/internal/util/inspect.js +++ b/lib/internal/util/inspect.js @@ -1363,8 +1363,139 @@ function reduceToSingleString(ctx, output, base, braces, combine = false) { return `${braces[0]}${ln}${join(output, `,\n${indentation} `)} ${braces[1]}`; } +const emptyOptions = {}; +function format(...args) { + return formatWithOptions(emptyOptions, ...args); +} + + +let CIRCULAR_ERROR_MESSAGE; +function tryStringify(arg) { + try { + return JSON.stringify(arg); + } catch (err) { + // Populate the circular error message lazily + if (!CIRCULAR_ERROR_MESSAGE) { + try { + const a = {}; a.a = a; JSON.stringify(a); + } catch (err) { + CIRCULAR_ERROR_MESSAGE = err.message; + } + } + if (err.name === 'TypeError' && err.message === CIRCULAR_ERROR_MESSAGE) + return '[Circular]'; + throw err; + } +} + +function formatWithOptions(inspectOptions, ...args) { + const first = args[0]; + let a = 0; + let str = ''; + let join = ''; + + if (typeof first === 'string') { + if (args.length === 1) { + return first; + } + let tempStr; + let lastPos = 0; + + for (var i = 0; i < first.length - 1; i++) { + if (first.charCodeAt(i) === 37) { // '%' + const nextChar = first.charCodeAt(++i); + if (a + 1 !== args.length) { + switch (nextChar) { + case 115: // 's' + tempStr = String(args[++a]); + break; + case 106: // 'j' + tempStr = tryStringify(args[++a]); + break; + case 100: // 'd' + const tempNum = args[++a]; + // eslint-disable-next-line valid-typeof + if (typeof tempNum === 'bigint') { + tempStr = `${tempNum}n`; + } else if (typeof tempNum === 'symbol') { + tempStr = 'NaN'; + } else { + tempStr = `${Number(tempNum)}`; + } + break; + case 79: // 'O' + tempStr = inspect(args[++a], inspectOptions); + break; + case 111: // 'o' + { + tempStr = inspect(args[++a], { + ...inspectOptions, + showHidden: true, + showProxy: true, + depth: 4 + }); + break; + } + case 105: // 'i' + const tempInteger = args[++a]; + // eslint-disable-next-line valid-typeof + if (typeof tempInteger === 'bigint') { + tempStr = `${tempInteger}n`; + } else if (typeof tempInteger === 'symbol') { + tempStr = 'NaN'; + } else { + tempStr = `${parseInt(tempInteger)}`; + } + break; + case 102: // 'f' + const tempFloat = args[++a]; + if (typeof tempFloat === 'symbol') { + tempStr = 'NaN'; + } else { + tempStr = `${parseFloat(tempFloat)}`; + } + break; + case 37: // '%' + str += first.slice(lastPos, i); + lastPos = i + 1; + continue; + default: // Any other character is not a correct placeholder + continue; + } + if (lastPos !== i - 1) { + str += first.slice(lastPos, i - 1); + } + str += tempStr; + lastPos = i + 1; + } else if (nextChar === 37) { + str += first.slice(lastPos, i); + lastPos = i + 1; + } + } + } + if (lastPos !== 0) { + a++; + join = ' '; + if (lastPos < first.length) { + str += first.slice(lastPos); + } + } + } + + while (a < args.length) { + const value = args[a]; + str += join; + str += typeof value !== 'string' ? inspect(value, inspectOptions) : value; + join = ' '; + a++; + } + return str; +} + module.exports = { inspect, formatProperty, - kObjectType + kObjectType, + format, + formatWithOptions }; diff --git a/lib/util.js b/lib/util.js index f422a1f41099b8..98e41e5a3750cb 100644 --- a/lib/util.js +++ b/lib/util.js @@ -22,7 +22,11 @@ 'use strict'; const errors = require('internal/errors'); -const { inspect } = require('internal/util/inspect'); +const { + format, + formatWithOptions, + inspect +} = require('internal/util/inspect'); const { ERR_FALSY_VALUE_REJECTION, ERR_INVALID_ARG_TYPE, @@ -46,136 +50,8 @@ function uncurryThis(func) { } const objectToString = uncurryThis(Object.prototype.toString); -let CIRCULAR_ERROR_MESSAGE; let internalDeepEqual; -function tryStringify(arg) { - try { - return JSON.stringify(arg); - } catch (err) { - // Populate the circular error message lazily - if (!CIRCULAR_ERROR_MESSAGE) { - try { - const a = {}; a.a = a; JSON.stringify(a); - } catch (err) { - CIRCULAR_ERROR_MESSAGE = err.message; - } - } - if (err.name === 'TypeError' && err.message === CIRCULAR_ERROR_MESSAGE) - return '[Circular]'; - throw err; - } -} - -const emptyOptions = {}; -function format(...args) { - return formatWithOptions(emptyOptions, ...args); -} - -function formatWithOptions(inspectOptions, ...args) { - const first = args[0]; - let a = 0; - let str = ''; - let join = ''; - - if (typeof first === 'string') { - if (args.length === 1) { - return first; - } - let tempStr; - let lastPos = 0; - - for (var i = 0; i < first.length - 1; i++) { - if (first.charCodeAt(i) === 37) { // '%' - const nextChar = first.charCodeAt(++i); - if (a + 1 !== args.length) { - switch (nextChar) { - case 115: // 's' - tempStr = String(args[++a]); - break; - case 106: // 'j' - tempStr = tryStringify(args[++a]); - break; - case 100: // 'd' - const tempNum = args[++a]; - // eslint-disable-next-line valid-typeof - if (typeof tempNum === 'bigint') { - tempStr = `${tempNum}n`; - } else if (typeof tempNum === 'symbol') { - tempStr = 'NaN'; - } else { - tempStr = `${Number(tempNum)}`; - } - break; - case 79: // 'O' - tempStr = inspect(args[++a], inspectOptions); - break; - case 111: // 'o' - { - tempStr = inspect(args[++a], { - ...inspectOptions, - showHidden: true, - showProxy: true, - depth: 4 - }); - break; - } - case 105: // 'i' - const tempInteger = args[++a]; - // eslint-disable-next-line valid-typeof - if (typeof tempInteger === 'bigint') { - tempStr = `${tempInteger}n`; - } else if (typeof tempInteger === 'symbol') { - tempStr = 'NaN'; - } else { - tempStr = `${parseInt(tempInteger)}`; - } - break; - case 102: // 'f' - const tempFloat = args[++a]; - if (typeof tempFloat === 'symbol') { - tempStr = 'NaN'; - } else { - tempStr = `${parseFloat(tempFloat)}`; - } - break; - case 37: // '%' - str += first.slice(lastPos, i); - lastPos = i + 1; - continue; - default: // Any other character is not a correct placeholder - continue; - } - if (lastPos !== i - 1) { - str += first.slice(lastPos, i - 1); - } - str += tempStr; - lastPos = i + 1; - } else if (nextChar === 37) { - str += first.slice(lastPos, i); - lastPos = i + 1; - } - } - } - if (lastPos !== 0) { - a++; - join = ' '; - if (lastPos < first.length) { - str += first.slice(lastPos); - } - } - } - - while (a < args.length) { - const value = args[a]; - str += join; - str += typeof value !== 'string' ? inspect(value, inspectOptions) : value; - join = ' '; - a++; - } - return str; -} - const debugs = {}; let debugEnvRegex = /^$/; if (process.env.NODE_DEBUG) { From 1b12c168d9b6822bdc4eb030d0e59aca6cf44d67 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Wed, 6 Mar 2019 12:53:04 +0100 Subject: [PATCH 2/3] process: call prepareMainThreadExecution in all main thread scripts --- lib/internal/main/inspect.js | 6 ++++++ lib/internal/main/print_bash_completion.js | 6 ++++++ lib/internal/main/print_help.js | 6 ++++++ lib/internal/main/prof_process.js | 5 +++++ 4 files changed, 23 insertions(+) diff --git a/lib/internal/main/inspect.js b/lib/internal/main/inspect.js index 7376f8984b13e1..f6777fe852bcfc 100644 --- a/lib/internal/main/inspect.js +++ b/lib/internal/main/inspect.js @@ -2,6 +2,12 @@ // `node inspect ...` or `node debug ...` +const { + prepareMainThreadExecution +} = require('internal/bootstrap/pre_execution'); + +prepareMainThreadExecution(); + if (process.argv[1] === 'debug') { process.emitWarning( '`node debug` is deprecated. Please use `node inspect` instead.', diff --git a/lib/internal/main/print_bash_completion.js b/lib/internal/main/print_bash_completion.js index 225ed3d2221c00..41ebf0c6063e5f 100644 --- a/lib/internal/main/print_bash_completion.js +++ b/lib/internal/main/print_bash_completion.js @@ -1,6 +1,10 @@ 'use strict'; const { options, aliases } = require('internal/options'); +const { + prepareMainThreadExecution +} = require('internal/bootstrap/pre_execution'); + function print(stream) { const all_opts = [...options.keys(), ...aliases.keys()]; @@ -18,6 +22,8 @@ function print(stream) { complete -F _node_complete node node_g`); } +prepareMainThreadExecution(); + markBootstrapComplete(); print(process.stdout); diff --git a/lib/internal/main/print_help.js b/lib/internal/main/print_help.js index ef1cb9ce4bb880..d34c412d1686b0 100644 --- a/lib/internal/main/print_help.js +++ b/lib/internal/main/print_help.js @@ -3,6 +3,10 @@ const { types } = internalBinding('options'); const hasCrypto = Boolean(process.versions.openssl); +const { + prepareMainThreadExecution +} = require('internal/bootstrap/pre_execution'); + const typeLookup = []; for (const key of Object.keys(types)) typeLookup[types[key]] = key; @@ -171,6 +175,8 @@ function print(stream) { stream.write('\nDocumentation can be found at https://nodejs.org/\n'); } +prepareMainThreadExecution(); + markBootstrapComplete(); print(process.stdout); diff --git a/lib/internal/main/prof_process.js b/lib/internal/main/prof_process.js index a1143cb201e79c..bd835bfe630fa4 100644 --- a/lib/internal/main/prof_process.js +++ b/lib/internal/main/prof_process.js @@ -1,4 +1,9 @@ 'use strict'; +const { + prepareMainThreadExecution +} = require('internal/bootstrap/pre_execution'); + +prepareMainThreadExecution(); markBootstrapComplete(); require('internal/v8_prof_processor'); From 83f1c582fcf3c043e0cffd4f043aa960daf130d5 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Wed, 6 Mar 2019 12:54:12 +0100 Subject: [PATCH 3/3] lib: explicitly initialize debuglog during bootstrap This patch splits the implementation of util.debuglog into a separate file and explicitly initialize it during pre-execution since the initialization depends on environment variables. Also delays the call to `debuglog` in modules that are loaded during bootstrap to make sure we only access the environment variable during pre-execution. --- lib/_stream_readable.js | 11 ++++- lib/internal/bootstrap/pre_execution.js | 7 ++++ lib/internal/main/worker_thread.js | 4 ++ lib/internal/modules/cjs/loader.js | 8 +++- lib/internal/util/debuglog.js | 54 +++++++++++++++++++++++++ lib/internal/worker.js | 10 ++++- lib/internal/worker/io.js | 9 ++++- lib/timers.js | 10 ++++- lib/util.js | 40 +----------------- node.gyp | 1 + 10 files changed, 108 insertions(+), 46 deletions(-) create mode 100644 lib/internal/util/debuglog.js diff --git a/lib/_stream_readable.js b/lib/_stream_readable.js index 85d1fb0c33b9af..957f232b6348f2 100644 --- a/lib/_stream_readable.js +++ b/lib/_stream_readable.js @@ -27,8 +27,15 @@ Readable.ReadableState = ReadableState; const EE = require('events'); const Stream = require('stream'); const { Buffer } = require('buffer'); -const util = require('util'); -const debug = util.debuglog('stream'); + +let debuglog; +function debug(...args) { + if (!debuglog) { + debuglog = require('internal/util/debuglog').debuglog('stream'); + } + debuglog(...args); +} + const BufferList = require('internal/streams/buffer_list'); const destroyImpl = require('internal/streams/destroy'); const { getHighWaterMark } = require('internal/streams/state'); diff --git a/lib/internal/bootstrap/pre_execution.js b/lib/internal/bootstrap/pre_execution.js index 992c0c1983e722..ee158810d6d7b0 100644 --- a/lib/internal/bootstrap/pre_execution.js +++ b/lib/internal/bootstrap/pre_execution.js @@ -8,6 +8,8 @@ let traceEventsAsyncHook; function prepareMainThreadExecution() { setupTraceCategoryState(); + setupDebugEnv(); + // Only main thread receives signals. setupSignalHandlers(); @@ -52,6 +54,10 @@ function initializeReport() { }); } +function setupDebugEnv() { + require('internal/util/debuglog').initializeDebugEnv(process.env.NODE_DEBUG); +} + function setupSignalHandlers() { const { createSignalHandlers @@ -231,6 +237,7 @@ function loadPreloadModules() { } module.exports = { + setupDebugEnv, prepareMainThreadExecution, initializeDeprecations, initializeESMLoader, diff --git a/lib/internal/main/worker_thread.js b/lib/internal/main/worker_thread.js index 0dc1b61ef94f45..40064546c35be1 100644 --- a/lib/internal/main/worker_thread.js +++ b/lib/internal/main/worker_thread.js @@ -4,6 +4,7 @@ // message port. const { + setupDebugEnv, initializeDeprecations, initializeESMLoader, initializeFrozenIntrinsics, @@ -37,6 +38,9 @@ const { } = require('internal/process/execution'); const publicWorker = require('worker_threads'); + +setupDebugEnv(); + const debug = require('util').debuglog('worker'); debug(`[${threadId}] is setting up worker child environment`); diff --git a/lib/internal/modules/cjs/loader.js b/lib/internal/modules/cjs/loader.js index 46b101f3a77df6..83ab464b40fd9c 100644 --- a/lib/internal/modules/cjs/loader.js +++ b/lib/internal/modules/cjs/loader.js @@ -174,7 +174,13 @@ Object.defineProperty(Module, 'wrapper', { } }); -const debug = util.debuglog('module'); +let debuglog; +function debug(...args) { + if (!debuglog) { + debuglog = require('internal/util/debuglog').debuglog('module'); + } + debuglog(...args); +} Module._debug = util.deprecate(debug, 'Module._debug is deprecated.', 'DEP0077'); diff --git a/lib/internal/util/debuglog.js b/lib/internal/util/debuglog.js new file mode 100644 index 00000000000000..769328ac9d8453 --- /dev/null +++ b/lib/internal/util/debuglog.js @@ -0,0 +1,54 @@ +'use strict'; + +const { format } = require('internal/util/inspect'); + +// `debugs` is deliberately initialized to undefined so any call to +// debuglog() before initializeDebugEnv() is called will throw. +let debugs; + +let debugEnvRegex = /^$/; + +// `debugEnv` is initial value of process.env.NODE_DEBUG +function initializeDebugEnv(debugEnv) { + debugs = {}; + if (debugEnv) { + debugEnv = debugEnv.replace(/[|\\{}()[\]^$+?.]/g, '\\$&') + .replace(/\*/g, '.*') + .replace(/,/g, '$|^') + .toUpperCase(); + debugEnvRegex = new RegExp(`^${debugEnv}$`, 'i'); + } +} + +// Emits warning when user sets +// NODE_DEBUG=http or NODE_DEBUG=http2. +function emitWarningIfNeeded(set) { + if ('HTTP' === set || 'HTTP2' === set) { + process.emitWarning('Setting the NODE_DEBUG environment variable ' + + 'to \'' + set.toLowerCase() + '\' can expose sensitive ' + + 'data (such as passwords, tokens and authentication headers) ' + + 'in the resulting log.'); + } +} + +function debuglog(set) { + set = set.toUpperCase(); + if (!debugs[set]) { + if (debugEnvRegex.test(set)) { + const pid = process.pid; + emitWarningIfNeeded(set); + debugs[set] = function debug(...args) { + const msg = format(...args); + console.error('%s %d: %s', set, pid, msg); + }; + } else { + debugs[set] = function debug() {}; + } + } + return debugs[set]; +} + +module.exports = { + debuglog, + initializeDebugEnv +}; diff --git a/lib/internal/worker.js b/lib/internal/worker.js index c81e1a5cd72771..02f6661b548e5b 100644 --- a/lib/internal/worker.js +++ b/lib/internal/worker.js @@ -3,7 +3,7 @@ const EventEmitter = require('events'); const assert = require('internal/assert'); const path = require('path'); -const util = require('util'); + const { ERR_WORKER_PATH, ERR_WORKER_UNSERIALIZABLE_ERROR, @@ -45,7 +45,13 @@ const kOnCouldNotSerializeErr = Symbol('kOnCouldNotSerializeErr'); const kOnErrorMessage = Symbol('kOnErrorMessage'); const kParentSideStdio = Symbol('kParentSideStdio'); -const debug = util.debuglog('worker'); +let debuglog; +function debug(...args) { + if (!debuglog) { + debuglog = require('internal/util/debuglog').debuglog('worker'); + } + debuglog(...args); +} class Worker extends EventEmitter { constructor(filename, options = {}) { diff --git a/lib/internal/worker/io.js b/lib/internal/worker/io.js index e88991aaaba0f0..387dc9df74efed 100644 --- a/lib/internal/worker/io.js +++ b/lib/internal/worker/io.js @@ -15,7 +15,14 @@ const { threadId } = internalBinding('worker'); const { Readable, Writable } = require('stream'); const EventEmitter = require('events'); const util = require('util'); -const debug = util.debuglog('worker'); + +let debuglog; +function debug(...args) { + if (!debuglog) { + debuglog = require('internal/util/debuglog').debuglog('worker'); + } + debuglog(...args); +} const kIncrementsPortRef = Symbol('kIncrementsPortRef'); const kName = Symbol('kName'); diff --git a/lib/timers.js b/lib/timers.js index a7c795701e97f8..d57b1ceb3eee1d 100644 --- a/lib/timers.js +++ b/lib/timers.js @@ -42,7 +42,15 @@ const { const internalUtil = require('internal/util'); const util = require('util'); const { ERR_INVALID_CALLBACK } = require('internal/errors').codes; -const debug = util.debuglog('timer'); + +let debuglog; +function debug(...args) { + if (!debuglog) { + debuglog = require('internal/util/debuglog').debuglog('timer'); + } + debuglog(...args); +} + const { destroyHooksExist, // The needed emit*() functions. diff --git a/lib/util.js b/lib/util.js index 98e41e5a3750cb..8c4c0cb098c990 100644 --- a/lib/util.js +++ b/lib/util.js @@ -27,6 +27,7 @@ const { formatWithOptions, inspect } = require('internal/util/inspect'); +const { debuglog } = require('internal/util/debuglog'); const { ERR_FALSY_VALUE_REJECTION, ERR_INVALID_ARG_TYPE, @@ -52,45 +53,6 @@ const objectToString = uncurryThis(Object.prototype.toString); let internalDeepEqual; -const debugs = {}; -let debugEnvRegex = /^$/; -if (process.env.NODE_DEBUG) { - let debugEnv = process.env.NODE_DEBUG; - debugEnv = debugEnv.replace(/[|\\{}()[\]^$+?.]/g, '\\$&') - .replace(/\*/g, '.*') - .replace(/,/g, '$|^') - .toUpperCase(); - debugEnvRegex = new RegExp(`^${debugEnv}$`, 'i'); -} - -// Emits warning when user sets -// NODE_DEBUG=http or NODE_DEBUG=http2. -function emitWarningIfNeeded(set) { - if ('HTTP' === set || 'HTTP2' === set) { - process.emitWarning('Setting the NODE_DEBUG environment variable ' + - 'to \'' + set.toLowerCase() + '\' can expose sensitive ' + - 'data (such as passwords, tokens and authentication headers) ' + - 'in the resulting log.'); - } -} - -function debuglog(set) { - set = set.toUpperCase(); - if (!debugs[set]) { - if (debugEnvRegex.test(set)) { - const pid = process.pid; - emitWarningIfNeeded(set); - debugs[set] = function debug() { - const msg = exports.format.apply(exports, arguments); - console.error('%s %d: %s', set, pid, msg); - }; - } else { - debugs[set] = function debug() {}; - } - } - return debugs[set]; -} - function isBoolean(arg) { return typeof arg === 'boolean'; } diff --git a/node.gyp b/node.gyp index c005470cef1e23..c22cb3c4a086b1 100644 --- a/node.gyp +++ b/node.gyp @@ -185,6 +185,7 @@ 'lib/internal/url.js', 'lib/internal/util.js', 'lib/internal/util/comparisons.js', + 'lib/internal/util/debuglog.js', 'lib/internal/util/inspect.js', 'lib/internal/util/inspector.js', 'lib/internal/util/types.js',