diff --git a/doc/api/test.md b/doc/api/test.md index 338c5e196d43ac..237b4aa83b9f41 100644 --- a/doc/api/test.md +++ b/doc/api/test.md @@ -320,6 +320,10 @@ internally. * `name` {string} The name of the test, which is displayed when reporting test @@ -339,6 +343,9 @@ added: REPLACEME * `todo` {boolean|string} If truthy, the test marked as `TODO`. If a string is provided, that string is displayed in the test results as the reason why the test is `TODO`. **Default:** `false`. + * `timeout` {number} A number of milliseconds the test will fail after. + If unspecified, subtests inherit this value from their parent. + **Default:** `30_000`. * `fn` {Function|AsyncFunction} The function under test. The first argument to this function is a [`TestContext`][] object. If the test uses callbacks, the callback function is passed as the second argument. **Default:** A no-op @@ -519,6 +526,10 @@ test('top level test', (t) => { * `name` {string} The name of the subtest, which is displayed when reporting @@ -538,6 +549,9 @@ added: REPLACEME * `todo` {boolean|string} If truthy, the test marked as `TODO`. If a string is provided, that string is displayed in the test results as the reason why the test is `TODO`. **Default:** `false`. + * `timeout` {number} A number of milliseconds the test will fail after. + If unspecified, subtests inherit this value from their parent. + **Default:** `30_000`. * `fn` {Function|AsyncFunction} The function under test. The first argument to this function is a [`TestContext`][] object. If the test uses callbacks, the callback function is passed as the second argument. **Default:** A no-op diff --git a/lib/internal/test_runner/test.js b/lib/internal/test_runner/test.js index 0f7c31ec808e28..2ecebde20ce34b 100644 --- a/lib/internal/test_runner/test.js +++ b/lib/internal/test_runner/test.js @@ -9,6 +9,7 @@ const { PromiseResolve, ReflectApply, SafeMap, + PromiseRace, } = primordials; const { AsyncResource } = require('async_hooks'); const { @@ -26,6 +27,7 @@ const { } = require('internal/util'); const { isPromise } = require('internal/util/types'); const { isUint32 } = require('internal/validators'); +const { setTimeout } = require('timers/promises'); const { cpus } = require('os'); const { bigint: hrtime } = process.hrtime; const kCallbackAndPromisePresent = 'callbackAndPromisePresent'; @@ -33,13 +35,31 @@ const kCancelledByParent = 'cancelledByParent'; const kParentAlreadyFinished = 'parentAlreadyFinished'; const kSubtestsFailed = 'subtestsFailed'; const kTestCodeFailure = 'testCodeFailure'; +const kTestTimeoutFailure = 'testTimeoutFailure'; const kDefaultIndent = ' '; +const kDefaultTimeout = null; const noop = FunctionPrototype; const isTestRunner = getOptionValue('--test'); const testOnlyFlag = !isTestRunner && getOptionValue('--test-only'); // TODO(cjihrig): Use uv_available_parallelism() once it lands. const rootConcurrency = isTestRunner ? cpus().length : 1; + +function testTimeout(promise, timeout) { + if (timeout === kDefaultTimeout) { + return promise; + } + return PromiseRace([ + promise, + setTimeout(timeout, null, { ref: false }).then(() => { + throw new ERR_TEST_FAILURE( + `test timed out after ${timeout}ms`, + kTestTimeoutFailure + ); + }), + ]); +} + class TestContext { #test; @@ -76,7 +96,7 @@ class Test extends AsyncResource { super('Test'); let { fn, name, parent, skip } = options; - const { concurrency, only, todo } = options; + const { concurrency, only, timeout, todo } = options; if (typeof fn !== 'function') { fn = noop; @@ -98,6 +118,7 @@ class Test extends AsyncResource { this.reporter = new TapStream(); this.runOnlySubtests = this.only; this.testNumber = 0; + this.timeout = kDefaultTimeout; } else { const indent = parent.parent === null ? parent.indent : parent.indent + parent.indentString; @@ -109,12 +130,17 @@ class Test extends AsyncResource { this.reporter = parent.reporter; this.runOnlySubtests = !this.only; this.testNumber = parent.subtests.length + 1; + this.timeout = parent.timeout; } if (isUint32(concurrency) && concurrency !== 0) { this.concurrency = concurrency; } + if (isUint32(timeout)) { + this.timeout = timeout; + } + if (testOnlyFlag && !this.only) { skip = '\'only\' option not set'; } @@ -329,13 +355,13 @@ class Test extends AsyncResource { 'passed a callback but also returned a Promise', kCallbackAndPromisePresent )); - await ret; + await testTimeout(ret, this.timeout); } else { - await promise; + await testTimeout(promise, this.timeout); } } else { // This test is synchronous or using Promises. - await ReflectApply(this.runInAsyncScope, this, args); + await testTimeout(ReflectApply(this.runInAsyncScope, this, args), this.timeout); } this.pass(); @@ -480,10 +506,10 @@ class Suite extends Test { this.parent.activeSubtests++; this.startTime = hrtime(); const subtests = this.skipped || this.error ? [] : this.subtests; - await ArrayPrototypeReduce(subtests, async (prev, subtest) => { + await testTimeout(ArrayPrototypeReduce(subtests, async (prev, subtest) => { await prev; await subtest.run(); - }, PromiseResolve()); + }, PromiseResolve()), this.timeout); this.pass(); this.postRun(); } diff --git a/test/message/test_runner_desctibe_it.js b/test/message/test_runner_desctibe_it.js index a8023f8e9bf350..156fecddaf6401 100644 --- a/test/message/test_runner_desctibe_it.js +++ b/test/message/test_runner_desctibe_it.js @@ -316,3 +316,26 @@ describe('describe async throw fails', async () => { it('should not run', () => {}); throw new Error('thrown from describe'); }); + +describe('timeouts', () => { + it('timed out async test', { timeout: 5 }, async () => { + return new Promise((resolve) => { + setTimeout(resolve, 1000); + }); + }); + + it('timed out callback test', { timeout: 5 }, (done) => { + setTimeout(done, 1000); + }); + + + it('large timeout async test is ok', { timeout: 30_000_000 }, async () => { + return new Promise((resolve) => { + setTimeout(resolve, 10); + }); + }); + + it('large timeout callback test is ok', { timeout: 30_000_000 }, (done) => { + setTimeout(done, 10); + }); +}); diff --git a/test/message/test_runner_desctibe_it.out b/test/message/test_runner_desctibe_it.out index f60553d4b7ff09..278d542fca2c7d 100644 --- a/test/message/test_runner_desctibe_it.out +++ b/test/message/test_runner_desctibe_it.out @@ -551,8 +551,43 @@ not ok 56 - describe async throw fails * * ... +# Subtest: timeouts + # Subtest: timed out async test + not ok 1 - timed out async test + --- + duration_ms: * + failureType: 'testTimeoutFailure' + error: 'test timed out after 5ms' + code: 'ERR_TEST_FAILURE' + ... + # Subtest: timed out callback test + not ok 2 - timed out callback test + --- + duration_ms: * + failureType: 'testTimeoutFailure' + error: 'test timed out after 5ms' + code: 'ERR_TEST_FAILURE' + ... + # Subtest: large timeout async test is ok + ok 3 - large timeout async test is ok + --- + duration_ms: * + ... + # Subtest: large timeout callback test is ok + ok 4 - large timeout callback test is ok + --- + duration_ms: * + ... + 1..4 +not ok 57 - timeouts + --- + duration_ms: * + failureType: 'subtestsFailed' + error: '2 subtests failed' + code: 'ERR_TEST_FAILURE' + ... # Subtest: invalid subtest fail -not ok 57 - invalid subtest fail +not ok 58 - invalid subtest fail --- duration_ms: * failureType: 'parentAlreadyFinished' @@ -561,16 +596,16 @@ not ok 57 - invalid subtest fail stack: |- * ... -1..57 +1..58 # Warning: Test "unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "async unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "immediate throw - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. # Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. # Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. -# tests 57 +# tests 58 # pass 23 -# fail 20 +# fail 21 # cancelled 0 # skipped 9 # todo 5 diff --git a/test/message/test_runner_output.js b/test/message/test_runner_output.js index c586199f0d9d31..33e17e6a082ca7 100644 --- a/test/message/test_runner_output.js +++ b/test/message/test_runner_output.js @@ -328,3 +328,24 @@ test('subtest sync throw fails', async (t) => { throw new Error('thrown from subtest sync throw fails at second'); }); }); + +test('timed out async test', { timeout: 5 }, async (t) => { + return new Promise((resolve) => { + setTimeout(resolve, 1000); + }); +}); + +test('timed out callback test', { timeout: 5 }, (t, done) => { + setTimeout(done, 1000); +}); + + +test('large timeout async test is ok', { timeout: 30_000_000 }, async (t) => { + return new Promise((resolve) => { + setTimeout(resolve, 10); + }); +}); + +test('large timeout callback test is ok', { timeout: 30_000_000 }, (t, done) => { + setTimeout(done, 10); +}); diff --git a/test/message/test_runner_output.out b/test/message/test_runner_output.out index bada2fdacae9a9..22d97940a36f9c 100644 --- a/test/message/test_runner_output.out +++ b/test/message/test_runner_output.out @@ -562,8 +562,34 @@ not ok 56 - subtest sync throw fails error: '2 subtests failed' code: 'ERR_TEST_FAILURE' ... +# Subtest: timed out async test +not ok 57 - timed out async test + --- + duration_ms: * + failureType: 'testTimeoutFailure' + error: 'test timed out after 5ms' + code: 'ERR_TEST_FAILURE' + ... +# Subtest: timed out callback test +not ok 58 - timed out callback test + --- + duration_ms: * + failureType: 'testTimeoutFailure' + error: 'test timed out after 5ms' + code: 'ERR_TEST_FAILURE' + ... +# Subtest: large timeout async test is ok +ok 59 - large timeout async test is ok + --- + duration_ms: * + ... +# Subtest: large timeout callback test is ok +ok 60 - large timeout callback test is ok + --- + duration_ms: * + ... # Subtest: invalid subtest fail -not ok 57 - invalid subtest fail +not ok 61 - invalid subtest fail --- duration_ms: * failureType: 'parentAlreadyFinished' @@ -572,16 +598,16 @@ not ok 57 - invalid subtest fail stack: |- * ... -1..57 +1..61 # Warning: Test "unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "async unhandled rejection - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from async unhandled rejection fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "immediate throw - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from immediate throw fail" and would have caused the test to fail, but instead triggered an uncaughtException event. # Warning: Test "immediate reject - passes but warns" generated asynchronous activity after the test ended. This activity created the error "Error: rejected from immediate reject fail" and would have caused the test to fail, but instead triggered an unhandledRejection event. # Warning: Test "callback called twice in different ticks" generated asynchronous activity after the test ended. This activity created the error "Error [ERR_TEST_FAILURE]: callback invoked multiple times" and would have caused the test to fail, but instead triggered an uncaughtException event. # Warning: Test "callback async throw after done" generated asynchronous activity after the test ended. This activity created the error "Error: thrown from callback async throw after done" and would have caused the test to fail, but instead triggered an uncaughtException event. -# tests 57 -# pass 24 -# fail 18 +# tests 61 +# pass 26 +# fail 20 # cancelled 0 # skipped 10 # todo 5