diff --git a/src/runtime/api/bun/js_bun_spawn_bindings.rs b/src/runtime/api/bun/js_bun_spawn_bindings.rs index b09111186b3a..8d5a5df6cfdf 100644 --- a/src/runtime/api/bun/js_bun_spawn_bindings.rs +++ b/src/runtime/api/bun/js_bun_spawn_bindings.rs @@ -293,7 +293,7 @@ pub(crate) fn spawn_sync( options.to_js(), &mut bun_test_deadline, ); - // A bun:test deadline that passed while the isolated loop was blocking is reported only now: the loop is torn down and the child reaped, so the runner's callback re-enters nothing that is mid-flight. With an exception pending (spawn failure, termination) the file timer is left armed and reports it from the main loop instead. + // A bun:test deadline that passed while the isolated loop was blocking is reported only now: the loop is torn down and the child reaped, so the runner's callback re-enters nothing that is mid-flight. With an exception pending (spawn failure, termination) the file timer is left armed: the runner reports the deadline when the callback ends, or when that timer fires. if let Some(deadline) = bun_test_deadline && result.is_ok() && !cx.global().has_exception() @@ -1912,10 +1912,10 @@ fn spawn_maybe_sync( .active_file .clone() { - active_file - .get() - .execution - .kill_dangling_processes_on_timeout(cx.global()); + let execution = &mut active_file.get().execution; + // `kill_dangling_processes_on_timeout` skips a concurrent group. The wait of this call ends below in any group. + execution.killed_on_timeout_at = now; + execution.kill_dangling_processes_on_timeout(cx.global()); } let _ = subprocess.try_kill(subprocess.kill_signal); } diff --git a/src/runtime/test_runner/Collection.rs b/src/runtime/test_runner/Collection.rs index 68e37ea7e4bc..cab27a166f10 100644 --- a/src/runtime/test_runner/Collection.rs +++ b/src/runtime/test_runner/Collection.rs @@ -6,7 +6,7 @@ use bun_jsc::{DeprecatedStrong, JSGlobalObject, JSValue, JsResult}; use bun_core::Timespec; use crate::test_runner::bun_test::{ - self, BunTest, BunTestPtr, DescribeScope, HandleUncaughtExceptionResult, + self, BunTest, BunTestPtr, CallbackEnd, DescribeScope, HandleUncaughtExceptionResult, RefDataValue, StepResult, }; use crate::test_runner::bun_test::debug::group; @@ -220,18 +220,20 @@ impl Collection { bstr::BStr::new(this.active_scope().base.name.as_deref().unwrap_or(b"undefined")), )); - if let Some(cfg_data) = BunTest::run_test_callback( + let callback_data = RefDataValue::Collection { active_scope: previous_scope }; + let end = BunTest::run_test_callback( buntest_strong, global_this, callback.get(), &[], false, - RefDataValue::Collection { active_scope: previous_scope }, + callback_data, &Timespec::EPOCH, - ) { + ); + if end != CallbackEnd::Running { // the result is available immediately; queue // Re-derive after re-entrant call per BunTestCell::get aliasing contract. - buntest_strong.get().add_result(cfg_data); + buntest_strong.get().add_result(callback_data); } return Ok(StepResult::Waiting { timeout: Timespec::EPOCH }); diff --git a/src/runtime/test_runner/DoneCallback.rs b/src/runtime/test_runner/DoneCallback.rs index 6345984ea38b..07109261dfde 100644 --- a/src/runtime/test_runner/DoneCallback.rs +++ b/src/runtime/test_runner/DoneCallback.rs @@ -10,6 +10,8 @@ pub(crate) struct DoneCallback { /// Some = not called yet. None = done already called, no-op. pub(crate) r#ref: JsCell>>, pub(crate) called: Cell, // = false + /// `done(error)` failed the running test after the deadline of that test. + pub(crate) failed_late: Cell, pub(crate) entry: RefDataValue, } @@ -20,6 +22,7 @@ impl DoneCallback { let done_callback = DoneCallback { r#ref: JsCell::new(None), called: Cell::new(false), + failed_late: Cell::new(false), entry, }; diff --git a/src/runtime/test_runner/Execution.rs b/src/runtime/test_runner/Execution.rs index 7de4c2887da9..bccb68e90f7b 100644 --- a/src/runtime/test_runner/Execution.rs +++ b/src/runtime/test_runner/Execution.rs @@ -45,7 +45,7 @@ use bun_core::scoped_log; use super::debug::group as group_log; // bun_test.debug.group use super::bun_test::{ - group_begin, AddedInPhase, Around, AroundPhase, BunTest, BunTestPtr, Calling, EntryData, ExecutionEntry, + group_begin, AddedInPhase, Around, AroundPhase, BunTest, BunTestPtr, CallbackEnd, Calling, EntryData, ExecutionEntry, HandleUncaughtExceptionResult, Order, RefDataValue, ScopeMode, StepResult, }; use super::expect::expect_deferred::ExpectDeferred; @@ -97,6 +97,8 @@ pub(crate) struct Execution { /// The entry whose callback is on the stack, which `get_current_state_data()` can't name in a concurrent group. /// Cleared before the call's microtasks drain, because those can resume other tests in the group. pub(crate) on_stack: core::cell::Cell>, + /// When bun last killed a process or ended a `Bun.spawnSync` wait for a timeout that had passed. `EPOCH` = never. + pub(crate) killed_on_timeout_at: Timespec, } pub(crate) struct ConcurrentGroup { @@ -284,6 +286,16 @@ impl ExecutionSequence { false } + /// Whether `handle_uncaught_exception` prints the error of a hook and leaves `result`, so the test doesn't fail. + fn result_survives_hook_error(&self) -> bool { + match self.result { + Result::Pass | Result::Todo => true, + // `skip()` of a test context hides later errors on purpose. + Result::Skip => self.context.is_none(), + _ => false, + } + } + /// For `test.failing`, `Result::Pass` means the callback threw, which is a failed attempt here. fn attempt_failed(&self) -> bool { match self.entry_mode() { @@ -425,6 +437,7 @@ impl Execution { sequences: Box::default(), group_index: 0, on_stack: core::cell::Cell::new(None), + killed_on_timeout_at: Timespec::EPOCH, } } @@ -457,6 +470,7 @@ impl Execution { // SAFETY: bun_vm() returns the live per-thread VM. let kill_count = global_this.bun_vm().as_mut().auto_killer.kill(); if kill_count.processes > 0 { + self.killed_on_timeout_at = now; bun_core::pretty_errorln!( "killed {} dangling process{}", kill_count.processes, @@ -1330,7 +1344,7 @@ fn step_sequence_one( // The callback re-enters and reaches the sequence on its own, so no `&mut` is held across it. let sequence_ptr = NonNull::from(sequence); global_this.bun_vm().as_mut().is_running_vitest_entry = next_item.calling.is_vitest(); - if BunTest::run_test_callback( + let end = BunTest::run_test_callback( buntest_strong, global_this, callback, @@ -1338,14 +1352,17 @@ fn step_sequence_one( next_item.calling == Calling::Jest { done: true }, callback_data, &next_item.timespec, - ) - .is_some() - { + ); + if end != CallbackEnd::Running { *now = Timespec::now_force_real_time(); // SAFETY: re-deref after run_test_callback; sequence_ptr still valid (sequences is a // Box<[ExecutionSequence]>, never reallocated during execution). let sequence = unsafe { &mut *sequence_ptr.as_ptr() }; - if next_item.evaluate_timeout(sequence, now) { + // A failed callback keeps its result, unless bun killed a process for it or it is a hook whose error can't fail the test. + let checks_deadline = end == CallbackEnd::Returned + || buntest_strong.get().execution.killed_on_timeout_at.order(&next_item.timespec) != core::cmp::Ordering::Less + || (Some(next_item_ptr) != sequence.test_entry && sequence.result_survives_hook_error()); + if checks_deadline && next_item.evaluate_timeout(sequence, now) { if let Some(context) = context { TestContext::abort_signal(context, global_this); } diff --git a/src/runtime/test_runner/bun_test.rs b/src/runtime/test_runner/bun_test.rs index ece763c71f91..c5946675697f 100644 --- a/src/runtime/test_runner/bun_test.rs +++ b/src/runtime/test_runner/bun_test.rs @@ -986,24 +986,31 @@ impl BunTest { Self::bun_test_then_or_catch(cx.global(), value.to_js(), context, true) } - fn on_done_error(global_this: &JSGlobalObject, entry: &RefDataValue, error: JSValue) { + /// Whether the error failed the running test after the deadline of that test. + fn on_done_error(global_this: &JSGlobalObject, entry: &RefDataValue, error: JSValue) -> bool { if let Some(strong) = clone_active_strong() { let this = strong.get(); - let is_running_test = this + // `Some` if `entry` is the running test, with whether its deadline has passed. + let running_test_is_late = this .execution .get_current_and_valid_execution_sequence(entry) - .is_some_and(|(sequence, _)| sequence.active_entry == sequence.test_entry); - if is_running_test { + .filter(|(sequence, _)| sequence.active_entry == sequence.test_entry) + .map(|(sequence, _)| { + // SAFETY: arena-owned entry, alive for the lifetime of BunTest + sequence.active_entry.is_some_and(|test| unsafe { test.as_ref() }.is_past_deadline(&Timespec::now_force_real_time())) + }); + if let Some(is_late) = running_test_is_late { this.on_uncaught_exception(global_this, Some(error), false, entry); // As for any other uncaught exception: the test is over whatever its callback returns, // and `on_before_exit()` doesn't drain the event loop of a file that failed. this.add_result(*entry); Self::run_next_tick(&Rc::downgrade(&strong), global_this, *entry); global_this.bun_vm().as_mut().unhandled_error_counter += 1; - return; + return is_late; } } let _ = global_this.bun_vm().as_mut().uncaught_exception(global_this, error, false); + false } pub(crate) fn bun_test_done_callback( @@ -1028,7 +1035,7 @@ impl BunTest { } else { // error is only reported for the first done() call if was_error { - Self::on_done_error(global_this, &this.entry, value); + this.failed_late.set(Self::on_done_error(global_this, &this.entry, value)); } } this.called.set(true); @@ -1330,7 +1337,6 @@ impl BunTest { } } - /// if sync, the result is returned. if async, None is returned. #[optimize(size)] pub(crate) fn run_test_callback( this_strong: &BunTestPtr, @@ -1340,7 +1346,7 @@ impl BunTest { cfg_done_parameter: bool, cfg_data: RefDataValue, timeout: &Timespec, - ) -> Option { + ) -> CallbackEnd { let _g = group_begin!(); // Raw `*mut` (via `UnsafeCell`) — the JS event-loop call below can // re-enter `bun_test_then_or_catch` / `bun_test_done_callback` / @@ -1376,6 +1382,7 @@ impl BunTest { // SAFETY: `UnsafeCell`-derived; sole `&mut` at this point (before JS re-entry). unsafe { (*this).update_min_timeout(global_this, timeout) }; + let mut end = CallbackEnd::Returned; let args_slice: &[JSValue] = if !done_arg.is_empty() { core::slice::from_ref(&done_arg) } else { cfg_args }; // SAFETY: `this_strong` keeps the cell alive and in place for the whole call. let on_stack = unsafe { OnStack::enter(&raw const (*this).execution.on_stack, &cfg_data) }; @@ -1393,6 +1400,7 @@ impl BunTest { { Ok(v) => v, Err(_) => { + end = CallbackEnd::Failed; global_this.clear_termination_exception(); // SAFETY: re-derive after JS callback returned; no outer `&mut` was held across it. unsafe { (*this).on_uncaught_exception(global_this, global_this.try_take_exception(), false, &cfg_data) }; @@ -1436,6 +1444,9 @@ impl BunTest { if let Some(dcb_data) = done_callback.as_class_ref::() { if dcb_data.called.get() { // done callback already called or the callback errored; add result immediately + if dcb_data.failed_late.get() { + end = CallbackEnd::Failed; + } } else { let r = Self::ref_(this_strong, cfg_data); let alias = NonNull::new(r.as_ptr()) @@ -1483,14 +1494,14 @@ impl BunTest { Bun__TestScope__Describe2__bunTestCatch, ); // TODO: properly propagate exception upwards - return None; + return CallbackEnd::Running; } PromiseStatus::Fulfilled => { // Do not register a then callback when it's already fulfilled. let value = bun_jsc::JSPromise::opaque_mut(promise).result(global_this.vm()); // SAFETY: as in the `Rejected` arm. unsafe { (*this).adopt_teardown(&cfg_data, value) }; - return Some(cfg_data); + return end; } PromiseStatus::Rejected => { let value = bun_jsc::JSPromise::opaque_mut(promise).result(global_this.vm()); @@ -1500,7 +1511,7 @@ impl BunTest { // We previously marked it as handled above. - return Some(cfg_data); + return CallbackEnd::Failed; } } } @@ -1509,7 +1520,7 @@ impl BunTest { if dcb_ref.is_some() { // completed asynchronously bun_core::scoped_log!(bun_test_group, "callTestCallback -> wait for done callback"); - return None; + return CallbackEnd::Running; } bun_core::scoped_log!(bun_test_group, "callTestCallback -> sync"); @@ -1517,7 +1528,7 @@ impl BunTest { // SAFETY: re-derived after the JS callback returned; sole `&mut` at this point. unsafe { (*this).adopt_teardown(&cfg_data, result) }; } - Some(cfg_data) + end } /// A promise that follows `returned` if it's a thenable other than a promise. Otherwise `returned`. @@ -1920,6 +1931,16 @@ pub enum HandleUncaughtExceptionResult { pub(crate) type ResultQueue = LinearFifo>; // bun.LinearFifo(.Dynamic) → second generic is the buffer strategy. +/// How a callback that `run_test_callback` called ended. +#[derive(Copy, Clone, PartialEq, Eq)] +pub(crate) enum CallbackEnd { + /// Its promise or its `done` is still pending. + Running, + Returned, + /// It threw, its promise rejected, or its `done(error)` failed the test after the deadline of the test. + Failed, +} + pub(crate) enum StepResult { Waiting { timeout: Timespec }, Complete, @@ -2418,12 +2439,17 @@ impl ExecutionEntry { entry } + /// An entry without a timeout has no deadline. + pub(crate) fn is_past_deadline(&self, now: &Timespec) -> bool { + !self.timespec.eql(&Timespec::EPOCH) && self.timespec.order(now) == core::cmp::Ordering::Less + } + pub(crate) fn evaluate_timeout( &self, sequence: &mut Execution::ExecutionSequence, now: &Timespec, ) -> bool { - if !self.timespec.eql(&Timespec::EPOCH) && self.timespec.order(now) == core::cmp::Ordering::Less { + if self.is_past_deadline(now) { // timed out // SAFETY: pointer-identity comparison only — no deref, no provenance laundering. let is_test_entry = sequence diff --git a/test/js/bun/test/test-test.test.ts b/test/js/bun/test/test-test.test.ts index ffa24fe9ce1b..70fb84689317 100644 --- a/test/js/bun/test/test-test.test.ts +++ b/test/js/bun/test/test-test.test.ts @@ -3,7 +3,7 @@ import { spawn, spawnSync } from "bun"; import { afterAll, afterEach, beforeAll, beforeEach, describe, expect, it, test } from "bun:test"; import { copyFileSync, mkdirSync, realpathSync, rmSync, writeFileSync } from "fs"; import { rm, writeFile } from "fs/promises"; -import { bunEnv, bunExe, tempDir, tmpdirSync } from "harness"; +import { bunEnv, bunExe, normalizeBunSnapshot, tempDir, tmpdirSync } from "harness"; import { tmpdir } from "os"; import { dirname, join } from "path"; @@ -538,6 +538,476 @@ it("test.todo doesnt cause exit code 1", () => { expect(exitCode).toBe(0); }); +describe("a callback that ends after its timeout without a yield", () => { + // Each late callback passes its timeout inside one call, so the runner gets control back only after the callback + // ended: Bun.sleepSync() blocks, and Bun.spawnSync() and tick() wait inside the call. + async function runFixture(name: string, source: string, args: string[] = []) { + using dir = tempDir("late-" + name, { "late.test.js": source, "package.json": "{}" }); + await using proc = spawn({ + cmd: [bunExe(), "test", ...args, "late.test.js"], + cwd: String(dir), + stdout: "ignore", + stderr: "pipe", + env: bunEnv, + }); + const [stderr, exitCode] = await Promise.all([proc.stderr.text(), proc.exited]); + // Errors, test lines, the note under a test line, what a fixture reports with "ran:", and the counts. + const lines = stderr + .split(/\r?\n/) + .filter(line => /^(error: |\((pass|fail|todo)\) | \^ \S|ran: | +\d+ (pass|fail|todo)$)/.test(line)); + const junit = Bun.file(join(String(dir), "junit.xml")); + return { + lines: normalizeBunSnapshot(lines.join("\n")), + junit: (await junit.exists()) ? await junit.text() : "", + exitCode, + }; + } + + // Bun.build() waits for an async plugin setup() inside the call, with the main event loop running. So the + // timeout timer of the test can run under the test callback. + const tick = /*js*/ ` + function tick(ms) { + try { + Bun.build({ + entrypoints: ["./none.ts"], + plugins: [{ name: "tick", setup: () => new Promise((_, reject) => setTimeout(() => reject(new Error("stop")), ms)) }], + }); + } catch {} + } + `; + + test.concurrent("keeps its own result when it threw", async () => { + const { lines, junit, exitCode } = await runFixture( + "throw", + /*js*/ ` + import { afterAll, afterEach, beforeAll, beforeEach, describe, onTestFinished, test } from "bun:test"; + ${tick} + + test("throws", () => { + Bun.sleepSync(30); + throw new Error("thrown by the test"); + }, 10); + test("rejects", async () => { + await 0; + Bun.sleepSync(30); + throw new Error("rejected by the test"); + }, 10); + test("returns a rejected promise", () => { + Bun.sleepSync(30); + return Promise.reject(new Error("rejected promise")); + }, 10); + test("returns an object whose then getter throws", () => { + Bun.sleepSync(30); + return { + get then() { + throw new Error("thrown by the then getter"); + }, + }; + }, 10); + test("returns a thenable that rejects", () => { + Bun.sleepSync(30); + return { + then(_, reject) { + reject(new Error("rejected by the thenable")); + }, + }; + }, 10); + test("returns a thenable whose then() throws", () => { + Bun.sleepSync(30); + return { + then() { + throw new Error("thrown by then()"); + }, + }; + }, 10); + test("calls done(error)", done => { + Bun.sleepSync(30); + done(new Error("passed to done")); + }, 10); + test("calls done(error) from a microtask", done => { + Bun.sleepSync(30); + queueMicrotask(() => done(new Error("passed to done from a microtask"))); + }, 10); + test("calls done(error) from an async callback", async done => { + Bun.sleepSync(30); + done(new Error("passed to done by an async callback")); + }, 10); + test("calls done(error) and returns a thenable", done => { + Bun.sleepSync(30); + done(new Error("passed to done before the thenable")); + return { + then(resolve) { + resolve(); + }, + }; + }, 10); + test("throws after done()", done => { + done(); + Bun.sleepSync(30); + throw new Error("thrown after done()"); + }, 10); + test.failing("test.failing throws", () => { + Bun.sleepSync(30); + throw new Error("the expected failure"); + }, 10); + test.failing("test.failing returns a thenable that rejects", () => { + Bun.sleepSync(30); + return { + then(_, reject) { + reject(new Error("the expected failure")); + }, + }; + }, 10); + test.failing("test.failing with retry throws", () => { + Bun.sleepSync(30); + throw new Error("the expected failure"); + }, { timeout: 10, retry: 1 }); + test.todo("test.todo throws", () => { + Bun.sleepSync(30); + throw new Error("thrown by the todo test"); + }, 10); + test.concurrent("test.concurrent throws", () => { + Bun.sleepSync(30); + throw new Error("thrown by the concurrent test"); + }, 10); + test.concurrent("its sibling", () => {}); + describe("beforeAll throws", () => { + beforeAll(() => { + Bun.sleepSync(30); + throw new Error("thrown by beforeAll"); + }, 10); + test("test", () => {}); + }); + describe("beforeEach throws", () => { + beforeEach(() => { + Bun.sleepSync(30); + throw new Error("thrown by beforeEach"); + }, 10); + test("test", () => {}); + }); + describe("afterEach throws", () => { + afterEach(() => { + Bun.sleepSync(30); + throw new Error("thrown by afterEach"); + }, 10); + test("test", () => {}); + test("a test that threw in time", () => { + throw new Error("thrown in time"); + }); + }); + describe("afterAll throws", () => { + afterAll(() => { + Bun.sleepSync(30); + throw new Error("thrown by afterAll"); + }, 10); + test("test", () => {}); + }); + test("onTestFinished throws", () => { + onTestFinished(() => { + Bun.sleepSync(30); + throw new Error("thrown by onTestFinished"); + }, 10); + }); + + // The error of a hook cannot fail a test whose body already failed as expected, so these two do not fail. + describe("a hook throws in time after the body failed as expected late", () => { + afterEach(() => { + throw new Error("thrown by afterEach in time"); + }); + test.failing("test.failing", () => { + Bun.sleepSync(30); + throw new Error("the expected failure"); + }, 10); + test.todo("test.todo", () => { + Bun.sleepSync(30); + throw new Error("thrown by the todo test"); + }, 10); + }); + + // The timeout timer runs inside tick(), and bun has no process to kill for it. + test("throws after the timeout timer ran under it", () => { + Bun.sleepSync(30); + tick(1); + throw new Error("thrown after the timer ran"); + }, 10); + `, + ["--todo", "--reporter=junit", "--reporter-outfile=junit.xml"], + ); + expect(lines).toMatchInlineSnapshot(` + "error: thrown by the test + (fail) throws + error: rejected by the test + (fail) rejects + error: rejected promise + (fail) returns a rejected promise + error: thrown by the then getter + (fail) returns an object whose then getter throws + error: rejected by the thenable + (fail) returns a thenable that rejects + error: thrown by then() + (fail) returns a thenable whose then() throws + error: passed to done + (fail) calls done(error) + error: passed to done from a microtask + (fail) calls done(error) from a microtask + error: passed to done by an async callback + (fail) calls done(error) from an async callback + error: passed to done before the thenable + (fail) calls done(error) and returns a thenable + error: thrown after done() + (fail) throws after done() + (pass) test.failing throws + (pass) test.failing returns a thenable that rejects + (pass) test.failing with retry throws + error: thrown by the todo test + (todo) test.todo throws + error: thrown by the concurrent test + (fail) test.concurrent throws + (pass) its sibling + error: thrown by beforeAll + (fail) beforeAll throws > (unnamed) + error: thrown by beforeEach + (fail) beforeEach throws > test + error: thrown by afterEach + (fail) afterEach throws > test + error: thrown in time + error: thrown by afterEach + (fail) afterEach throws > a test that threw in time + (pass) afterAll throws > test + error: thrown by afterAll + (fail) afterAll throws > (unnamed) + error: thrown by onTestFinished + (fail) onTestFinished throws + error: thrown by afterEach in time + (pass) a hook throws in time after the body failed as expected late > test.failing + error: thrown by the todo test + error: thrown by afterEach in time + (todo) a hook throws in time after the body failed as expected late > test.todo + error: thrown after the timer ran + (fail) throws after the timeout timer ran under it + 6 pass + 2 todo + 19 fail" + `); + expect(junit).toContain(''); + expect(junit).not.toContain("TimeoutError"); + expect(exitCode).toBe(1); + }); + + test.concurrent("is timed out when it returned, or when its error could not fail the test", async () => { + const { lines, exitCode } = await runFixture( + "returned", + /*js*/ ` + import { afterEach, beforeEach, describe, expect, onTestFinished, test } from "bun:test"; + + test("returns", () => { + Bun.sleepSync(30); + }, 10); + test("resolves", async () => { + await 0; + Bun.sleepSync(30); + }, 10); + test.failing("test.failing returns", () => { + Bun.sleepSync(30); + }, 10); + test("calls done()", done => { + Bun.sleepSync(30); + done(); + }, 10); + test("returns after expect.soft() failed", () => { + expect.soft(1).toBe(2); + Bun.sleepSync(30); + }, 10); + test("returns after a stray rejection", () => { + Promise.reject(new Error("stray rejection")); + Bun.sleepSync(30); + }, 10); + + // The timeout is longer in the next four, because their failure has to come before the timeout. + test("calls done(error) in time and returns late", done => { + done(new Error("passed to done in time")); + Bun.sleepSync(300); + }, 250); + test.failing("test.failing calls done(error) in time and returns late", done => { + done(new Error("the expected failure")); + Bun.sleepSync(300); + }, 250); + + // The matcher waits for the promise, fails in a microtask, and the test does not await it. + function failsUnawaited() { + const { promise, resolve } = Promise.withResolvers(); + expect(promise).resolves.toBe(2); + resolve(1); + } + test("returns after a matcher it did not await failed", async () => { + failsUnawaited(); + for (let i = 0; i < 8; i++) await 0; + Bun.sleepSync(300); + }, 250); + test.failing("test.failing returns after a matcher it did not await failed", async () => { + failsUnawaited(); + for (let i = 0; i < 8; i++) await 0; + Bun.sleepSync(300); + }, 250); + + describe("afterEach returns late after a test that threw in time", () => { + afterEach(() => { + Bun.sleepSync(30); + }, 10); + // bun skips the hooks behind a hook that timed out, so this one does not run. + afterEach(() => { + console.error("ran: the afterEach behind the late one"); + }); + test("test", () => { + throw new Error("thrown in time"); + }); + test.failing("test.failing", () => { + throw new Error("the expected failure"); + }); + }); + + // The error of done(error) in a hook does not fail the test that the hook runs for. + describe("beforeEach calls done(error)", () => { + beforeEach(done => { + Bun.sleepSync(30); + done(new Error("passed to done by beforeEach")); + }, 10); + test("test", () => {}); + }); + + // The error of a hook cannot fail a test whose body already failed as expected. + describe("a hook throws after the body failed as expected in time", () => { + describe("afterEach", () => { + afterEach(() => { + Bun.sleepSync(30); + throw new Error("thrown by afterEach"); + }, 10); + test.failing("test.failing", () => { + throw new Error("the expected failure"); + }); + test.todo("test.todo", () => { + throw new Error("thrown by the todo test"); + }); + }); + test.failing("onTestFinished, test.failing", () => { + onTestFinished(() => { + Bun.sleepSync(30); + throw new Error("thrown by onTestFinished"); + }, 10); + throw new Error("the expected failure"); + }); + }); + `, + ["--todo"], + ); + expect(lines).toMatchInlineSnapshot(` + "(fail) returns + ^ this test timed out after 10ms. + (fail) resolves + ^ this test timed out after 10ms. + (fail) test.failing returns + ^ this test timed out after 10ms. + (fail) calls done() + ^ this test timed out after 10ms, before its done callback was called. If a done callback was not intended, remove the last parameter from the test callback function + error: expect(received).toBe(expected) + (fail) returns after expect.soft() failed + ^ this test timed out after 10ms. + error: stray rejection + (fail) returns after a stray rejection + ^ this test timed out after 10ms. + error: passed to done in time + (fail) calls done(error) in time and returns late + ^ this test timed out after 250ms, before its done callback was called. If a done callback was not intended, remove the last parameter from the test callback function + (fail) test.failing calls done(error) in time and returns late + ^ this test timed out after 250ms, before its done callback was called. If a done callback was not intended, remove the last parameter from the test callback function + error: expect(received).toBe(expected) + (fail) returns after a matcher it did not await failed + ^ this test timed out after 250ms. + (fail) test.failing returns after a matcher it did not await failed + ^ this test timed out after 250ms. + error: thrown in time + (fail) afterEach returns late after a test that threw in time > test + ^ a beforeEach/afterEach hook timed out for this test. + (fail) afterEach returns late after a test that threw in time > test.failing + ^ a beforeEach/afterEach hook timed out for this test. + error: passed to done by beforeEach + (fail) beforeEach calls done(error) > test + ^ a beforeEach/afterEach hook timed out before its done callback was called. If a done callback was not intended, remove the last parameter from the hook callback function + error: thrown by afterEach + (fail) a hook throws after the body failed as expected in time > afterEach > test.failing + ^ a beforeEach/afterEach hook timed out for this test. + error: thrown by the todo test + error: thrown by afterEach + (fail) a hook throws after the body failed as expected in time > afterEach > test.todo + ^ a beforeEach/afterEach hook timed out for this test. + error: thrown by onTestFinished + (fail) a hook throws after the body failed as expected in time > onTestFinished, test.failing + ^ a beforeEach/afterEach hook timed out for this test. + 0 pass + 16 fail" + `); + expect(exitCode).toBe(1); + }); + + test.concurrent("is timed out when bun killed a process for its timeout before it threw", async () => { + const { lines, exitCode } = await runFixture( + "killed", + /*js*/ ` + import { test } from "bun:test"; + ${tick} + const cmd = [process.execPath, "-e", "setTimeout(() => {}, 60_000)"]; + + // This test is the first one, so the timer of the file is set to its deadline. The timer runs inside + // tick(), and bun kills the child there. + test("throws after bun killed the process it spawned", () => { + Bun.spawn({ cmd, stdio: ["ignore", "ignore", "ignore"] }); + tick(100); + throw new Error("thrown after bun killed the child"); + }, 50); + + // Bun.spawnSync() kills its child when the timeout passes, and the test throws because of that. + const child = () => Bun.spawnSync({ cmd }); + test("throws after Bun.spawnSync outlived the timeout", () => { + if (child().exitCode !== 0) throw new Error("the child did not exit with 0"); + }, 100); + test.failing("test.failing throws after Bun.spawnSync outlived the timeout", () => { + if (child().exitCode !== 0) throw new Error("the child did not exit with 0"); + }, 100); + test.failing("test.failing rejects after Bun.spawnSync outlived the timeout", async () => { + await 0; + if (child().exitCode !== 0) throw new Error("the child did not exit with 0"); + }, 100); + test.concurrent("test.concurrent throws after Bun.spawnSync outlived the timeout", () => { + if (child().exitCode !== 0) throw new Error("the child of the concurrent test did not exit with 0"); + }, 100); + test.concurrent.failing("test.concurrent.failing throws after Bun.spawnSync outlived the timeout", () => { + if (child().exitCode !== 0) throw new Error("the child did not exit with 0"); + }, 100); + `, + ); + expect(lines).toMatchInlineSnapshot(` + "error: thrown after bun killed the child + (fail) throws after bun killed the process it spawned + ^ this test timed out after 50ms. + error: the child did not exit with 0 + (fail) throws after Bun.spawnSync outlived the timeout + ^ this test timed out after 100ms. + (fail) test.failing throws after Bun.spawnSync outlived the timeout + ^ this test timed out after 100ms. + (fail) test.failing rejects after Bun.spawnSync outlived the timeout + ^ this test timed out after 100ms. + error: the child of the concurrent test did not exit with 0 + (fail) test.concurrent throws after Bun.spawnSync outlived the timeout + ^ this test timed out after 100ms. + (fail) test.concurrent.failing throws after Bun.spawnSync outlived the timeout + ^ this test timed out after 100ms. + 0 pass + 6 fail" + `); + expect(exitCode).toBe(1); + }); +}); + it("test timeouts when expected", () => { const path = join(tmp, "test-timeout.test.js"); copyFileSync(join(import.meta.dir, "timeout-test-fixture.js"), path); diff --git a/test/js/bun/test/vitest-flavor.test.ts b/test/js/bun/test/vitest-flavor.test.ts index c343e3008134..054bea270851 100644 --- a/test/js/bun/test/vitest-flavor.test.ts +++ b/test/js/bun/test/vitest-flavor.test.ts @@ -540,6 +540,111 @@ describe.concurrent("test context", () => { }); }); + test("a callback that throws after its timeout keeps its own result, and one that returns is timed out", async () => { + // Each callback blocks for longer than its timeout before it yields, so the timeout timer cannot run first. + const { log, results, errors, stderr, exitCode } = await runTests({ + "a.test.js": ` + import { afterEach, aroundEach, describe, expect, onTestFinished, test } from "vitest"; + const block = () => Bun.sleepSync(30); + test("throws", { timeout: 10 }, ({ signal }) => { + onTestFinished(() => console.log("throws, signal.aborted:", signal.aborted)); + block(); + throw new Error("thrown by the test"); + }); + test("returns", { timeout: 10 }, ({ signal }) => { + onTestFinished(() => console.log("returns, signal.aborted:", signal.aborted)); + block(); + }); + test("skips", { timeout: 10 }, ({ skip }) => { + block(); + skip(); + }); + test("throws after expect.soft() failed", { timeout: 10 }, () => { + expect.soft(1).toBe(2); + block(); + throw new Error("thrown after expect.soft()"); + }); + test("returns after expect.soft() failed", { timeout: 10 }, () => { + expect.soft(1).toBe(2); + block(); + }); + test("onTestFinished throws", () => { + onTestFinished(() => { block(); throw new Error("thrown by onTestFinished"); }, 10); + }); + describe("afterEach throws after its test failed", () => { + afterEach(() => { block(); throw new Error("thrown by afterEach"); }, 10); + test("test", () => { throw new Error("thrown in time"); }); + }); + describe("afterEach returns after its test failed", () => { + afterEach(block, 10); + test("test", () => { throw new Error("thrown in time"); }); + }); + describe("aroundEach throws in its set-up", () => { + aroundEach(() => { block(); throw new Error("thrown by the set-up"); }, 10); + test("test", () => {}); + }); + describe("aroundEach throws in its teardown", () => { + // The timeout is longer here because the set-up has to call runTest() before it. + aroundEach(async runTest => { await runTest(); Bun.sleepSync(300); throw new Error("thrown by the teardown"); }, 250); + test("test", () => {}); + }); + describe("afterEach throws after skip()", () => { + afterEach(() => { block(); throw new Error("thrown by afterEach after skip()"); }, 10); + test("test", ({ skip }) => skip()); + }); + // The runner reports an error for the next two, so they failed and did not only return. + describe("aroundEach returns without runTest()", () => { + aroundEach(() => block(), 10); + test("test", () => {}); + }); + const withFixture = test.extend({ late: async ({}, use) => block() }); + withFixture("a fixture returns without use()", { timeout: 10 }, ({ late }) => {}); + `, + }); + const lines = stderr.split("\n"); + const timedOut = lines.flatMap((line, i) => + /^ \^ .*timed out/.test(line) ? [lines[i - 1].replace(/ \[[\d.]+ms\]$/, "")] : [], + ); + expect({ log, results, timedOut, errors, exitCode }).toEqual({ + log: ["throws, signal.aborted: false", "returns, signal.aborted: true"], + results: [ + "(fail) throws", + "(fail) returns", + "(skip) skips", + "(fail) throws after expect.soft() failed", + "(fail) returns after expect.soft() failed", + "(fail) onTestFinished throws", + "(fail) afterEach throws after its test failed > test", + "(fail) afterEach returns after its test failed > test", + "(fail) aroundEach throws in its set-up > test", + "(fail) aroundEach throws in its teardown > test", + "(skip) afterEach throws after skip() > test", + "(fail) aroundEach returns without runTest() > test", + "(fail) a fixture returns without use()", + ], + timedOut: [ + "(fail) returns", + "(fail) returns after expect.soft() failed", + "(fail) afterEach returns after its test failed > test", + ], + errors: [ + "error: thrown by the test", + "error: expect(received).toBe(expected)", + "error: thrown after expect.soft()", + "error: expect(received).toBe(expected)", + "error: thrown by onTestFinished", + "error: thrown in time", + "error: thrown by afterEach", + "error: thrown in time", + "error: thrown by the set-up", + "error: thrown by the teardown", + "AroundHookSetupError: The `runTest()` callback was not called in the `aroundEach` hook. Make sure to call `runTest()` to run the test.", + 'error: Fixture "late" returned without calling use()', + ], + exitCode: 1, + }); + }); + test("annotate() records into task.annotations", async () => { const { log, exitCode } = await runTests({ "a.test.js": ` diff --git a/test/js/node/test_runner/fixtures/30-late-throw-without-yield.js b/test/js/node/test_runner/fixtures/30-late-throw-without-yield.js new file mode 100644 index 000000000000..1ca2e3c7dc10 --- /dev/null +++ b/test/js/node/test_runner/fixtures/30-late-throw-without-yield.js @@ -0,0 +1,37 @@ +// node-test.test.ts runs this with `--timeout 50`. No body yields before it +// blocks past that timeout, so the timeout timer cannot run first. +const { test } = require("node:test"); +const bunTest = require("bun:test"); + +const block = () => Atomics.wait(new Int32Array(new SharedArrayBuffer(4)), 0, 0, 100); + +test("throws", () => { + block(); + throw new Error("thrown by the test"); +}); + +test("returns", () => { + block(); +}); + +// node:test fails this test with an error of its own, so the test did not only return. +test("expectFailure returns", { expectFailure: true }, () => { + block(); +}); + +// node:test accepts this error and ends the test without one, so the test only returned. +test("expectFailure throws", { expectFailure: true }, () => { + block(); + throw new Error("the expected failure"); +}); + +// The error of a bun:test hook cannot fail a test that called t.skip(), so the timeout of the hook does. +bunTest.describe("t.skip(), then a bun:test hook throws", () => { + bunTest.afterEach(() => { + block(); + throw new Error("thrown by the hook"); + }); + test("test", t => { + t.skip(); + }); +}); diff --git a/test/js/node/test_runner/node-test.test.ts b/test/js/node/test_runner/node-test.test.ts index 2a27963203c0..118d0925153c 100644 --- a/test/js/node/test_runner/node-test.test.ts +++ b/test/js/node/test_runner/node-test.test.ts @@ -141,6 +141,30 @@ describe("node:test", () => { }); }); + test("should report the error of a test that throws after the timeout, and time out one that returns", async () => { + const { exitCode, stderr } = await runTests(["30-late-throw-without-yield.js"], {}, ["--timeout", "50"]); + const lines = stderr.split(/\r?\n/).map(line => line.replace(/ \[[\d.]+ms\]$/, "")); + const results = lines.filter(line => /^\((pass|fail)\) /.test(line)); + const timedOut = lines.flatMap((line, i) => (/^ \^ .*timed out/.test(line) ? [lines[i - 1]] : [])); + const errors = lines.filter(line => line.startsWith("error: ")); + expect({ errors, results, timedOut, exitCode }).toEqual({ + errors: ["error: thrown by the test", "error: test was expected to fail but passed", "error: thrown by the hook"], + results: [ + "(fail) throws", + "(fail) returns", + "(fail) expectFailure returns", + "(fail) expectFailure throws", + "(fail) t.skip(), then a bun:test hook throws > test", + ], + timedOut: [ + "(fail) returns", + "(fail) expectFailure throws", + "(fail) t.skip(), then a bun:test hook throws > test", + ], + exitCode: 1, + }); + }); + test("should not leak file-level beforeEach hooks across files in one process", async () => { const { exitCode, stderr } = await runTests(["14-root-hooks-a.js", "14-root-hooks-b.js"]); expect(stderr).toContain("4 pass");