From 0bf97958e9d73e9e5a3695ea84b9e508d692890c Mon Sep 17 00:00:00 2001 From: Ruben Bridgewater Date: Thu, 2 Dec 2021 07:01:50 +0100 Subject: [PATCH] util: always visualize cause property in errors during inspection MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit While inspecting errors, always visualize the cause. That property is non-enumerable by default while being useful in general for debugging. Duplicated stack frames are hidden. Signed-off-by: Ruben Bridgewater PR-URL: https://github.com/nodejs/node/pull/41002 Fixes: https://github.com/nodejs/node/issues/40859 Fixes: https://github.com/nodejs/node/issues/38725 Reviewed-By: James M Snell Reviewed-By: Michaël Zasso --- lib/internal/util/inspect.js | 124 +++++++++++++++----- test/message/util-inspect-error-cause.js | 31 +++++ test/message/util-inspect-error-cause.out | 136 ++++++++++++++++++++++ 3 files changed, 261 insertions(+), 30 deletions(-) create mode 100644 test/message/util-inspect-error-cause.js create mode 100644 test/message/util-inspect-error-cause.out diff --git a/lib/internal/util/inspect.js b/lib/internal/util/inspect.js index 7dae71038e5409..11d5400a278f40 100644 --- a/lib/internal/util/inspect.js +++ b/lib/internal/util/inspect.js @@ -1162,25 +1162,58 @@ function getFunctionBase(value, constructor, tag) { return base; } -function formatError(err, constructor, tag, ctx, keys) { - const name = err.name != null ? String(err.name) : 'Error'; - let len = name.length; - let stack = err.stack ? String(err.stack) : ErrorPrototypeToString(err); +function identicalSequenceRange(a, b) { + for (let i = 0; i < a.length - 3; i++) { + // Find the first entry of b that matches the current entry of a. + const pos = b.indexOf(a[i]); + if (pos !== -1) { + const rest = b.length - pos; + if (rest > 3) { + let len = 1; + const maxLen = MathMin(a.length - i, rest); + // Count the number of consecutive entries. + while (maxLen > len && a[i + len] === b[pos + len]) { + len++; + } + if (len > 3) { + return { len, offset: i }; + } + } + } + } - // Do not "duplicate" error properties that are already included in the output - // otherwise. - if (!ctx.showHidden && keys.length !== 0) { - for (const name of ['name', 'message', 'stack']) { - const index = keys.indexOf(name); - // Only hide the property in case it's part of the original stack - if (index !== -1 && stack.includes(err[name])) { - keys.splice(index, 1); + return { len: 0, offset: 0 }; +} + +function getStackString(error) { + return error.stack ? String(error.stack) : ErrorPrototypeToString(error); +} + +function getStackFrames(ctx, err, stack) { + const frames = stack.split('\n'); + + // Remove stack frames identical to frames in cause. + if (err.cause) { + const causeStack = getStackString(err.cause); + const causeStackStart = causeStack.indexOf('\n at'); + if (causeStackStart !== -1) { + const causeFrames = causeStack.slice(causeStackStart + 1).split('\n'); + const { len, offset } = identicalSequenceRange(frames, causeFrames); + if (len > 0) { + const skipped = len - 2; + const msg = ` ... ${skipped} lines matching cause stack trace ...`; + frames.splice(offset + 1, skipped, ctx.stylize(msg, 'undefined')); } } } + return frames; +} +function improveStack(stack, constructor, name, tag) { // A stack trace may contain arbitrary data. Only manipulate the output // for "regular errors" (errors that "look normal") for now. + let len = name.length; + if (constructor === null || (name.endsWith('Error') && stack.startsWith(name) && @@ -1206,6 +1239,33 @@ function formatError(err, constructor, tag, ctx, keys) { } } } + return stack; +} + +function removeDuplicateErrorKeys(ctx, keys, err, stack) { + if (!ctx.showHidden && keys.length !== 0) { + for (const name of ['name', 'message', 'stack']) { + const index = keys.indexOf(name); + // Only hide the property in case it's part of the original stack + if (index !== -1 && stack.includes(err[name])) { + keys.splice(index, 1); + } + } + } +} + +function formatError(err, constructor, tag, ctx, keys) { + const name = err.name != null ? String(err.name) : 'Error'; + let stack = getStackString(err); + + removeDuplicateErrorKeys(ctx, keys, err, stack); + + if (err.cause && (keys.length === 0 || !keys.includes('cause'))) { + keys.push('cause'); + } + + stack = improveStack(stack, constructor, name, tag); + // Ignore the error message if it's contained in the stack. let pos = (err.message && stack.indexOf(err.message)) || -1; if (pos !== -1) @@ -1214,27 +1274,31 @@ function formatError(err, constructor, tag, ctx, keys) { const stackStart = stack.indexOf('\n at', pos); if (stackStart === -1) { stack = `[${stack}]`; - } else if (ctx.colors) { - // Highlight userland code and node modules. + } else { let newStack = stack.slice(0, stackStart); - const lines = stack.slice(stackStart + 1).split('\n'); - for (const line of lines) { - const core = line.match(coreModuleRegExp); - if (core !== null && NativeModule.exists(core[1])) { - newStack += `\n${ctx.stylize(line, 'undefined')}`; - } else { - // This adds underscores to all node_modules to quickly identify them. - let nodeModule; - newStack += '\n'; - let pos = 0; - while (nodeModule = nodeModulesRegExp.exec(line)) { - // '/node_modules/'.length === 14 - newStack += line.slice(pos, nodeModule.index + 14); - newStack += ctx.stylize(nodeModule[1], 'module'); - pos = nodeModule.index + nodeModule[0].length; + const lines = getStackFrames(ctx, err, stack.slice(stackStart + 1)); + if (ctx.colors) { + // Highlight userland code and node modules. + for (const line of lines) { + const core = line.match(coreModuleRegExp); + if (core !== null && NativeModule.exists(core[1])) { + newStack += `\n${ctx.stylize(line, 'undefined')}`; + } else { + // This adds underscores to all node_modules to quickly identify them. + let nodeModule; + newStack += '\n'; + let pos = 0; + while (nodeModule = nodeModulesRegExp.exec(line)) { + // '/node_modules/'.length === 14 + newStack += line.slice(pos, nodeModule.index + 14); + newStack += ctx.stylize(nodeModule[1], 'module'); + pos = nodeModule.index + nodeModule[0].length; + } + newStack += pos === 0 ? line : line.slice(pos); } - newStack += pos === 0 ? line : line.slice(pos); } + } else { + newStack += `\n${lines.join('\n')}`; } stack = newStack; } diff --git a/test/message/util-inspect-error-cause.js b/test/message/util-inspect-error-cause.js new file mode 100644 index 00000000000000..f6318357974cb6 --- /dev/null +++ b/test/message/util-inspect-error-cause.js @@ -0,0 +1,31 @@ +'use strict'; + +require('../common'); + +const { inspect } = require('util'); + +class FoobarError extends Error { + status = 'Feeling good'; +} + +const cause1 = new TypeError('Inner error'); +const cause2 = new FoobarError('Individual message', { cause: cause1 }); +cause2.extraProperties = 'Yes!'; +const cause3 = new Error('Stack causes', { cause: cause2 }); + +process.nextTick(() => { + const error = new RangeError('New Stack Frames', { cause: cause2 }); + const error2 = new RangeError('New Stack Frames', { cause: cause3 }); + + inspect.defaultOptions.colors = true; + + console.log(inspect(error)); + console.log(inspect(cause3)); + console.log(inspect(error2)); + + inspect.defaultOptions.colors = false; + + console.log(inspect(error)); + console.log(inspect(cause3)); + console.log(inspect(error2)); +}); diff --git a/test/message/util-inspect-error-cause.out b/test/message/util-inspect-error-cause.out new file mode 100644 index 00000000000000..bd8673ae25c031 --- /dev/null +++ b/test/message/util-inspect-error-cause.out @@ -0,0 +1,136 @@ +RangeError: New Stack Frames + at * +*[90m at *[39m { + [cause]: FoobarError: Individual message + at * + *[90m at *[39m + *[90m ... 4 lines matching cause stack trace ...*[39m + *[90m at *[39m { + status: *[32m'Feeling good'*[39m, + extraProperties: *[32m'Yes!'*[39m, + [cause]: TypeError: Inner error + at * + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + } +} +Error: Stack causes + at * +*[90m at *[39m +*[90m ... 4 lines matching cause stack trace ...*[39m +*[90m at *[39m { + [cause]: FoobarError: Individual message + at * + *[90m at *[39m + *[90m ... 4 lines matching cause stack trace ...*[39m + *[90m at *[39m { + status: *[32m'Feeling good'*[39m, + extraProperties: *[32m'Yes!'*[39m, + [cause]: TypeError: Inner error + at * + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + } +} +RangeError: New Stack Frames + at * +*[90m at *[39m { + [cause]: Error: Stack causes + at * + *[90m at *[39m + *[90m ... 4 lines matching cause stack trace ...*[39m + *[90m at *[39m { + [cause]: FoobarError: Individual message + at * + *[90m at *[39m + *[90m ... 4 lines matching cause stack trace ...*[39m + *[90m at *[39m { + status: *[32m'Feeling good'*[39m, + extraProperties: *[32m'Yes!'*[39m, + [cause]: TypeError: Inner error + at * + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + *[90m at *[39m + } + } +} +RangeError: New Stack Frames + at * + at * { + [cause]: FoobarError: Individual message + at * + at * + ... 4 lines matching cause stack trace ... + at * { + status: 'Feeling good', + extraProperties: 'Yes!', + [cause]: TypeError: Inner error + at * + at * + at * + at * + at * + at * + at * + } +} +Error: Stack causes + at * + at * + ... 4 lines matching cause stack trace ... + at * { + [cause]: FoobarError: Individual message + at * + at * + ... 4 lines matching cause stack trace ... + at * + status: 'Feeling good', + extraProperties: 'Yes!', + [cause]: TypeError: Inner error + at * + at * + at * + at * + at * + at * + at * + } +} +RangeError: New Stack Frames + at * + at * { + [cause]: Error: Stack causes + at * + at * + ... 4 lines matching cause stack trace ... + at * { + [cause]: FoobarError: Individual message + at * + at * + ... 4 lines matching cause stack trace ... + at * { + status: 'Feeling good', + extraProperties: 'Yes!', + [cause]: TypeError: Inner error + at * + at * + at * + at * + at * + at * + at * + } + } +}