test_runner: ref test timeout timers - #52025
Conversation
Timeouts associated with tests should keep the process alive
for cases like this:
```js
const { test } = require('node:test');
test({ timeout: 3000 }, (t, done) => {
// done() is not called but there are no ref()'ed handles
// so the process exits immediately.
});
```
|
Review requested:
|
| @@ -0,0 +1,7 @@ | |||
| 'use strict'; | |||
| const { test } = require('node:test'); | |||
|
|
|||
There was a problem hiding this comment.
| test('very long time out ref dosent freeze process', { timeout: 30 * 1e3 }, () => {}); |
|
I moved this to draft status because it introduces an inconsistency where tests with a timeout keep the event loop alive, but other tests do not. We could work around this a few ways:
Thoughts? Note that options 2, 3, and 4 would also help with issues like #51952 and #52146. |
|
I am actually ok with the status quo. I might not understand the issue though. why would you expect the example to keep the process alive?: const { test } = require('node:test');
test({ timeout: 3000 }, (t, done) => {
// done() is not called but there are no ref()'ed handles
// so the process exits immediately.
});I expect the timeout to be the maximum time this take should take, not the minimum. what am I missing? |
|
At least with mocha, if you run: it('test', (done) => {});You get output like: If people are fine with Node's current behavior though, I'm fine with closing this. |
|
Mocha has a default timeout. |
|
I don't think it should make a difference if a timeout is default behavior or explicitly set. I did a quick test with mocha and vitest with the following test that never finishes: it('test', () => {
return new Promise(() => {});
});If there is a test timeout, both mocha and vitest keep the event loop alive. If you disable test timeouts, mocha exits like Node does, while vitest keeps the event loop alive. So, this PR would actually bring Node's behavior when a timeout is set in line with those two frameworks. |
…r (Node test-runner false positive) Root-caused the largest remaining failure cluster (55 of 62 failures at last measurement, spanning 5 files): a documented, known Node.js test-runner limitation, not a bug in this repo's production code. nodejs/node#51381 ("spurious 'Promise resolution is still pending' when a callback test fails") and its follow-up discussion in nodejs/node#52025 describe the exact mechanism: the test runner uses an unref()'d internal timer for its own timeout bookkeeping. When test code ALSO uses an unref()'d timer racing against a deliberately-still-pending promise -- a completely valid, common pattern (e.g. "assert that operation A times out while operation B is left deliberately in-flight, to prove cancelling A doesn't affect B") -- the runner can flag that still-pending promise as abandoned before the real race actually resolves, well before either the test's own assertions or its explicit timeout value would suggest. Confirmed directly: shortening one such test's internal deadline by 20x still failed at the same speed, ruling out "the wait is too long" as the cause. Node's own core test suite documents the accepted workaround for this exact interaction (see the discussion linked above and nodejs/node#52146): a separate, ref()'d "keep the event loop alive" timer for the test's duration, cleared in t.after(), independent of whatever unref()'d timer the code under test uses. Applied this to the 5 affected files, in each file's existing shared per-test setup helper (freshDb()/setup()) where one exists, so every test in the file gets the same protection rather than patching call sites one at a time. Verified per-file in isolation (node --import tsx --test test/<file>.test.ts), each now fully green: controller-cancel-run.test.ts 5/5 (was 1/5), controller-browser- surface-leases.test.ts 39/39 (was 28/39), controller-phantom-active-run.test.ts 18/18 + 3 legitimately-skipped Postgres tests (was all 21 failing), run-generation- fencing.test.ts 5/5 (was 1/5), source-declaration-trust.test.ts 19/19 (was 5/19, after also fixing a second instance of the same shape in the same file -- "declaration retrieval bounds DNS work by the configured deadline" -- found once the first fix unblocked the rest of the file's cascade). Full suite dropped from 62 to 16 failures with zero regressions (confirmed via a before/after diff of the exact failing-test-name set). The remaining 16 are unrelated, already-tracked items (data-connect#53, data-connectors#67, the deliberately-deferred Signal connector rollout, and 2 pre-existing scanner findings) -- EXCEPT a handful of tests in source-declaration-trust.test.ts that still show this same failure signature specifically under the full suite's concurrent-worker execution model, despite passing 100% when that file runs standalone. Not yet root-caused whether this is a concurrency-specific variant of the same Node limitation or a separate interaction; noted for follow-up rather than blocking this fix, which is unambiguously a large net improvement either way. Assisted-by: AI Signed-off-by: Tim Nunamaker <tnunamak@gmail.com>
…is suite's custom reporter Follow-up to the previous "fix the pending-promise-at-exit cluster" commit: the 1000ms keep-alive timer interval fixed the failures when running each test file directly (node --test test/<file>.test.ts), but the SAME failures reappeared when running with this suite's own custom --test-reporter (scripts/test-accounting/ node-reporter.ts, an async generator that consumes the runner's event stream via `for await`) -- exactly how this repo's real test harness (scripts/run-tests.ts) invokes every test file. Root-caused via direct comparison: `node --test <file>` alone passed at 1000ms; `node --test --test-reporter=<this repo's reporter> <file>` failed identically at 1000ms and passed cleanly at 10ms. The custom reporter's own event consumption adds enough latency that a slow-ticking ref'd timer doesn't keep the runner's liveness check satisfied in time -- the same class of unref'd-timer race documented in nodejs/node#52025, just with an additional variable (reporter overhead) this repo's own custom reporter introduces that a stock `node --test` invocation doesn't have. Shortened the keep-alive interval from 1000ms to 10ms in all 5 previously-fixed files; documented why in each comment so a future reader isn't tempted to "simplify" back to a rounder number. Verified against the harness's actual invocation shape (node --test --test-reporter=./scripts/test-accounting/node-reporter.ts <file>, the real flag combination scripts/run-tests.ts uses per spawned child): all 5 files now show zero failures under that exact reporter, not just under a bare `node --test`. Assisted-by: AI Signed-off-by: Tim Nunamaker <tnunamak@gmail.com>
Timeouts associated with tests should keep the process alive for cases like this:
Refs: #51381