From 6c679ccd647abb0867b3de93fbb97d0b10b6b850 Mon Sep 17 00:00:00 2001 From: cjihrig Date: Sun, 30 Jul 2023 18:17:39 -0400 Subject: [PATCH] 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. Fixes: https://github.com/nodejs/node/issues/48457 --- doc/api/test.md | 36 +++++++ lib/internal/test_runner/harness.js | 20 +++- lib/internal/test_runner/reporter/spec.js | 12 ++- lib/internal/test_runner/test.js | 78 ++++++++++----- lib/internal/test_runner/tests_stream.js | 94 ++++++++++++++----- src/node_util.cc | 26 +++++ .../output/default_output.snapshot | 3 + .../test-runner/output/spec_reporter.snapshot | 28 ++++++ .../output/spec_reporter_cli.snapshot | 28 ++++++ 9 files changed, 270 insertions(+), 55 deletions(-) diff --git a/doc/api/test.md b/doc/api/test.md index 00cea0530b9e3b..d6a71296a3c8ed 100644 --- a/doc/api/test.md +++ b/doc/api/test.md @@ -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. @@ -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. @@ -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. @@ -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. @@ -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. @@ -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. @@ -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. @@ -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`. @@ -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`. diff --git a/lib/internal/test_runner/harness.js b/lib/internal/test_runner/harness.js index 36c36f2de14b04..52b0cca463051c 100644 --- a/lib/internal/test_runner/harness.js +++ b/lib/internal/test_runner/harness.js @@ -5,6 +5,7 @@ const { PromiseResolve, SafeMap, } = primordials; +const { getCallerLocation } = internalBinding('util'); const { createHook, executionAsyncId, @@ -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; } diff --git a/lib/internal/test_runner/reporter/spec.js b/lib/internal/test_runner/reporter/spec.js index f15b3eaa40aa27..6114f1b544575f 100644 --- a/lib/internal/test_runner/reporter/spec.js +++ b/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 line ${test.line}, column ${test.column} of '${relPath}'`; + + ArrayPrototypePush(results, location, formattedErr); } callback(null, ArrayPrototypeJoin(results, '\n')); } diff --git a/lib/internal/test_runner/test.js b/lib/internal/test_runner/test.js index 0d8e3dbd6e8d3c..6165f429dab612 100644 --- a/lib/internal/test_runner/test.js +++ b/lib/internal/test_runner/test.js @@ -22,6 +22,7 @@ const { SafePromiseRace, Symbol, } = primordials; +const { getCallerLocation } = internalBinding('util'); const { AsyncResource } = require('async_hooks'); const { once } = require('events'); const { AbortController } = require('internal/abort_controller'); @@ -124,8 +125,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(); } @@ -172,7 +180,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; @@ -202,6 +210,7 @@ class Test extends AsyncResource { beforeEach: [], afterEach: [], }; + this.loc = undefined; } else { const nesting = parent.parent === null ? parent.nesting : parent.nesting + 1; @@ -221,6 +230,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) { @@ -322,7 +342,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(); } @@ -481,7 +501,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(); @@ -490,7 +510,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(); } @@ -655,29 +675,37 @@ class Test extends AsyncResource { this.parent.processReadySubtestRange(false); this.parent.processPendingSubtests(); } else if (!this.reported) { + const { + diagnostics, + harness, + loc, + nesting, + reporter, + } = this; + 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(); } } @@ -713,7 +741,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(); } @@ -731,14 +759,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]); } } @@ -748,7 +776,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); } } diff --git a/lib/internal/test_runner/tests_stream.js b/lib/internal/test_runner/tests_stream.js index 901987681f319b..f7730caac00fa7 100644 --- a/lib/internal/test_runner/tests_stream.js +++ b/lib/internal/test_runner/tests_stream.js @@ -29,16 +29,37 @@ class TestsStream extends Readable { } } - fail(nesting, file, testNumber, name, details, directive) { - this[kEmitMessage]('test:fail', { __proto__: null, name, nesting, file, testNumber, details, ...directive }); - } - - ok(nesting, file, testNumber, name, details, directive) { - this[kEmitMessage]('test:pass', { __proto__: null, name, nesting, file, testNumber, details, ...directive }); - } - - plan(nesting, file, count) { - this[kEmitMessage]('test:plan', { __proto__: null, nesting, file, count }); + fail(nesting, loc, testNumber, name, details, directive) { + this[kEmitMessage]('test:fail', { + __proto__: null, + name, + nesting, + testNumber, + details, + ...loc, + ...directive, + }); + } + + ok(nesting, loc, testNumber, name, details, directive) { + this[kEmitMessage]('test:pass', { + __proto__: null, + name, + nesting, + testNumber, + details, + ...loc, + ...directive, + }); + } + + plan(nesting, loc, count) { + this[kEmitMessage]('test:plan', { + __proto__: null, + nesting, + count, + ...loc, + }); } getSkip(reason = undefined) { @@ -49,32 +70,57 @@ class TestsStream extends Readable { return { __proto__: null, todo: reason ?? true }; } - enqueue(nesting, file, name) { - this[kEmitMessage]('test:enqueue', { __proto__: null, nesting, file, name }); + enqueue(nesting, loc, name) { + this[kEmitMessage]('test:enqueue', { + __proto__: null, + nesting, + name, + ...loc, + }); } - dequeue(nesting, file, name) { - this[kEmitMessage]('test:dequeue', { __proto__: null, nesting, file, name }); + dequeue(nesting, loc, name) { + this[kEmitMessage]('test:dequeue', { + __proto__: null, + nesting, + name, + ...loc, + }); } - start(nesting, file, name) { - this[kEmitMessage]('test:start', { __proto__: null, nesting, file, name }); + start(nesting, loc, name) { + this[kEmitMessage]('test:start', { + __proto__: null, + nesting, + name, + ...loc, + }); } - diagnostic(nesting, file, message) { - this[kEmitMessage]('test:diagnostic', { __proto__: null, nesting, file, message }); + diagnostic(nesting, loc, message) { + this[kEmitMessage]('test:diagnostic', { + __proto__: null, + nesting, + message, + ...loc, + }); } - stderr(file, message) { - this[kEmitMessage]('test:stderr', { __proto__: null, file, message }); + stderr(loc, message) { + this[kEmitMessage]('test:stderr', { __proto__: null, message, ...loc }); } - stdout(file, message) { - this[kEmitMessage]('test:stdout', { __proto__: null, file, message }); + stdout(loc, message) { + this[kEmitMessage]('test:stdout', { __proto__: null, message, ...loc }); } - coverage(nesting, file, summary) { - this[kEmitMessage]('test:coverage', { __proto__: null, nesting, file, summary }); + coverage(nesting, loc, summary) { + this[kEmitMessage]('test:coverage', { + __proto__: null, + nesting, + summary, + ...loc, + }); } end() { diff --git a/src/node_util.cc b/src/node_util.cc index 2af3b5a7276aae..b987fa41b10515 100644 --- a/src/node_util.cc +++ b/src/node_util.cc @@ -34,6 +34,8 @@ using v8::PropertyFilter; using v8::Proxy; using v8::SKIP_STRINGS; using v8::SKIP_SYMBOLS; +using v8::StackFrame; +using v8::StackTrace; using v8::String; using v8::Uint32; using v8::Value; @@ -140,6 +142,27 @@ static void GetProxyDetails(const FunctionCallbackInfo& args) { } } +static void GetCallerLocation(const FunctionCallbackInfo& args) { + Isolate* isolate = args.GetIsolate(); + Local trace = StackTrace::CurrentStackTrace(isolate, 2); + + // This function is frame zero. The caller is frame one. If there aren't two + // stack frames, return undefined. + if (trace->GetFrameCount() != 2) { + return; + } + + Local frame = trace->GetFrame(isolate, 1); + Local ret[] = { + Integer::New(isolate, frame->GetLineNumber()), + Integer::New(isolate, frame->GetColumn()), + frame->GetScriptNameOrSourceURL() + }; + + args.GetReturnValue().Set( + Array::New(args.GetIsolate(), ret, arraysize(ret))); +} + static void IsArrayBufferDetached(const FunctionCallbackInfo& args) { if (args[0]->IsArrayBuffer()) { auto buffer = args[0].As(); @@ -393,6 +416,7 @@ static void ToUSVString(const FunctionCallbackInfo& args) { void RegisterExternalReferences(ExternalReferenceRegistry* registry) { registry->Register(GetPromiseDetails); registry->Register(GetProxyDetails); + registry->Register(GetCallerLocation); registry->Register(IsArrayBufferDetached); registry->Register(PreviewEntries); registry->Register(GetOwnNonIndexProperties); @@ -494,6 +518,8 @@ void Initialize(Local target, SetMethodNoSideEffect( context, target, "getPromiseDetails", GetPromiseDetails); SetMethodNoSideEffect(context, target, "getProxyDetails", GetProxyDetails); + SetMethodNoSideEffect( + context, target, "getCallerLocation", GetCallerLocation); SetMethodNoSideEffect( context, target, "isArrayBufferDetached", IsArrayBufferDetached); SetMethodNoSideEffect(context, target, "previewEntries", PreviewEntries); diff --git a/test/fixtures/test-runner/output/default_output.snapshot b/test/fixtures/test-runner/output/default_output.snapshot index dca844bb8402aa..3be84789fb219b 100644 --- a/test/fixtures/test-runner/output/default_output.snapshot +++ b/test/fixtures/test-runner/output/default_output.snapshot @@ -35,6 +35,7 @@ [31m✖ failing tests:[39m +test at line 10, column 1 of 'test/fixtures/test-runner/output/default_output.js' [31m✖ should fail [90m(*ms)[39m[39m Error: fail *[39m @@ -45,6 +46,7 @@ *[39m *[39m +test at line 13, column 3 of 'test/fixtures/test-runner/output/default_output.js' [31m✖ should fail [90m(*ms)[39m[39m Error: fail *[39m @@ -53,5 +55,6 @@ *[39m *[39m +test at line 14, column 3 of 'test/fixtures/test-runner/output/default_output.js' [31m✖ should pass but parent fail [90m(*ms)[39m[39m [32m'test did not finish before its parent and was cancelled'[39m diff --git a/test/fixtures/test-runner/output/spec_reporter.snapshot b/test/fixtures/test-runner/output/spec_reporter.snapshot index 13f3618d38c28d..0ceb302f5abf40 100644 --- a/test/fixtures/test-runner/output/spec_reporter.snapshot +++ b/test/fixtures/test-runner/output/spec_reporter.snapshot @@ -307,6 +307,7 @@ failing tests: +test at line 16, column 1 of 'test/fixtures/test-runner/output/output.js' sync fail todo (*ms) # TODO Error: thrown from sync fail todo * @@ -317,6 +318,7 @@ * * +test at line 21, column 1 of 'test/fixtures/test-runner/output/output.js' sync fail todo with message (*ms) # this is a failing todo Error: thrown from sync fail todo with message * @@ -327,6 +329,7 @@ * * +test at line 38, column 1 of 'test/fixtures/test-runner/output/output.js' sync throw fail (*ms) Error: thrown from sync throw fail * @@ -337,6 +340,7 @@ * * +test at line 50, column 1 of 'test/fixtures/test-runner/output/output.js' async throw fail (*ms) Error: thrown from async throw fail * @@ -347,6 +351,7 @@ * * +test at line 54, column 1 of 'test/fixtures/test-runner/output/output.js' async skip fail (*ms) # SKIP Error: thrown from async throw fail * @@ -357,6 +362,7 @@ * * +test at line 59, column 1 of 'test/fixtures/test-runner/output/output.js' async assertion fail (*ms) AssertionError [ERR_ASSERTION]: Expected values to be strictly equal: @@ -376,6 +382,7 @@ operator: 'strictEqual' } +test at line 68, column 1 of 'test/fixtures/test-runner/output/output.js' reject fail (*ms) Error: rejected from reject fail * @@ -386,6 +393,7 @@ * * +test at line 101, column 11 of 'test/fixtures/test-runner/output/output.js' +sync throw fail (*ms) Error: thrown from subtest sync throw fail * @@ -399,12 +407,15 @@ * * +test at line 107, column 1 of 'test/fixtures/test-runner/output/output.js' sync throw non-error fail (*ms) Symbol(thrown symbol from sync throw non-error fail) +test at line 160, column 5 of 'test/fixtures/test-runner/output/output.js' +long running (*ms) 'test did not finish before its parent and was cancelled' +test at line 187, column 1 of 'test/fixtures/test-runner/output/output.js' sync skip option is false fail (*ms) Error: this should be executed * @@ -415,14 +426,17 @@ * * +test at line 233, column 1 of 'test/fixtures/test-runner/output/output.js' callback fail (*ms) Error: callback failure * * +test at line 252, column 1 of 'test/fixtures/test-runner/output/output.js' callback also returns a Promise (*ms) 'passed a callback but also returned a Promise' +test at line 256, column 1 of 'test/fixtures/test-runner/output/output.js' callback throw (*ms) Error: thrown from callback throw * @@ -433,9 +447,11 @@ * * +test at line 260, column 1 of 'test/fixtures/test-runner/output/output.js' callback called twice (*ms) 'callback invoked multiple times' +test at line 270, column 1 of 'test/fixtures/test-runner/output/output.js' callback called twice in future tick (*ms) Error [ERR_TEST_FAILURE]: callback invoked multiple times * { @@ -444,17 +460,21 @@ code: 'ERR_TEST_FAILURE' } +test at line 277, column 1 of 'test/fixtures/test-runner/output/output.js' callback async throw (*ms) Error: thrown from callback async throw * * +test at line 301, column 1 of 'test/fixtures/test-runner/output/output.js' custom inspect symbol fail (*ms) customized +test at line 312, column 1 of 'test/fixtures/test-runner/output/output.js' custom inspect symbol that throws fail (*ms) { foo: 1, [Symbol(nodejs.util.inspect.custom)]: [Function: [nodejs.util.inspect.custom]] } +test at line 324, column 11 of 'test/fixtures/test-runner/output/output.js' sync throw fails at first (*ms) Error: thrown from subtest sync throw fails at first * @@ -468,6 +488,7 @@ * * +test at line 327, column 11 of 'test/fixtures/test-runner/output/output.js' sync throw fails at second (*ms) Error: thrown from subtest sync throw fails at second * @@ -481,27 +502,33 @@ * * +test at line 332, column 1 of 'test/fixtures/test-runner/output/output.js' timed out async test (*ms) 'test timed out after *ms' +test at line 338, column 1 of 'test/fixtures/test-runner/output/output.js' timed out callback test (*ms) 'test timed out after *ms' +test at line 364, column 1 of 'test/fixtures/test-runner/output/output.js' rejected thenable (*ms) 'custom error' +test at line 375, column 1 of 'test/fixtures/test-runner/output/output.js' unfinished test with uncaughtException (*ms) Error: foo * * * +test at line 381, column 1 of 'test/fixtures/test-runner/output/output.js' unfinished test with unhandledRejection (*ms) Error: bar * * * +test at line 393, column 1 of 'test/fixtures/test-runner/output/output.js' assertion errors display actual and expected properly (*ms) AssertionError [ERR_ASSERTION]: Expected values to be loosely deep-equal: @@ -524,5 +551,6 @@ operator: 'deepEqual' } +test at line 173, column 7 of 'test/fixtures/test-runner/output/output.js' invalid subtest fail (*ms) 'test could not be started because its parent finished' diff --git a/test/fixtures/test-runner/output/spec_reporter_cli.snapshot b/test/fixtures/test-runner/output/spec_reporter_cli.snapshot index 22c9a9174574a1..fc06278183a6e8 100644 --- a/test/fixtures/test-runner/output/spec_reporter_cli.snapshot +++ b/test/fixtures/test-runner/output/spec_reporter_cli.snapshot @@ -307,6 +307,7 @@ failing tests: +test at line 16, column 1 of 'test/fixtures/test-runner/output/output.js' sync fail todo (*ms) # TODO Error: thrown from sync fail todo * @@ -317,6 +318,7 @@ * * +test at line 21, column 1 of 'test/fixtures/test-runner/output/output.js' sync fail todo with message (*ms) # this is a failing todo Error: thrown from sync fail todo with message * @@ -327,6 +329,7 @@ * * +test at line 38, column 1 of 'test/fixtures/test-runner/output/output.js' sync throw fail (*ms) Error: thrown from sync throw fail * @@ -337,6 +340,7 @@ * * +test at line 50, column 1 of 'test/fixtures/test-runner/output/output.js' async throw fail (*ms) Error: thrown from async throw fail * @@ -347,6 +351,7 @@ * * +test at line 54, column 1 of 'test/fixtures/test-runner/output/output.js' async skip fail (*ms) # SKIP Error: thrown from async throw fail * @@ -357,6 +362,7 @@ * * +test at line 59, column 1 of 'test/fixtures/test-runner/output/output.js' async assertion fail (*ms) AssertionError [ERR_ASSERTION]: Expected values to be strictly equal: @@ -376,6 +382,7 @@ operator: 'strictEqual' } +test at line 68, column 1 of 'test/fixtures/test-runner/output/output.js' reject fail (*ms) Error: rejected from reject fail * @@ -386,6 +393,7 @@ * * +test at line 101, column 11 of 'test/fixtures/test-runner/output/output.js' +sync throw fail (*ms) Error: thrown from subtest sync throw fail * @@ -399,12 +407,15 @@ * * +test at line 107, column 1 of 'test/fixtures/test-runner/output/output.js' sync throw non-error fail (*ms) Symbol(thrown symbol from sync throw non-error fail) +test at line 160, column 5 of 'test/fixtures/test-runner/output/output.js' +long running (*ms) 'test did not finish before its parent and was cancelled' +test at line 187, column 1 of 'test/fixtures/test-runner/output/output.js' sync skip option is false fail (*ms) Error: this should be executed * @@ -415,14 +426,17 @@ * * +test at line 233, column 1 of 'test/fixtures/test-runner/output/output.js' callback fail (*ms) Error: callback failure * * +test at line 252, column 1 of 'test/fixtures/test-runner/output/output.js' callback also returns a Promise (*ms) 'passed a callback but also returned a Promise' +test at line 256, column 1 of 'test/fixtures/test-runner/output/output.js' callback throw (*ms) Error: thrown from callback throw * @@ -433,9 +447,11 @@ * * +test at line 260, column 1 of 'test/fixtures/test-runner/output/output.js' callback called twice (*ms) 'callback invoked multiple times' +test at line 270, column 1 of 'test/fixtures/test-runner/output/output.js' callback called twice in future tick (*ms) Error [ERR_TEST_FAILURE]: callback invoked multiple times * { @@ -444,17 +460,21 @@ code: 'ERR_TEST_FAILURE' } +test at line 277, column 1 of 'test/fixtures/test-runner/output/output.js' callback async throw (*ms) Error: thrown from callback async throw * * +test at line 301, column 1 of 'test/fixtures/test-runner/output/output.js' custom inspect symbol fail (*ms) customized +test at line 312, column 1 of 'test/fixtures/test-runner/output/output.js' custom inspect symbol that throws fail (*ms) { foo: 1 } +test at line 324, column 11 of 'test/fixtures/test-runner/output/output.js' sync throw fails at first (*ms) Error: thrown from subtest sync throw fails at first * @@ -468,6 +488,7 @@ * * +test at line 327, column 11 of 'test/fixtures/test-runner/output/output.js' sync throw fails at second (*ms) Error: thrown from subtest sync throw fails at second * @@ -481,27 +502,33 @@ * * +test at line 332, column 1 of 'test/fixtures/test-runner/output/output.js' timed out async test (*ms) 'test timed out after *ms' +test at line 338, column 1 of 'test/fixtures/test-runner/output/output.js' timed out callback test (*ms) 'test timed out after *ms' +test at line 364, column 1 of 'test/fixtures/test-runner/output/output.js' rejected thenable (*ms) 'custom error' +test at line 375, column 1 of 'test/fixtures/test-runner/output/output.js' unfinished test with uncaughtException (*ms) Error: foo * * * +test at line 381, column 1 of 'test/fixtures/test-runner/output/output.js' unfinished test with unhandledRejection (*ms) Error: bar * * * +test at line 393, column 1 of 'test/fixtures/test-runner/output/output.js' assertion errors display actual and expected properly (*ms) AssertionError [ERR_ASSERTION]: Expected values to be loosely deep-equal: @@ -524,5 +551,6 @@ operator: 'deepEqual' } +test at line 173, column 7 of 'test/fixtures/test-runner/output/output.js' invalid subtest fail (*ms) 'test could not be started because its parent finished'