voyage/tests/lib/timing.test.mjs

// tests/lib/timing.test.mjs
// The shared timing helpers (tests/helpers/timing.mjs, tests/helpers/hook-helper.mjs):
//   - fastestWithin keeps its limit and measures up to three runs, passing on
//     the fastest. Load only ever ADDS time, so the fastest run is the best
//     reading of the real cost: a real slowness is slow every time and still
//     fails; one run slowed by a busy machine does not.
//   - The hook helper's kill limit (HOOK_TIMEOUT_MS) is long by default and
//     overridable per call.
//   - CONTROL_RUN gives the red-proof control run a timeout with headroom over
//     a slow start, and a hang that outlasts it.

import { test } from 'node:test';
import { strict as assert } from 'node:assert';
import { mkdtempSync, rmSync, writeFileSync } from 'node:fs';
import { tmpdir } from 'node:os';
import { join } from 'node:path';
import { CONTROL_RUN, fastestWithin } from '../helpers/timing.mjs';
import { HOOK_TIMEOUT_MS, runHookWithEnv } from '../helpers/hook-helper.mjs';

/** A measure that returns the given durations in turn (no real waiting). */
const stub = (durations) => {
  let i = 0;
  return async () => durations[i++];
};

test('timing: a stub that is slow every time fails the limit (a real slowness is felled)', async () => {
  const r = await fastestWithin(800, stub([900, 950, 1200]));
  assert.equal(r.ok, false);
  assert.deepEqual(r.runs, [900, 950, 1200]);
  assert.equal(r.fastest, 900);
});

test('timing: one slow run of three is tolerated - the next run under the limit passes', async () => {
  const r = await fastestWithin(800, stub([1500, 300, 2000]));
  assert.equal(r.ok, true);
  assert.deepEqual(r.runs, [1500, 300], 'stops at the first run under the limit');
});

test('timing: the limit itself is not loosened - a run AT the limit is not under it', async () => {
  const r = await fastestWithin(800, stub([800, 800, 800]));
  assert.equal(r.ok, false);
});

test('timing: a first run under the limit passes at once (one run on a quiet machine)', async () => {
  const r = await fastestWithin(800, stub([120]));
  assert.equal(r.ok, true);
  assert.deepEqual(r.runs, [120]);
});

test('hook helper: the kill limit is far above 5 s by default, and a call can set its own', async () => {
  assert.ok(HOOK_TIMEOUT_MS >= 30_000, `HOOK_TIMEOUT_MS = ${HOOK_TIMEOUT_MS}`);
  const dir = mkdtempSync(join(tmpdir(), 'hook-helper-'));
  try {
    const slow = join(dir, 'slow-hook.mjs');
    writeFileSync(slow, "setTimeout(() => { process.stdout.write('done'); process.exit(0); }, 400);\n");
    const killed = await runHookWithEnv(slow, '{}', {}, { timeoutMs: 100 });
    assert.notEqual(killed.code, 0, 'a per-call limit below the hook\'s run time kills it');
    const done = await runHookWithEnv(slow, '{}', {});
    assert.equal(done.code, 0);
    assert.equal(done.stdout, 'done');
  } finally { rmSync(dir, { recursive: true, force: true }); }
});

test('red proof control run: the timeout leaves headroom over a slow start and the hang outlasts it', () => {
  const c = CONTROL_RUN;
  const seen = JSON.stringify(c);
  assert.ok(c.slowStartMs > 2000, `the simulated slow start is above the old 2 s timeout: ${seen}`);
  assert.ok(c.timeoutMs >= 15000, `the timeout leaves headroom over a loaded machine: ${seen}`);
  assert.equal(c.timeoutMs % 1000, 0, `a whole number of seconds (the reason prints Math.round(timeoutMs / 1000)): ${seen}`);
  assert.ok(c.timeoutMs >= 6 * c.slowStartMs, `the timeout is at least 6x the simulated slow start: ${seen}`);
  assert.ok(c.hangMs >= c.timeoutMs + 30000, `the hang outlasts the timeout by 30 s: ${seen}`);
  assert.ok(c.hangMs < 2 ** 31 - 1, `the hang fits a real timer (below 2^31-1 ms): ${seen}`);
});