test_runner: expose location of tests

This commit adds each test's line and column number to the reporter
output. This will aid in debugging test suite failures when error
stacks are not helpful, test suites are large, or tests have the
same name. This data is also exposed on the spec reporter.

This commit also replaces the filename that was previously being
reported, with the filename where the test actually exists. These
are normally correct, but could be wrong if tests were run from
a file other than the user's entrypoint.

PR-URL: nodejs#48975
Fixes: nodejs#48457
Reviewed-By: Yagiz Nizipli <[email protected]>
Reviewed-By: Matteo Collina <[email protected]>
Reviewed-By: Chemi Atlow <[email protected]>
Reviewed-By: Moshe Atlow <[email protected]>

doc/api/test.md

@@ -2034,8 +2034,12 @@ Emitted when code coverage is enabled and all tests have completed.
 ### Event: `'test:dequeue'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `file` {string|undefined} The path of the test file,
     `undefined` if test was run through the REPL.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `name` {string} The test name.
   * `nesting` {number} The nesting level of the test.
 
@@ -2044,8 +2048,12 @@ Emitted when a test is dequeued, right before it is executed.
 ### Event: `'test:diagnostic'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `file` {string|undefined} The path of the test file,
     `undefined` if test was run through the REPL.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `message` {string} The diagnostic message.
   * `nesting` {number} The nesting level of the test.
 
@@ -2054,8 +2062,12 @@ Emitted when [`context.diagnostic`][] is called.
 ### Event: `'test:enqueue'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `file` {string|undefined} The path of the test file,
     `undefined` if test was run through the REPL.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `name` {string} The test name.
   * `nesting` {number} The nesting level of the test.
 
@@ -2064,6 +2076,8 @@ Emitted when a test is enqueued for execution.
 ### Event: `'test:fail'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `details` {Object} Additional execution metadata.
     * `duration_ms` {number} The duration of the test in milliseconds.
     * `error` {Error} An error wrapping the error thrown by the test.
@@ -2072,6 +2086,8 @@ Emitted when a test is enqueued for execution.
       this is a suite.
   * `file` {string|undefined} The path of the test file,
     `undefined` if test was run through the REPL.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `name` {string} The test name.
   * `nesting` {number} The nesting level of the test.
   * `testNumber` {number} The ordinal number of the test.
@@ -2083,12 +2099,16 @@ Emitted when a test fails.
 ### Event: `'test:pass'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `details` {Object} Additional execution metadata.
     * `duration_ms` {number} The duration of the test in milliseconds.
     * `type` {string|undefined} The type of the test, used to denote whether
       this is a suite.
   * `file` {string|undefined} The path of the test file,
     `undefined` if test was run through the REPL.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `name` {string} The test name.
   * `nesting` {number} The nesting level of the test.
   * `testNumber` {number} The ordinal number of the test.
@@ -2100,8 +2120,12 @@ Emitted when a test passes.
 ### Event: `'test:plan'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `file` {string|undefined} The path of the test file,
     `undefined` if test was run through the REPL.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `nesting` {number} The nesting level of the test.
   * `count` {number} The number of subtests that have ran.
 
@@ -2110,8 +2134,12 @@ Emitted when all subtests have completed for a given test.
 ### Event: `'test:start'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `file` {string|undefined} The path of the test file,
     `undefined` if test was run through the REPL.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `name` {string} The test name.
   * `nesting` {number} The nesting level of the test.
 
@@ -2122,7 +2150,11 @@ defined.
 ### Event: `'test:stderr'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `file` {string} The path of the test file.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `message` {string} The message written to `stderr`.
 
 Emitted when a running test writes to `stderr`.
@@ -2131,7 +2163,11 @@ This event is only emitted if `--test` flag is passed.
 ### Event: `'test:stdout'`
 
 * `data` {Object}
+  * `column` {number|undefined} The column number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `file` {string} The path of the test file.
+  * `line` {number|undefined} The line number where the test is defined, or
+    `undefined` if the test was run through the REPL.
   * `message` {string} The message written to `stdout`.
 
 Emitted when a running test writes to `stdout`.

lib/internal/test_runner/harness.js

@@ -5,6 +5,7 @@ const {
   PromiseResolve,
   SafeMap,
 } = primordials;
+const { getCallerLocation } = internalBinding('util');
 const {
   createHook,
   executionAsyncId,
@@ -217,17 +218,38 @@ function runInParentContext(Factory) {
     return PromiseResolve();
   }
 
-  const test = (name, options, fn) => run(name, options, fn);
+  const test = (name, options, fn) => {
+    const overrides = {
+      __proto__: null,
+      loc: getCallerLocation(),
+    };
+
+    return run(name, options, fn, overrides);
+  };
   ArrayPrototypeForEach(['skip', 'todo', 'only'], (keyword) => {
-    test[keyword] = (name, options, fn) => run(name, options, fn, { __proto__: null, [keyword]: true });
+    test[keyword] = (name, options, fn) => {
+      const overrides = {
+        __proto__: null,
+        [keyword]: true,
+        loc: getCallerLocation(),
+      };
+
+      return run(name, options, fn, overrides);
+    };
   });
   return test;
 }
 
 function hook(hook) {
   return (fn, options) => {
     const parent = testResources.get(executionAsyncId()) || getGlobalRoot();
-    parent.createHook(hook, fn, options);
+    parent.createHook(hook, fn, {
+      __proto__: null,
+      ...options,
+      parent,
+      hookType: hook,
+      loc: getCallerLocation(),
+    });
   };
 }
 

lib/internal/test_runner/reporter/spec.js

@@ -17,6 +17,7 @@ const { inspectWithNoCustomRetry } = require('internal/errors');
 const { green, blue, red, white, gray, shouldColorize } = require('internal/util/colors');
 const { kSubtestsFailed } = require('internal/test_runner/test');
 const { getCoverageReport } = require('internal/test_runner/utils');
+const { relative } = require('path');
 
 const inspectOptions = { __proto__: null, colors: shouldColorize(process.stdout), breakLength: Infinity };
 
@@ -40,6 +41,7 @@ class SpecReporter extends Transform {
   #reported = [];
   #indentMemo = new SafeMap();
   #failedTests = [];
+  #cwd = process.cwd();
 
   constructor() {
     super({ __proto__: null, writableObjectMode: true });
@@ -142,10 +144,12 @@ class SpecReporter extends Transform {
     }
     const results = [`\n${colors['test:fail']}${symbols['test:fail']}failing tests:${white}\n`];
     for (let i = 0; i < this.#failedTests.length; i++) {
-      ArrayPrototypePush(results, this.#formatTestReport(
-        'test:fail',
-        this.#failedTests[i],
-      ));
+      const test = this.#failedTests[i];
+      const relPath = relative(this.#cwd, test.file);
+      const formattedErr = this.#formatTestReport('test:fail', test);
+      const location = `test at ${relPath}:${test.line}:${test.column}`;
+
+      ArrayPrototypePush(results, location, formattedErr);
     }
     callback(null, ArrayPrototypeJoin(results, '\n'));
   }

lib/internal/test_runner/reporter/tap.js

@@ -31,13 +31,14 @@ async function * tapReporter(source) {
   yield `TAP version ${kDefaultTAPVersion}\n`;
   for await (const { type, data } of source) {
     switch (type) {
-      case 'test:fail':
+      case 'test:fail': {
         yield reportTest(data.nesting, data.testNumber, 'not ok', data.name, data.skip, data.todo);
-        yield reportDetails(data.nesting, data.details);
+        const location = `${data.file}:${data.line}:${data.column}`;
+        yield reportDetails(data.nesting, data.details, location);
         break;
-      case 'test:pass':
+      } case 'test:pass':
         yield reportTest(data.nesting, data.testNumber, 'ok', data.name, data.skip, data.todo);
-        yield reportDetails(data.nesting, data.details);
+        yield reportDetails(data.nesting, data.details, null);
         break;
       case 'test:plan':
         yield `${indent(data.nesting)}1..${data.count}\n`;
@@ -81,13 +82,18 @@ function reportTest(nesting, testNumber, status, name, skip, todo) {
   return line;
 }
 
-function reportDetails(nesting, data = kEmptyObject) {
+function reportDetails(nesting, data = kEmptyObject, location) {
   const { error, duration_ms } = data;
   const _indent = indent(nesting);
   let details = `${_indent}  ---\n`;
 
   details += jsToYaml(_indent, 'duration_ms', duration_ms);
   details += jsToYaml(_indent, 'type', data.type);
+
+  if (location) {
+    details += jsToYaml(_indent, 'location', location);
+  }
+
   details += jsToYaml(_indent, null, error, new SafeSet());
   details += `${_indent}  ...\n`;
   return details;