Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -77,4 +77,4 @@ pnpm-lock.yaml

.ai-workspace/
/processes/
.probe
.probe*
19 changes: 10 additions & 9 deletions bun.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

2 changes: 1 addition & 1 deletion distilled
Submodule distilled updated 113 files
15 changes: 14 additions & 1 deletion packages/alchemy-test/src/FileLog.ts
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,10 @@ export const formatEvent = (event: TestEvent): string | undefined => {
switch (event._tag) {
case "RunStart":
return `running ${event.tests.length} tests from ${event.files} files (${new Date().toISOString()})\n\n`;
case "TestRetry": {
const title = `${event.test.file} > ${event.test.titlePath.join(" > ")}`;
return `RETRY ${title} — attempt ${event.attempt} failed:\n${event.error}\n\n`;
}
case "TestEnd": {
const title = `${event.test.file} > ${event.test.titlePath.join(" > ")}`;
const retries =
Expand Down Expand Up @@ -79,6 +83,13 @@ export const formatEvent = (event: TestEvent): string | undefined => {

export interface FileLog {
readonly append: (event: TestEvent) => Effect.Effect<void>;
/**
* Append a raw pre-formatted chunk. Used for records that are not test
* events — e.g. the RUN INTERRUPTED trailer written when the process is
* killed externally (SIGINT/SIGTERM) mid-run. Best-effort: write failures
* are ignored.
*/
readonly appendRaw: (text: string) => Effect.Effect<void>;
/**
* Enqueue one live file-hook log line (prefixed with the file it belongs
* to). File-level hooks (beforeAll deploys / afterAll destroys) can run
Expand Down Expand Up @@ -145,6 +156,8 @@ export const makeFileLog = Effect.fn(function* (logFile: string) {
.writeFileString(logFile, chunk, { flag: "a" })
.pipe(Effect.ignore);
};
const appendRaw: FileLog["appendRaw"] = (text) =>
fs.writeFileString(logFile, text, { flag: "a" }).pipe(Effect.ignore);
// Hook lines flow through an unbounded queue to a single writer fiber so
// the capture site (a synchronous array-push interception) never performs
// I/O and never blocks: `offerUnsafe` on an unbounded queue is a plain
Expand Down Expand Up @@ -176,5 +189,5 @@ export const makeFileLog = Effect.fn(function* (logFile: string) {
yield* Queue.end(hookLines);
yield* Fiber.await(writer);
});
return { append, appendHookLine, close } satisfies FileLog;
return { append, appendRaw, appendHookLine, close } satisfies FileLog;
});
10 changes: 10 additions & 0 deletions packages/alchemy-test/src/PlainReporter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -249,6 +249,16 @@ const onEvent = (
state.running.delete(`${event.file} :: ${event.hook}`);
state.lastEnd = Date.now();
});
case "TestRetry": {
// The failed attempt's error prints NOW — the retry may run for
// minutes, and if the process is killed during it this line is the
// only console record of what went wrong.
const title = `${dim(event.test.file)} ${dim(">")} ${event.test.titlePath.join(` ${dim(">")} `)}`;
const firstLine = event.error.split("\n", 1)[0] ?? event.error;
return write(
`${yellow("↻")} ${title} ${yellow(`attempt ${event.attempt} failed — retrying`)}\n${indent(dim(firstLine))}`,
);
}
case "TestEnd": {
state.running.delete(event.test.id);
state.lastEnd = Date.now();
Expand Down
16 changes: 16 additions & 0 deletions packages/alchemy-test/src/Reporter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -95,6 +95,22 @@ export type TestEvent =
/** LIVE reference to the test's captured-output buffer (see FileStart). */
readonly logs?: ReadonlyArray<LogEntry>;
}
| {
/**
* An attempt failed and the test is about to be re-run. Emitted BEFORE
* the retry starts so the failed attempt's error reaches the console
* and the run log immediately — without this, a test that spends
* several timeouts' worth of wall clock across retries leaves no trace
* on disk until its final TestEnd, and an externally-killed run
* (SIGTERM/SIGINT) loses the failure entirely.
*/
readonly _tag: "TestRetry";
readonly test: TestMeta;
/** 1-based number of the attempt that just failed. */
readonly attempt: number;
/** Pretty-printed failure of that attempt. */
readonly error: string;
}
| {
readonly _tag: "TestEnd";
readonly test: TestMeta;
Expand Down
98 changes: 95 additions & 3 deletions packages/alchemy-test/src/Runner.ts
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ import { inspect } from "node:util";
import { pathToFileURL } from "node:url";

import { makeFileLog } from "./FileLog.ts";
import { writeDirect } from "./StrayOutput.ts";
import type { FileSuite, Hook, LogEntry, Suite, TestCase } from "./Model.ts";
import { containsOnly, forEachTest, titlePath } from "./Model.ts";
import * as Registry from "./Registry.ts";
Expand Down Expand Up @@ -381,11 +382,40 @@ interface TestAttempt {
readonly afterEach: Exit.Exit<void, unknown>;
}

/**
* Marker failure for a body that hit its per-test timeout. Distinguished
* from ordinary failures because a timed-out attempt is NEVER retried —
* see {@link attemptNeedsRetry}.
*/
class TestTimeoutError extends Error {
override name = "TestTimeoutError";
}

/** Did the attempt's body fail by hitting its per-test timeout? */
const failedByTimeout = (exit: Exit.Exit<TestAttempt, unknown>): boolean =>
Exit.isSuccess(exit) &&
exit.value.body !== undefined &&
Exit.isFailure(exit.value.body) &&
exit.value.body.cause.reasons.some(
(reason) =>
reason._tag === "Fail" && reason.error instanceof TestTimeoutError,
);

const attemptNeedsRetry = (
exit: Exit.Exit<TestAttempt, unknown>,
expectsFailure: boolean | undefined,
): boolean => {
if (Exit.isFailure(exit)) return !wasInterrupted(exit);
// A per-test timeout is never retried. The attempt already consumed the
// test's ENTIRE time budget, and its body fiber may have been abandoned
// mid-teardown (still running detached, still holding locks/state) — a
// re-run races the abandoned attempt AND multiplies the wall-clock cost
// by (1 + retries). On real cloud suites that pushed a single wedged
// 120s-timeout test past external wall clocks (`timeout 240`, CI limits,
// Ctrl+C), which killed the whole runner with a SIGTERM/SIGINT-style
// exit 130 and a truncated run log before the failure was ever reported.
// Hitting the timeout IS the result; report it immediately.
if (failedByTimeout(exit)) return false;
if (
Exit.isFailure(exit.value.beforeEach) ||
Exit.isFailure(exit.value.afterEach)
Expand All @@ -399,6 +429,17 @@ const attemptNeedsRetry = (
);
};

/** Compact description of why an attempt failed (for TestRetry events). */
const attemptFailure = (exit: Exit.Exit<TestAttempt, unknown>): string => {
if (Exit.isFailure(exit)) return prettyCause(exit.cause);
const hook = hookError(exit.value);
if (hook !== undefined) return hook;
const body = exit.value.body;
return body !== undefined && Exit.isFailure(body)
? prettyCause(body.cause)
: "unknown failure";
};

const hookError = (attempt: TestAttempt): string | undefined => {
const errors: Array<string> = [];
if (Exit.isFailure(attempt.beforeEach)) {
Expand Down Expand Up @@ -451,7 +492,7 @@ const runBodyWithTimeout = Effect.fn(function* (
Effect.timeoutOption(Duration.millis(INTERRUPT_GRACE_MS)),
);
return Exit.fail(
new Error(
new TestTimeoutError(
Option.isNone(settled)
? `test timed out after ${timeoutMs}ms (teardown did not settle within ${INTERRUPT_GRACE_MS}ms and was abandoned)`
: `test timed out after ${timeoutMs}ms`,
Expand Down Expand Up @@ -542,6 +583,15 @@ const runTest = Effect.fn(function* (test: TestCase, ctx: ExecContext) {
retries < (test.retry ?? ctx.options.retry)
) {
retries++;
// Announce the failed attempt BEFORE re-running: the retry may take
// minutes (or the run may be killed during it) — the attempt's error
// must already be on the console and in the run log by then.
yield* ctx.emit({
_tag: "TestRetry",
test: meta,
attempt: retries,
error: attemptFailure(exit),
});
// Clear IN PLACE — TestStart handed this array's reference out.
logs.length = 0;
exit = yield* runAttempt();
Expand Down Expand Up @@ -727,6 +777,49 @@ export const run = Effect.fn(function* (options: RunOptions) {
const emit = (event: TestEvent): Effect.Effect<void> =>
reporter.emit(event).pipe(Effect.andThen(fileLog.append(event)));

// Hoisted run state, shared with the interruption trailer below: results
// reported so far, currently-executing test fibers, and the announced
// test total.
const allResults: Array<{ meta: TestMeta; result: TestResult }> = [];
const running = new Map<string, Fiber.Fiber<unknown, unknown>>();
const totals = { tests: 0 };

// When the process is killed externally (Ctrl+C, a `timeout N` wrapper,
// a CI wall clock — all of which the platform runMain converts into an
// interruption of this fiber and an exit-130), the run would otherwise
// die silently: no failure report, and a run log that simply stops after
// `running N tests...`. This finalizer runs on the CLI scope's close with
// the run's exit; on interruption it drains the live hook-line queue and
// appends an attributed trailer so the log always records what was in
// flight when the run was killed.
yield* Effect.addFinalizer((exit) =>
Effect.gen(function* () {
if (!wasInterrupted(exit)) return;
const passed = allResults.filter(
(r) => r.result.status === "pass",
).length;
const failed = allResults.filter(
(r) => r.result.status === "fail",
).length;
const inFlight = [...running.keys()];
const lines = [
`RUN INTERRUPTED (killed by signal — Ctrl+C, timeout wrapper, or CI limit) after ${((Date.now() - startedAt) / 1000).toFixed(1)}s`,
`${allResults.length}/${totals.tests} tests reported (${passed} passed, ${failed} failed)`,
...(inFlight.length === 0
? []
: ["still running when killed:", ...inFlight.map((id) => ` ${id}`)]),
];
// Drain queued hook lines first so the trailer is the log's last word.
yield* fileLog.close;
yield* fileLog.appendRaw(`\n${lines.join("\n")}\n`);
yield* Effect.sync(() => {
writeDirect(
`\nrun interrupted — partial results in ${options.logFile}\n`,
);
});
}),
);

const absoluteFiles = yield* discover(options).pipe(Effect.orDie);
const relative = absoluteFiles.map((f) => path.relative(options.root, f));
yield* emit({ _tag: "CollectStart", files: relative });
Expand Down Expand Up @@ -779,17 +872,16 @@ export const run = Effect.fn(function* (options: RunOptions) {
};
walk(c.suite);
}
totals.tests = allMetas.length;
yield* emit({
_tag: "RunStart",
files: collected.length,
tests: allMetas,
});

// Phase 2 — run files concurrently.
const allResults: Array<{ meta: TestMeta; result: TestResult }> = [];
const fileFailures: Array<{ file: string; error: string }> = [];
const lock = yield* Semaphore.make(EXCLUSIVE_PERMITS);
const running = new Map<string, Fiber.Fiber<unknown, unknown>>();
const completed = new Set<string>();
const testIndex = new Map<string, { test: TestCase; ctx: ExecContext }>();

Expand Down
Loading
Loading