FazBrowse GitHub Viewer | Trending |
URL:
| Home
Tools: [Download Repo ZIP]   [Original HTTPS Page]

test_runner: support timeout for tests · nodejs/node@e404a3e · GitHub

/ node Public

Commit e404a3e

Browse files
MoLow
authored and
danielleadams
committed
test_runner: support timeout for tests
PR-URL: #43505 Refs: #43490 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
1 parent c2db4f4 commit e404a3e

6 files changed

Lines changed: 160 additions & 15 deletions

File tree

‎doc/api/test.md‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -320,6 +320,10 @@ internally.
320320

321321
<!-- YAML
322322
added: v18.0.0
323+
changes:
324+
- version: REPLACEME
325+
pr-url: https://github.com/nodejs/node/pull/43505
326+
description: add a timeout to tests and allow setting it in options.
323327
-->
324328

325329
* `name` {string} The name of the test, which is displayed when reporting test
@@ -339,6 +343,9 @@ added: v18.0.0
339343
* `todo` {boolean|string} If truthy, the test marked as `TODO`. If a string
340344
is provided, that string is displayed in the test results as the reason why
341345
the test is `TODO`. **Default:** `false`.
346+
* `timeout` {number} A number of milliseconds the test will fail after.
347+
If unspecified, subtests inherit this value from their parent.
348+
**Default:** `30_000`.
342349
* `fn` {Function|AsyncFunction} The function under test. The first argument
343350
to this function is a [`TestContext`][] object. If the test uses callbacks,
344351
the callback function is passed as the second argument. **Default:** A no-op
@@ -519,6 +526,10 @@ test('top level test', (t) => {
519526

520527
<!-- YAML
521528
added: v18.0.0
529+
changes:
530+
- version: REPLACEME
531+
pr-url: https://github.com/nodejs/node/pull/43505
532+
description: add a timeout to tests and allow setting it in options.
522533
-->
523534

524535
* `name` {string} The name of the subtest, which is displayed when reporting
@@ -538,6 +549,9 @@ added: v18.0.0
538549
* `todo` {boolean|string} If truthy, the test marked as `TODO`. If a string
539550
is provided, that string is displayed in the test results as the reason why
540551
the test is `TODO`. **Default:** `false`.
552+
* `timeout` {number} A number of milliseconds the test will fail after.
553+
If unspecified, subtests inherit this value from their parent.
554+
**Default:** `30_000`.
541555
* `fn` {Function|AsyncFunction} The function under test. The first argument
542556
to this function is a [`TestContext`][] object. If the test uses callbacks,
543557
the callback function is passed as the second argument. **Default:** A no-op

‎lib/internal/test_runner/test.js‎

Lines changed: 32 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ const {
99
PromiseResolve,
1010
ReflectApply,
1111
SafeMap,
12+
PromiseRace,
1213
} = primordials;
1314
const { AsyncResource } = require('async_hooks');
1415
const {
@@ -26,20 +27,39 @@ const {
2627
} = require('internal/util');
2728
const { isPromise } = require('internal/util/types');
2829
const { isUint32 } = require('internal/validators');
30+
const { setTimeout } = require('timers/promises');
2931
const { cpus } = require('os');
3032
const { bigint: hrtime } = process.hrtime;
3133
const kCallbackAndPromisePresent = 'callbackAndPromisePresent';
3234
const kCancelledByParent = 'cancelledByParent';
3335
const kParentAlreadyFinished = 'parentAlreadyFinished';
3436
const kSubtestsFailed = 'subtestsFailed';
3537
const kTestCodeFailure = 'testCodeFailure';
38+
const kTestTimeoutFailure = 'testTimeoutFailure';
3639
const kDefaultIndent = ' ';
40+
const kDefaultTimeout = null;
3741
const noop = FunctionPrototype;
3842
const isTestRunner = getOptionValue('--test');
3943
const testOnlyFlag = !isTestRunner && getOptionValue('--test-only');
4044
// TODO(cjihrig): Use uv_available_parallelism() once it lands.
4145
const rootConcurrency = isTestRunner ? cpus().length : 1;
4246

47+
48+
function testTimeout(promise, timeout) {
49+
if (timeout === kDefaultTimeout) {
50+
return promise;
51+
}
52+
return PromiseRace([
53+
promise,
54+
setTimeout(timeout, null, { ref: false }).then(() => {
55+
throw new ERR_TEST_FAILURE(
56+
`test timed out after ${timeout}ms`,
57+
kTestTimeoutFailure
58+
);
59+
}),
60+
]);
61+
}
62+
4363
class TestContext {
4464
#test;
4565

@@ -76,7 +96,7 @@ class Test extends AsyncResource {
7696
super('Test');
7797

7898
let { fn, name, parent, skip } = options;
79-
const { concurrency, only, todo } = options;
99+
const { concurrency, only, timeout, todo } = options;
80100

81101
if (typeof fn !== 'function') {
82102
fn = noop;
@@ -98,6 +118,7 @@ class Test extends AsyncResource {
98118
this.reporter = new TapStream();
99119
this.runOnlySubtests = this.only;
100120
this.testNumber = 0;
121+
this.timeout = kDefaultTimeout;
101122
} else {
102123
const indent = parent.parent === null ? parent.indent :
103124
parent.indent + parent.indentString;
@@ -109,12 +130,17 @@ class Test extends AsyncResource {
109130
this.reporter = parent.reporter;
110131
this.runOnlySubtests = !this.only;
111132
this.testNumber = parent.subtests.length + 1;
133+
this.timeout = parent.timeout;
112134
}
113135

114136
if (isUint32(concurrency) && concurrency !== 0) {
115137
this.concurrency = concurrency;
116138
}
117139

140+
if (isUint32(timeout)) {
141+
this.timeout = timeout;
142+
}
143+
118144
if (testOnlyFlag && !this.only) {
119145
skip = '\'only\' option not set';
120146
}
@@ -329,13 +355,13 @@ class Test extends AsyncResource {
329355
'passed a callback but also returned a Promise',
330356
kCallbackAndPromisePresent
331357
));
332-
await ret;
358+
await testTimeout(ret, this.timeout);
333359
} else {
334-
await promise;
360+
await testTimeout(promise, this.timeout);
335361
}
336362
} else {
337363
// This test is synchronous or using Promises.
338-
await ReflectApply(this.runInAsyncScope, this, args);
364+
await testTimeout(ReflectApply(this.runInAsyncScope, this, args), this.timeout);
339365
}
340366

341367
this.pass();
@@ -480,10 +506,10 @@ class Suite extends Test {
480506
this.parent.activeSubtests++;
481507
this.startTime = hrtime();
482508
const subtests = this.skipped || this.error ? [] : this.subtests;
483-
await ArrayPrototypeReduce(subtests, async (prev, subtest) => {
509+
await testTimeout(ArrayPrototypeReduce(subtests, async (prev, subtest) => {
484510
await prev;
485511
await subtest.run();
486-
}, PromiseResolve());
512+
}, PromiseResolve()), this.timeout);
487513
this.pass();
488514
this.postRun();
489515
}

‎test/message/test_runner_describe_it.js‎

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -316,3 +316,26 @@ describe('describe async throw fails', async () => {
316316
it('should not run', () => {});
317317
throw new Error('thrown from describe');
318318
});
319+
320+
describe('timeouts', () => {
321+
it('timed out async test', { timeout: 5 }, async () => {
322+
return new Promise((resolve) => {
323+
setTimeout(resolve, 1000);
324+
});
325+
});
326+
327+
it('timed out callback test', { timeout: 5 }, (done) => {
328+
setTimeout(done, 1000);
329+
});
330+
331+
332+
it('large timeout async test is ok', { timeout: 30_000_000 }, async () => {
333+
return new Promise((resolve) => {
334+
setTimeout(resolve, 10);
335+
});
336+
});
337+
338+
it('large timeout callback test is ok', { timeout: 30_000_000 }, (done) => {
339+
setTimeout(done, 10);
340+
});
341+
});

‎test/message/test_runner_describe_it.out‎

Lines changed: 39 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -551,8 +551,43 @@ not ok 56 - describe async throw fails
551551
*
552552
*
553553
...
554+
# Subtest: timeouts
555+
# Subtest: timed out async test
556+
not ok 1 - timed out async test
557+
---
558+
duration_ms: *
559+
failureType: 'testTimeoutFailure'
560+
error: 'test timed out after 5ms'
561+
code: 'ERR_TEST_FAILURE'
562+
...
563+
# Subtest: timed out callback test
564+
not ok 2 - timed out callback test
565+
---
566+
duration_ms: *
567+
failureType: 'testTimeoutFailure'
568+
error: 'test timed out after 5ms'
569+
code: 'ERR_TEST_FAILURE'
570+
...
571+
# Subtest: large timeout async test is ok
572+
ok 3 - large timeout async test is ok
573+
---
574+
duration_ms: *
575+
...
576+
# Subtest: large timeout callback test is ok
577+
ok 4 - large timeout callback test is ok
578+
---
579+
duration_ms: *
580+
...
581+
1..4
582+
not ok 57 - timeouts
583+
---
584+
duration_ms: *
585+
failureType: 'subtestsFailed'
586+
error: '2 subtests failed'
587+
code: 'ERR_TEST_FAILURE'
588+
...
554589
# Subtest: invalid subtest fail
555-
not ok 57 - invalid subtest fail
590+
not ok 58 - invalid subtest fail
556591
---
557592
duration_ms: *
558593
failureType: 'parentAlreadyFinished'
@@ -561,16 +596,16 @@ not ok 57 - invalid subtest fail
561596
stack: |-
562597
*
563598
...
564-
1..57
599+
1..58
565600
# 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.
566601
# 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.
567602
# 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.
568603
# 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.
569604
# 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.
570605
# 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.
571-
# tests 57
606+
# tests 58
572607
# pass 23
573-
# fail 20
608+
# fail 21
574609
# cancelled 0
575610
# skipped 9
576611
# todo 5

‎test/message/test_runner_output.js‎

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -328,3 +328,24 @@ test('subtest sync throw fails', async (t) => {
328328
throw new Error('thrown from subtest sync throw fails at second');
329329
});
330330
});
331+
332+
test('timed out async test', { timeout: 5 }, async (t) => {
333+
return new Promise((resolve) => {
334+
setTimeout(resolve, 1000);
335+
});
336+
});
337+
338+
test('timed out callback test', { timeout: 5 }, (t, done) => {
339+
setTimeout(done, 1000);
340+
});
341+
342+
343+
test('large timeout async test is ok', { timeout: 30_000_000 }, async (t) => {
344+
return new Promise((resolve) => {
345+
setTimeout(resolve, 10);
346+
});
347+
});
348+
349+
test('large timeout callback test is ok', { timeout: 30_000_000 }, (t, done) => {
350+
setTimeout(done, 10);
351+
});

‎test/message/test_runner_output.out‎

Lines changed: 31 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -562,8 +562,34 @@ not ok 56 - subtest sync throw fails
562562
error: '2 subtests failed'
563563
code: 'ERR_TEST_FAILURE'
564564
...
565+
# Subtest: timed out async test
566+
not ok 57 - timed out async test
567+
---
568+
duration_ms: *
569+
failureType: 'testTimeoutFailure'
570+
error: 'test timed out after 5ms'
571+
code: 'ERR_TEST_FAILURE'
572+
...
573+
# Subtest: timed out callback test
574+
not ok 58 - timed out callback test
575+
---
576+
duration_ms: *
577+
failureType: 'testTimeoutFailure'
578+
error: 'test timed out after 5ms'
579+
code: 'ERR_TEST_FAILURE'
580+
...
581+
# Subtest: large timeout async test is ok
582+
ok 59 - large timeout async test is ok
583+
---
584+
duration_ms: *
585+
...
586+
# Subtest: large timeout callback test is ok
587+
ok 60 - large timeout callback test is ok
588+
---
589+
duration_ms: *
590+
...
565591
# Subtest: invalid subtest fail
566-
not ok 57 - invalid subtest fail
592+
not ok 61 - invalid subtest fail
567593
---
568594
duration_ms: *
569595
failureType: 'parentAlreadyFinished'
@@ -572,16 +598,16 @@ not ok 57 - invalid subtest fail
572598
stack: |-
573599
*
574600
...
575-
1..57
601+
1..61
576602
# 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.
577603
# 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.
578604
# 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.
579605
# 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.
580606
# 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.
581607
# 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.
582-
# tests 57
583-
# pass 24
584-
# fail 18
608+
# tests 61
609+
# pass 26
610+
# fail 20
585611
# cancelled 0
586612
# skipped 10
587613
# todo 5

0 commit comments

Comments
 (0)
Back | FazBrowse Home | New Git URL