GeezerVison is showing github.com — test_runner: support timeout for tests · nodejs/node@e404a3e
File treeExpand file treeCollapse file tree Open diff view settings Expand file treeCollapse file tree Open diff view settings Collapse file Copy file name to clipboardExpand all lines: doc/api/test.md +14Lines changed: 14 additions & 0 deletions - Display the source diff
- Display the rich diff
| Original file line number | Diff line number | Diff line change |
|---|
@@ -320,6 +320,10 @@ internally. | 320 | 320 |
| 321 | 321 | <!-- YAML | 322 | 322 | 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. | 323 | 327 | --> | 324 | 328 |
| 325 | 329 | * `name` {string} The name of the test, which is displayed when reporting test | @@ -339,6 +343,9 @@ added: v18.0.0 | 339 | 343 | * `todo` {boolean|string} If truthy, the test marked as `TODO`. If a string | 340 | 344 | is provided, that string is displayed in the test results as the reason why | 341 | 345 | 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`. | 342 | 349 | * `fn` {Function|AsyncFunction} The function under test. The first argument | 343 | 350 | to this function is a [`TestContext`][] object. If the test uses callbacks, | 344 | 351 | the callback function is passed as the second argument. **Default:** A no-op | @@ -519,6 +526,10 @@ test('top level test', (t) => { | 519 | 526 |
| 520 | 527 | <!-- YAML | 521 | 528 | 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. | 522 | 533 | --> | 523 | 534 |
| 524 | 535 | * `name` {string} The name of the subtest, which is displayed when reporting | @@ -538,6 +549,9 @@ added: v18.0.0 | 538 | 549 | * `todo` {boolean|string} If truthy, the test marked as `TODO`. If a string | 539 | 550 | is provided, that string is displayed in the test results as the reason why | 540 | 551 | 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`. | 541 | 555 | * `fn` {Function|AsyncFunction} The function under test. The first argument | 542 | 556 | to this function is a [`TestContext`][] object. If the test uses callbacks, | 543 | 557 | the callback function is passed as the second argument. **Default:** A no-op | |
Collapse file Copy file name to clipboardExpand all lines: lib/internal/test_runner/test.js +32-6Lines changed: 32 additions & 6 deletions | Original file line number | Diff line number | Diff line change |
|---|
| 9 | 9 | PromiseResolve, | 10 | 10 | ReflectApply, | 11 | 11 | SafeMap, | | 12 | + PromiseRace, | 12 | 13 | } = primordials; | 13 | 14 | const { AsyncResource } = require('async_hooks'); | 14 | 15 | const { | @@ -26,20 +27,39 @@ const { | 26 | 27 | } = require('internal/util'); | 27 | 28 | const { isPromise } = require('internal/util/types'); | 28 | 29 | const { isUint32 } = require('internal/validators'); | | 30 | +const { setTimeout } = require('timers/promises'); | 29 | 31 | const { cpus } = require('os'); | 30 | 32 | const { bigint: hrtime } = process.hrtime; | 31 | 33 | const kCallbackAndPromisePresent = 'callbackAndPromisePresent'; | 32 | 34 | const kCancelledByParent = 'cancelledByParent'; | 33 | 35 | const kParentAlreadyFinished = 'parentAlreadyFinished'; | 34 | 36 | const kSubtestsFailed = 'subtestsFailed'; | 35 | 37 | const kTestCodeFailure = 'testCodeFailure'; | | 38 | +const kTestTimeoutFailure = 'testTimeoutFailure'; | 36 | 39 | const kDefaultIndent = ' '; | | 40 | +const kDefaultTimeout = null; | 37 | 41 | const noop = FunctionPrototype; | 38 | 42 | const isTestRunner = getOptionValue('--test'); | 39 | 43 | const testOnlyFlag = !isTestRunner && getOptionValue('--test-only'); | 40 | 44 | // TODO(cjihrig): Use uv_available_parallelism() once it lands. | 41 | 45 | const rootConcurrency = isTestRunner ? cpus().length : 1; | 42 | 46 |
| | 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 | + | 43 | 63 | class TestContext { | 44 | 64 | #test; | 45 | 65 |
| @@ -76,7 +96,7 @@ class Test extends AsyncResource { | 76 | 96 | super('Test'); | 77 | 97 |
| 78 | 98 | let { fn, name, parent, skip } = options; | 79 | | - const { concurrency, only, todo } = options; | | 99 | + const { concurrency, only, timeout, todo } = options; | 80 | 100 |
| 81 | 101 | if (typeof fn !== 'function') { | 82 | 102 | fn = noop; | @@ -98,6 +118,7 @@ class Test extends AsyncResource { | 98 | 118 | this.reporter = new TapStream(); | 99 | 119 | this.runOnlySubtests = this.only; | 100 | 120 | this.testNumber = 0; | | 121 | + this.timeout = kDefaultTimeout; | 101 | 122 | } else { | 102 | 123 | const indent = parent.parent === null ? parent.indent : | 103 | 124 | parent.indent + parent.indentString; | @@ -109,12 +130,17 @@ class Test extends AsyncResource { | 109 | 130 | this.reporter = parent.reporter; | 110 | 131 | this.runOnlySubtests = !this.only; | 111 | 132 | this.testNumber = parent.subtests.length + 1; | | 133 | + this.timeout = parent.timeout; | 112 | 134 | } | 113 | 135 |
| 114 | 136 | if (isUint32(concurrency) && concurrency !== 0) { | 115 | 137 | this.concurrency = concurrency; | 116 | 138 | } | 117 | 139 |
| | 140 | + if (isUint32(timeout)) { | | 141 | + this.timeout = timeout; | | 142 | + } | | 143 | + | 118 | 144 | if (testOnlyFlag && !this.only) { | 119 | 145 | skip = '\'only\' option not set'; | 120 | 146 | } | @@ -329,13 +355,13 @@ class Test extends AsyncResource { | 329 | 355 | 'passed a callback but also returned a Promise', | 330 | 356 | kCallbackAndPromisePresent | 331 | 357 | )); | 332 | | - await ret; | | 358 | + await testTimeout(ret, this.timeout); | 333 | 359 | } else { | 334 | | - await promise; | | 360 | + await testTimeout(promise, this.timeout); | 335 | 361 | } | 336 | 362 | } else { | 337 | 363 | // This test is synchronous or using Promises. | 338 | | - await ReflectApply(this.runInAsyncScope, this, args); | | 364 | + await testTimeout(ReflectApply(this.runInAsyncScope, this, args), this.timeout); | 339 | 365 | } | 340 | 366 |
| 341 | 367 | this.pass(); | @@ -480,10 +506,10 @@ class Suite extends Test { | 480 | 506 | this.parent.activeSubtests++; | 481 | 507 | this.startTime = hrtime(); | 482 | 508 | const subtests = this.skipped || this.error ? [] : this.subtests; | 483 | | - await ArrayPrototypeReduce(subtests, async (prev, subtest) => { | | 509 | + await testTimeout(ArrayPrototypeReduce(subtests, async (prev, subtest) => { | 484 | 510 | await prev; | 485 | 511 | await subtest.run(); | 486 | | - }, PromiseResolve()); | | 512 | + }, PromiseResolve()), this.timeout); | 487 | 513 | this.pass(); | 488 | 514 | this.postRun(); | 489 | 515 | } | |
Collapse file Copy file name to clipboardExpand all lines: test/message/test_runner_describe_it.js +23Lines changed: 23 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -316,3 +316,26 @@ describe('describe async throw fails', async () => { | 316 | 316 | it('should not run', () => {}); | 317 | 317 | throw new Error('thrown from describe'); | 318 | 318 | }); | | 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 | +}); |
Collapse file Copy file name to clipboardExpand all lines: test/message/test_runner_describe_it.out +39-4Lines changed: 39 additions & 4 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -551,8 +551,43 @@ not ok 56 - describe async throw fails | 551 | 551 | * | 552 | 552 | * | 553 | 553 | ... | | 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 | + ... | 554 | 589 | # Subtest: invalid subtest fail | 555 | | -not ok 57 - invalid subtest fail | | 590 | +not ok 58 - invalid subtest fail | 556 | 591 | --- | 557 | 592 | duration_ms: * | 558 | 593 | failureType: 'parentAlreadyFinished' | @@ -561,16 +596,16 @@ not ok 57 - invalid subtest fail | 561 | 596 | stack: |- | 562 | 597 | * | 563 | 598 | ... | 564 | | -1..57 | | 599 | +1..58 | 565 | 600 | # 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. | 566 | 601 | # 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. | 567 | 602 | # 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. | 568 | 603 | # 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. | 569 | 604 | # 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. | 570 | 605 | # 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 | 572 | 607 | # pass 23 | 573 | | -# fail 20 | | 608 | +# fail 21 | 574 | 609 | # cancelled 0 | 575 | 610 | # skipped 9 | 576 | 611 | # todo 5 | |
Collapse file Copy file name to clipboardExpand all lines: test/message/test_runner_output.js +21Lines changed: 21 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -328,3 +328,24 @@ test('subtest sync throw fails', async (t) => { | 328 | 328 | throw new Error('thrown from subtest sync throw fails at second'); | 329 | 329 | }); | 330 | 330 | }); | | 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 | +}); |
Collapse file Copy file name to clipboardExpand all lines: test/message/test_runner_output.out +31-5Lines changed: 31 additions & 5 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -562,8 +562,34 @@ not ok 56 - subtest sync throw fails | 562 | 562 | error: '2 subtests failed' | 563 | 563 | code: 'ERR_TEST_FAILURE' | 564 | 564 | ... | | 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 | + ... | 565 | 591 | # Subtest: invalid subtest fail | 566 | | -not ok 57 - invalid subtest fail | | 592 | +not ok 61 - invalid subtest fail | 567 | 593 | --- | 568 | 594 | duration_ms: * | 569 | 595 | failureType: 'parentAlreadyFinished' | @@ -572,16 +598,16 @@ not ok 57 - invalid subtest fail | 572 | 598 | stack: |- | 573 | 599 | * | 574 | 600 | ... | 575 | | -1..57 | | 601 | +1..61 | 576 | 602 | # 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. | 577 | 603 | # 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. | 578 | 604 | # 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. | 579 | 605 | # 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. | 580 | 606 | # 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. | 581 | 607 | # 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 | 585 | 611 | # cancelled 0 | 586 | 612 | # skipped 10 | 587 | 613 | # todo 5 | |
|