test(e2e): un échec ne peut plus emporter les suivants, et les bornes sont mesurées

Trois choses, dont une qui explique pourquoi aucun diagnostic n'aboutissait.

SIGN_IN_MS valait 180 s alors que la somme de ses propres étapes en faisait 270.
La borne englobante se déclenchait donc TOUJOURS avant celle de l'étape en
cause, et ne pouvait dire qu'une chose : « bob-… to sign in ». Le message était
structurellement condamné à ne rien apprendre — on a cherché des jours une cause
que le harnais s'interdisait de nommer. Les bornes englobantes sont maintenant
des sommes calculées de leurs étapes.

Les parcours sont isolés. La suite déclare ses 7 parcours et leurs 27
vérifications AVANT tout lancement de navigateur, et rend donc toujours 34
lignes — y compris quand le montage meurt, où les parcours non exécutés sont
rapportés comme tels. Auparavant le total valait 24, 26 ou 27 selon ce qui
mourait : deux exécutions ne mesuraient même pas la même chose. Un échec est
contenu, pas absorbé — il reste compté.

Et chaque borne est dimensionnée sur une durée MESURÉE, inscrite à côté d'elle
dans le code. Le premier rendu d'un acteur prend 4,9 à 7,4 s et vaut 45 s ; la
traversée du broker 1,3 à 2,8 s et vaut 75 s. Un nombre nu n'apprend rien et
pourrit en silence.

Au passage : un walletPage.close() n'avait aucune borne du tout.
This commit is contained in:
Sylvain Duchesne
2026-08-16 12:28:44 +02:00
parent 1ecf511e9d
commit ed0f872f5d
5 changed files with 965 additions and 187 deletions
+8
View File
@@ -0,0 +1,8 @@
# Doc-debt — e2e-harness
> Presence of a block = doc to update. Processed → delete the block; no blocks left → delete this file.
> One block = one "big change": `why` + `files` + `verify` (leaves to review).
## Raw markers (consolidate into blocks, then delete)
- TOUCHED packages/polyfill/e2e/measure.ts @2026-08-16 (session f93872b5-293a-4916-a353-181409a96d42)
- TOUCHED packages/polyfill/e2e/notebook.ts @2026-08-16 (session f93872b5-293a-4916-a353-181409a96d42)
+36 -7
View File
@@ -49,10 +49,21 @@ export const WALLET_PASSWORD = "ng-eventually-e2e";
const BUILD_MS = 60_000;
/** Launching a browser is local too — 30s is Playwright's own default, doubled. */
const LAUNCH_MS = 60_000;
/** Opening a page in a live browser is instant; a minute means the browser is not answering. */
const NEW_PAGE_MS = 60_000;
/** The whole wallet export measures ~7s against the real broker; two minutes is a hang. */
const EXPORT_MS = 120_000;
/**
* Opening a page in a live browser is instant — measured 0.00.1s over a batch. Bounded at
* 10s, which is a hundred times the measurement and still fails while a reader is watching.
* Exported because the applicative suite has to know it: a caller that wraps `newPage` in a
* TIGHTER bound of its own would fire first and report its own name instead of this one.
*/
export const NEW_PAGE_MS = 10_000;
/**
* The whole wallet export measures ~7s against the real broker. Bounded at 60s ≈ 8x.
*
* Was two minutes, and that cost the batch of 2026-08-16 twice over: the export hung, and the
* suite spent two full minutes reaching a verdict it could have reached in one — before dying
* without a summary, because this runs in the SETUP, ahead of every journey.
*/
const EXPORT_MS = 60_000;
const ENTRY = path.resolve(__dirname, "polyfill-entry.ts");
const BUNDLE_OUT = path.resolve(__dirname, ".dist", "polyfill-entry.js");
@@ -538,9 +549,27 @@ export async function setupBrokerPage(page: Page, appUrl: string): Promise<Frame
// dispatches on it, and stops when a frame is on the application's ORIGIN — an origin the
// broker's pages can never be on, whatever they carry in their query string.
/** One bound for the whole ceremony. Measured healthy: 2.63.9s; the newcomer's cold
* profile pays a broker session-start on top. Two minutes is a hang, not a slow host. */
const BROKER_LOGIN_MS = 120_000;
/**
* One bound for the whole ceremony — the screens, the clicks, and the application's frame
* attaching. Measured 1.32.8s for an actor and 1.7s on a cold profile's barrier passage
* (2026-08-16, `E2E_TIMINGS=1`). Bounded at 45s ≈ 16x the slowest measured: enough that a
* busy host does not manufacture a false diagnosis, little enough
* that the rich failure below — the screen, the trail, the frames, the page's own text —
* arrives in under a minute instead of after two.
*
* Exported for the same reason as {@link NEW_PAGE_MS}: this function's failure message is
* the most informative one in the harness, and an enclosing bound set below it would replace
* that message with "the round-trip timed out" and lose every fact in it.
*/
export const BROKER_LOGIN_MS = 45_000;
/**
* What {@link setupBrokerPage} costs at worst: its navigation plus the ceremony. A caller
* that wants to MEASURE the round-trip should hand this to `measured` rather than invent a
* bound of its own — an enclosure below this number fires before the ceremony can explain
* itself, which is the failure mode `notebook.ts` documents at length.
*/
export const BROKER_ROUND_TRIP_MS = CONTEXT_NAVIGATION_MS + BROKER_LOGIN_MS;
/** How often the browser re-reads the screen. Not a sleep: it is the interval of a
* condition check that runs INSIDE the page, the same mechanism `isVisible` uses. */
const SCREEN_POLL_MS = 200;
+10 -1
View File
@@ -166,8 +166,12 @@ export async function closeQuietly(what: string, close: () => Promise<unknown>):
* cost the hours this module exists to stop spending.
*
* `unref`ed, so a healthy run is never held open by its own watchdog.
*
* `thenReport` lets a suite print its own summary before the process goes — without it a run
* that trips this watchdog reports its waits and then vanishes, so its check count is zero
* and comparable with nothing. (`notebook.ts` passes its `finish`.)
*/
export function armSuiteDeadline(suite: string, ms: number): void {
export function armSuiteDeadline(suite: string, ms: number, thenReport?: () => void): void {
const startedAt = Date.now();
const timer = setTimeout(() => {
console.error(
@@ -188,6 +192,11 @@ export function armSuiteDeadline(suite: string, ms: number): void {
}
}
console.error(` Total elapsed: ${fmtMs(Date.now() - startedAt)}`);
// A suite that can still say what it did and did not verify must be allowed to say it —
// otherwise the watchdog, whose whole purpose is to replace a silent kill with a report,
// produces its own silent kill. `thenReport` is expected to exit; the line below is the
// fallback for a caller that has nothing to report.
if (thenReport !== undefined) thenReport();
process.exit(1);
}, ms);
timer.unref?.();
+113
View File
@@ -0,0 +1,113 @@
/**
* What each bounded operation ACTUALLY takes — the measurement every bound is sized from.
*
* ── Why a bound needs its measurement kept beside it ─────────────────────────
* A bare number teaches nothing and rots in silence. "180 seconds" cannot be judged: is it
* ten times the normal duration, or a hundred? Only one of those is a bound; the other is a
* hang dressed up as one. The suite this module serves had a sign-in bounded at 3 minutes
* for an operation that measures 1.4s, so its single job — turning a hang into a named
* failure fast — was done fifty times too slowly to be worth anything.
*
* So every bound in these harnesses is written as `measured normal → bound → margin`, and
* this module is how the "measured normal" half is obtained and re-obtained. Run any suite
* with `E2E_TIMINGS=1` and it prints, at the end, what each named operation took and how
* much headroom its bound still has. A future reader who suspects a number has gone stale
* does not have to believe this file's comments: they can re-run the measurement.
*
* Passive by default — a `Date.now()` per wait, and nothing printed unless asked.
*/
/** One observation of one named operation. */
interface Sample {
readonly ms: number;
/** Sizing a bound from a FAILED attempt would size it from the bound itself. */
readonly ok: boolean;
/** The bound in force, so the report can show the headroom rather than make one guess it. */
readonly bound: number;
}
const samples = new Map<string, Sample[]>();
export function record(what: string, ms: number, ok: boolean, bound: number): void {
const seen = samples.get(what);
if (seen === undefined) samples.set(what, [{ ms, ok, bound }]);
else seen.push({ ms, ok, bound });
}
/**
* Run a wait under `bound`, recording what it took under the stable name `what`.
*
* The bound is handed TO the task rather than raced against it, deliberately: Playwright's
* own timeout reports the call log ("waiting for locator(…)"), and a race would replace that
* with a message naming only the enclosure. What this adds is the measurement and a stable
* name — not a second, competing deadline.
*
* The name must be stable across runs (no identifiers, no ports) or the table fragments into
* one row per run and measures nothing.
*/
export async function measured<T>(what: string, bound: number, task: (ms: number) => Promise<T>): Promise<T> {
const startedAt = Date.now();
let ok = false;
try {
const out = await task(bound);
ok = true;
return out;
} finally {
record(what, Date.now() - startedAt, ok, bound);
}
}
/** Whether the caller asked for the table. */
export function timingsWanted(): boolean {
return (process.env.E2E_TIMINGS ?? "") !== "";
}
function fmt(ms: number): string {
return ms >= 10_000 ? `${(ms / 1000).toFixed(0)}s` : `${(ms / 1000).toFixed(1)}s`;
}
/**
* Print what was measured: per operation, the healthy observations and the headroom its
* bound has over the SLOWEST of them.
*
* Failed attempts are counted but excluded from the statistics, because an operation that
* hit its bound measures the bound and not the operation — feeding that back into the sizing
* is how a bound ratchets upward for ever, one bad run at a time.
*/
export function printTimings(): void {
if (samples.size === 0) {
console.log("\n── measured durations ── nothing was recorded.");
return;
}
const rows = [...samples.entries()].map(([what, all]) => {
const good = all.filter((s) => s.ok).map((s) => s.ms).sort((a, b) => a - b);
const bound = all[all.length - 1]!.bound;
const failed = all.length - good.length;
return {
what,
n: good.length,
min: good.length === 0 ? null : good[0]!,
max: good.length === 0 ? null : good[good.length - 1]!,
bound,
failed,
};
});
const width = Math.max(...rows.map((r) => r.what.length), 9);
console.log("\n── measured durations (E2E_TIMINGS) ─────────────────────────────────────────");
console.log(
` ${"operation".padEnd(width)} ${"n".padStart(3)} ${"min".padStart(6)} ${"max".padStart(6)}` +
` ${"bound".padStart(6)} headroom failed`,
);
for (const r of rows) {
const headroom = r.max === null || r.max === 0 ? "—" : `${(r.bound / r.max).toFixed(0)}x`;
console.log(
` ${r.what.padEnd(width)} ${String(r.n).padStart(3)} ` +
`${(r.min === null ? "—" : fmt(r.min)).padStart(6)} ${(r.max === null ? "—" : fmt(r.max)).padStart(6)} ` +
`${fmt(r.bound).padStart(6)} ${headroom.padStart(8)} ${r.failed === 0 ? "" : String(r.failed)}`,
);
}
console.log(
" (statistics are over SUCCESSFUL attempts only: a wait that hit its bound measures\n" +
" the bound, and sizing the next bound from it ratchets upward for ever.)",
);
}
File diff suppressed because it is too large Load Diff