Retain (most of) Node.js internals in stack traces

This retains most of the Node.js internals in stack traces for the mini and verbose reporters. Internals are dimmed in the output. Call sites are prefixed with a small pointer.

Reporter logs are now tested for each Node.js version separately.

Stack beautification now takes place in the main process, not the workers.

Fixes #2110.

Co-authored-by: Mark Wubben <mark@novemberborn.net>

Author: bunysae

lib/beautify-stack.js

@@ -0,0 +1,69 @@
+'use strict';
+const StackUtils = require('stack-utils');
+
+const stackUtils = new StackUtils({
+	ignoredPackages: [
+		'@ava/babel',
+		'@ava/require-precompiled',
+		'@ava/typescript',
+		'append-transform',
+		'ava',
+		'empower-core',
+		'esm',
+		'nyc'
+	],
+	internals: [
+		// AVA internals, which ignoredPackages don't ignore when we run our own unit tests.
+		/\/ava\/(?:lib\/|lib\/worker\/)?[\w-]+\.js:\d+:\d+\)?$/,
+		// Only ignore Node.js internals that really are not useful for debugging.
+		...StackUtils.nodeInternals().filter(regexp => !/\(internal/.test(regexp.source)),
+		/\(internal\/process\/task_queues\.js:\d+:\d+\)$/,
+		/\(internal\/modules\/cjs\/.+?\.js:\d+:\d+\)$/,
+		/async Promise\.all \(index/,
+		/new Promise \(<anonymous>\)/
+	]
+});
+
+/*
+ * Given a string value of the format generated for the `stack` property of a
+ * V8 error object, return a string that contains only stack frame information
+ * for frames that have relevance to the consumer.
+ *
+ * For example, given the following string value:
+ *
+ * ```
+ * Error
+ *     at inner (/home/ava/ex.js:7:12)
+ *     at /home/ava/ex.js:12:5
+ *     at outer (/home/ava/ex.js:13:4)
+ *     at Object.<anonymous> (/home/ava/ex.js:14:3)
+ *     at Module._compile (module.js:570:32)
+ *     at Object.Module._extensions..js (module.js:579:10)
+ *     at Module.load (module.js:487:32)
+ *     at tryModuleLoad (module.js:446:12)
+ *     at Function.Module._load (module.js:438:3)
+ *     at Module.runMain (module.js:604:10)
+ * ```
+ *
+ * ...this function returns the following string value:
+ *
+ * ```
+ * inner (/home/ava/ex.js:7:12)
+ * /home/ava/ex.js:12:5
+ * outer (/home/ava/ex.js:13:4)
+ * Object.<anonymous> (/home/ava/ex.js:14:3)
+ * Module._compile (module.js:570:32)
+ * Object.Module._extensions..js (module.js:579:10)
+ * Module.load (module.js:487:32)
+ * tryModuleLoad (module.js:446:12)
+ * Function.Module._load (module.js:438:3)
+ * Module.runMain (module.js:604:10)
+ * ```
+ */
+module.exports = stack => {
+	if (!stack) {
+		return [];
+	}
+
+	return stackUtils.clean(stack).trim().split('\n');
+};

lib/reporters/beautify-stack.js

@@ -11,6 +11,7 @@ module.exports = {
 	duration: chalk.gray.dim,
 	errorSource: chalk.gray,
 	errorStack: chalk.gray,
+	errorStackInternal: chalk.gray.dim,
 	stack: chalk.red,
 	information: chalk.magenta
 };

lib/reporters/colors.js

@@ -9,6 +9,7 @@ const indentString = require('indent-string');
 const ora = require('ora');
 const plur = require('plur');
 const trimOffNewlines = require('trim-off-newlines');
+const beautifyStack = require('./beautify-stack');
 
 const chalk = require('../chalk').get();
 const codeExcerpt = require('../code-excerpt');
@@ -18,6 +19,8 @@ const improperUsageMessages = require('./improper-usage-messages');
 const prefixTitle = require('./prefix-title');
 const whileCorked = require('./while-corked');
 
+const nodeInternals = require('stack-utils').nodeInternals();
+
 class LineWriter extends stream.Writable {
 	constructor(dest, spinner) {
 		super();
@@ -322,13 +325,27 @@ class MiniReporter {
 
 		if (evt.err.stack) {
 			const {stack} = evt.err;
-			if (stack.includes(os.EOL)) {
+			if (stack.includes('\n')) {
 				this.lineWriter.writeLine();
-				this.lineWriter.writeLine(colors.errorStack(stack));
+				this.lineWriter.writeLine(this.formatErrorStack(evt.err));
 			}
 		}
 	}
 
+	formatErrorStack(error) {
+		if (error.shouldBeautifyStack) {
+			return beautifyStack(error.stack).map(line => {
+				if (nodeInternals.some(internal => internal.test(line))) {
+					return colors.errorStackInternal(`${figures.pointerSmall} ${line}`);
+				}
+
+				return colors.errorStack(`${figures.pointerSmall} ${line}`);
+			}).join('\n');
+		}
+
+		return error.stack;
+	}
+
 	writeLogs(evt) {
 		if (evt.logs) {
 			for (const log of evt.logs) {

lib/reporters/mini.js

@@ -7,6 +7,7 @@ const stripAnsi = require('strip-ansi');
 const supertap = require('supertap');
 const indentString = require('indent-string');
 
+const beautifyStack = require('./beautify-stack');
 const prefixTitle = require('./prefix-title');
 
 function dumpError(error) {
@@ -42,7 +43,7 @@ function dumpError(error) {
 	}
 
 	if (error.stack) {
-		object.at = error.stack;
+		object.at = error.shouldBeautifyStack ? beautifyStack(error.stack).join('\n') : error.stack;
 	}
 
 	return object;

lib/reporters/tap.js

@@ -8,6 +8,7 @@ const indentString = require('indent-string');
 const plur = require('plur');
 const prettyMs = require('pretty-ms');
 const trimOffNewlines = require('trim-off-newlines');
+const beautifyStack = require('./beautify-stack');
 
 const chalk = require('../chalk').get();
 const codeExcerpt = require('../code-excerpt');
@@ -17,6 +18,8 @@ const improperUsageMessages = require('./improper-usage-messages');
 const prefixTitle = require('./prefix-title');
 const whileCorked = require('./while-corked');
 
+const nodeInternals = require('stack-utils').nodeInternals();
+
 class LineWriter extends stream.Writable {
 	constructor(dest) {
 		super();
@@ -264,11 +267,25 @@ class VerboseReporter {
 			const {stack} = evt.err;
 			if (stack.includes('\n')) {
 				this.lineWriter.writeLine();
-				this.lineWriter.writeLine(colors.errorStack(stack));
+				this.lineWriter.writeLine(this.formatErrorStack(evt.err));
 			}
 		}
 	}
 
+	formatErrorStack(error) {
+		if (error.shouldBeautifyStack) {
+			return beautifyStack(error.stack).map(line => {
+				if (nodeInternals.some(internal => internal.test(line))) {
+					return colors.errorStackInternal(`${figures.pointerSmall} ${line}`);
+				}
+
+				return colors.errorStack(`${figures.pointerSmall} ${line}`);
+			}).join('\n');
+		}
+
+		return error.stack;
+	}
+
 	writePendingTests(evt) {
 		for (const [file, testsInFile] of evt.pendingTests) {
 			if (testsInFile.size === 0) {

lib/reporters/verbose.js

@@ -347,7 +347,7 @@ class Runner extends Emittery {
 				this.emit('stateChange', {
 					type: 'test-failed',
 					title: result.title,
-					err: serializeError('Test failure', true, result.error),
+					err: serializeError('Test failure', true, result.error, this.file),
 					duration: result.duration,
 					knownFailing: result.metadata.failing,
 					logs: result.logs

lib/runner.js

@@ -3,9 +3,9 @@ const path = require('path');
 const cleanYamlObject = require('clean-yaml-object');
 const concordance = require('concordance');
 const isError = require('is-error');
+const slash = require('slash');
 const StackUtils = require('stack-utils');
 const assert = require('./assert');
-const beautifyStack = require('./beautify-stack');
 const concordanceOptions = require('./concordance-options').default;
 
 function isAvaAssertionError(source) {
@@ -17,13 +17,29 @@ function filter(propertyName, isRoot) {
 }
 
 const stackUtils = new StackUtils();
-function extractSource(stack) {
-	if (!stack) {
+function extractSource(stack, testFile) {
+	if (!stack || !testFile) {
 		return null;
 	}
 
-	const firstStackLine = stack.split('\n')[0];
-	return stackUtils.parseLine(firstStackLine);
+	// Normalize the test file so it matches `callSite.file`.
+	const relFile = path.relative(process.cwd(), testFile);
+	const normalizedFile = process.platform === 'win32' ? slash(relFile) : relFile;
+	for (const line of stack.split('\n')) {
+		try {
+			const callSite = stackUtils.parseLine(line);
+			if (callSite.file === normalizedFile) {
+				return {
+					isDependency: false,
+					isWithinProject: true,
+					file: path.resolve(process.cwd(), callSite.file),
+					line: callSite.line
+				};
+			}
+		} catch {}
+	}
+
+	return null;
 }
 
 function buildSource(source) {
@@ -51,22 +67,19 @@ function buildSource(source) {
 	};
 }
 
-function trySerializeError(err, shouldBeautifyStack) {
-	let stack = err.savedError ? err.savedError.stack : err.stack;
-
-	if (shouldBeautifyStack) {
-		stack = beautifyStack(stack);
-	}
+function trySerializeError(err, shouldBeautifyStack, testFile) {
+	const stack = err.savedError ? err.savedError.stack : err.stack;
 
 	const retval = {
 		avaAssertionError: isAvaAssertionError(err),
 		nonErrorObject: false,
-		source: buildSource(extractSource(stack)),
-		stack
+		source: extractSource(stack, testFile),
+		stack,
+		shouldBeautifyStack
 	};
 
 	if (err.actualStack) {
-		retval.stack = shouldBeautifyStack ? beautifyStack(err.actualStack) : err.actualStack;
+		retval.stack = err.actualStack;
 	}
 
 	if (retval.avaAssertionError) {
@@ -133,7 +146,7 @@ function trySerializeError(err, shouldBeautifyStack) {
 	return retval;
 }
 
-function serializeError(origin, shouldBeautifyStack, err) {
+function serializeError(origin, shouldBeautifyStack, err, testFile) {
 	if (!isError(err)) {
 		return {
 			avaAssertionError: false,
@@ -143,8 +156,8 @@ function serializeError(origin, shouldBeautifyStack, err) {
 	}
 
 	try {
-		return trySerializeError(err, shouldBeautifyStack);
-	} catch (_) {
+		return trySerializeError(err, shouldBeautifyStack, testFile);
+	} catch {
 		const replacement = new Error(`${origin}: Could not serialize error`);
 		return {
 			avaAssertionError: false,