Skip to content

Commit

Permalink
test_runner: expose location of tests
Browse files Browse the repository at this point in the history 
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.

Fixes: nodejs#48457
  • Loading branch information
@cjihrig
cjihrig committed Aug 7, 2023
1 parent d150316 commit 9386507
Show file tree
Hide file tree
Showing 9 changed files with 268 additions and 56 deletions.
36 changes: 36 additions & 0 deletions doc/api/test.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2027,8 +2027,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.

Expand All @@ -2037,8 +2041,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.

Expand All @@ -2047,8 +2055,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.

Expand All @@ -2057,12 +2069,16 @@ 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.
* `cause` {Error} The actual error thrown by the test.
* `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.
Expand All @@ -2074,10 +2090,14 @@ 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.
* `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.
Expand All @@ -2089,8 +2109,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.

Expand All @@ -2099,8 +2123,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.

Expand All @@ -2111,7 +2139,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`.
Expand All @@ -2120,7 +2152,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`.
Expand Down
20 changes: 18 additions & 2 deletions lib/internal/test_runner/harness.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ const {
PromiseResolve,
SafeMap,
} = primordials;
const { getCallerLocation } = internalBinding('util');
const {
createHook,
executionAsyncId,
Expand Down Expand Up @@ -217,9 +218,24 @@ 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;
}
Expand Down
12 changes: 8 additions & 4 deletions lib/internal/test_runner/reporter/spec.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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 };

Expand All @@ -40,6 +41,7 @@ class SpecReporter extends Transform {
#reported = [];
#indentMemo = new SafeMap();
#failedTests = [];
#cwd = process.cwd();

constructor() {
super({ __proto__: null, writableObjectMode: true });
Expand Down Expand Up @@ -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 line ${test.line}, column ${test.column} of '${relPath}'`;

ArrayPrototypePush(results, location, formattedErr);
}
callback(null, ArrayPrototypeJoin(results, '\n'));
}
Expand Down
80 changes: 54 additions & 26 deletions lib/internal/test_runner/test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ const {
ObjectDefineProperty,
Symbol,
} = primordials;
const { getCallerLocation } = internalBinding('util');
const { addAbortListener } = require('events');
const { AsyncResource } = require('async_hooks');
const { AbortController } = require('internal/abort_controller');
Expand Down Expand Up @@ -153,8 +154,15 @@ class TestContext {
}

test(name, options, fn) {
// eslint-disable-next-line no-use-before-define
const subtest = this.#test.createSubtest(Test, name, options, fn);
const overrides = {
__proto__: null,
loc: getCallerLocation(),
};

const subtest = this.#test.createSubtest(
// eslint-disable-next-line no-use-before-define
Test, name, options, fn, overrides,
);

return subtest.start();
}
Expand Down Expand Up @@ -201,7 +209,7 @@ class Test extends AsyncResource {
super('Test');

let { fn, name, parent, skip } = options;
const { concurrency, only, timeout, todo, signal } = options;
const { concurrency, loc, only, timeout, todo, signal } = options;

if (typeof fn !== 'function') {
fn = noop;
Expand Down Expand Up @@ -231,6 +239,7 @@ class Test extends AsyncResource {
beforeEach: [],
afterEach: [],
};
this.loc = undefined;
} else {
const nesting = parent.parent === null ? parent.nesting :
parent.nesting + 1;
Expand All @@ -250,6 +259,17 @@ class Test extends AsyncResource {
beforeEach: ArrayPrototypeSlice(parent.hooks.beforeEach),
afterEach: ArrayPrototypeSlice(parent.hooks.afterEach),
};

if (loc === undefined || kFilename === undefined) {
this.loc = undefined;
} else {
this.loc = {
__proto__: null,
line: loc[0],
column: loc[1],
file: loc[2],
};
}
}

switch (typeof concurrency) {
Expand Down Expand Up @@ -351,7 +371,7 @@ class Test extends AsyncResource {
while (this.pendingSubtests.length > 0 && this.hasConcurrency()) {
const deferred = ArrayPrototypeShift(this.pendingSubtests);
const test = deferred.test;
this.reporter.dequeue(test.nesting, kFilename, test.name);
this.reporter.dequeue(test.nesting, test.loc, test.name);
await test.run();
deferred.resolve();
}
Expand Down Expand Up @@ -510,7 +530,7 @@ class Test extends AsyncResource {
// If there is enough available concurrency to run the test now, then do
// it. Otherwise, return a Promise to the caller and mark the test as
// pending for later execution.
this.reporter.enqueue(this.nesting, kFilename, this.name);
this.reporter.enqueue(this.nesting, this.loc, this.name);
if (!this.parent.hasConcurrency()) {
const deferred = createDeferredPromise();

Expand All @@ -519,7 +539,7 @@ class Test extends AsyncResource {
return deferred.promise;
}

this.reporter.dequeue(this.nesting, kFilename, this.name);
this.reporter.dequeue(this.nesting, this.loc, this.name);
return this.run();
}

Expand Down Expand Up @@ -688,37 +708,45 @@ class Test extends AsyncResource {
this.parent.processReadySubtestRange(false);
this.parent.processPendingSubtests();
} else if (!this.reported) {
const {
diagnostics,
harness,
loc,
nesting,
reporter,
} = this;

if (!this.passed && failed === 0 && this.error) {
this.reporter.fail(0, kFilename, this.subtests.length + 1, kFilename, {
reporter.fail(0, kFilename, this.subtests.length + 1, kFilename, {
__proto__: null,
duration_ms: this.#duration(),
error: this.error,
}, undefined);
}

this.reported = true;
this.reporter.plan(this.nesting, kFilename, this.root.harness.counters.topLevel);
reporter.plan(nesting, loc, harness.counters.topLevel);

for (let i = 0; i < this.diagnostics.length; i++) {
this.reporter.diagnostic(this.nesting, kFilename, this.diagnostics[i]);
for (let i = 0; i < diagnostics.length; i++) {
reporter.diagnostic(nesting, loc, diagnostics[i]);
}

this.reporter.diagnostic(this.nesting, kFilename, `tests ${this.root.harness.counters.all}`);
this.reporter.diagnostic(this.nesting, kFilename, `suites ${this.root.harness.counters.suites}`);
this.reporter.diagnostic(this.nesting, kFilename, `pass ${this.root.harness.counters.passed}`);
this.reporter.diagnostic(this.nesting, kFilename, `fail ${this.root.harness.counters.failed}`);
this.reporter.diagnostic(this.nesting, kFilename, `cancelled ${this.root.harness.counters.cancelled}`);
this.reporter.diagnostic(this.nesting, kFilename, `skipped ${this.root.harness.counters.skipped}`);
this.reporter.diagnostic(this.nesting, kFilename, `todo ${this.root.harness.counters.todo}`);
this.reporter.diagnostic(this.nesting, kFilename, `duration_ms ${this.#duration()}`);
reporter.diagnostic(nesting, loc, `tests ${harness.counters.all}`);
reporter.diagnostic(nesting, loc, `suites ${harness.counters.suites}`);
reporter.diagnostic(nesting, loc, `pass ${harness.counters.passed}`);
reporter.diagnostic(nesting, loc, `fail ${harness.counters.failed}`);
reporter.diagnostic(nesting, loc, `cancelled ${harness.counters.cancelled}`);
reporter.diagnostic(nesting, loc, `skipped ${harness.counters.skipped}`);
reporter.diagnostic(nesting, loc, `todo ${harness.counters.todo}`);
reporter.diagnostic(nesting, loc, `duration_ms ${this.#duration()}`);

const coverage = this.harness.coverage();
const coverage = harness.coverage();

if (coverage) {
this.reporter.coverage(this.nesting, kFilename, coverage);
reporter.coverage(nesting, loc, coverage);
}

this.reporter.end();
reporter.end();
}
}

Expand Down Expand Up @@ -754,7 +782,7 @@ class Test extends AsyncResource {
report() {
countCompletedTest(this);
if (this.subtests.length > 0) {
this.reporter.plan(this.subtests[0].nesting, kFilename, this.subtests.length);
this.reporter.plan(this.subtests[0].nesting, this.loc, this.subtests.length);
} else {
this.reportStarted();
}
Expand All @@ -772,14 +800,14 @@ class Test extends AsyncResource {
}

if (this.passed) {
this.reporter.ok(this.nesting, kFilename, this.testNumber, this.name, details, directive);
this.reporter.ok(this.nesting, this.loc, this.testNumber, this.name, details, directive);
} else {
details.error = this.error;
this.reporter.fail(this.nesting, kFilename, this.testNumber, this.name, details, directive);
this.reporter.fail(this.nesting, this.loc, this.testNumber, this.name, details, directive);
}

for (let i = 0; i < this.diagnostics.length; i++) {
this.reporter.diagnostic(this.nesting, kFilename, this.diagnostics[i]);
this.reporter.diagnostic(this.nesting, this.loc, this.diagnostics[i]);
}
}

Expand All @@ -789,7 +817,7 @@ class Test extends AsyncResource {
}
this.#reportedSubtest = true;
this.parent.reportStarted();
this.reporter.start(this.nesting, kFilename, this.name);
this.reporter.start(this.nesting, this.loc, this.name);
}
}

Expand Down
Loading

0 comments on commit 9386507

Please sign in to comment.