ng-eventually/packages/ng-e2e-helpers/src/measure.ts

/**
 * 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.)",
  );
}