Compare commits
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
fd347d5159 | ||
|
|
f334fe9d20 | ||
|
|
58c6d86b66 | ||
|
|
9704e95100 | ||
|
|
664a909957 | ||
|
|
ef83ad93bb | ||
|
|
48979bf744 |
No files matched your search
+129
-30
@@ -72,6 +72,9 @@ DEMO_REQUIRED_CAPTIONS = (
|
||||
"A file from a newer Timmy is refused with an instruction, and the ledger it would have replaced is untouched",
|
||||
"A restored log still says it began as an AI suggestion you corrected — provenance is part of the record",
|
||||
"Health counters are disclosed where you read privacy facts — they never include notes, photos, image fingerprints, or identity",
|
||||
"The operator health report is a command line, not a screen in the app — this runs it against this recording’s own server",
|
||||
"Every counter on this card came from the requests this recording just made, and a wrong token is refused instead of answered",
|
||||
"The snapshot holds counts, a readiness phase, latency, and enumerated failure classes — no note, photo, image fingerprint, or identity",
|
||||
"The review tool is a command line, not a screen in the app — this runs it against the committed synthetic sample",
|
||||
"The queue shows the proposal and hides the model answer; revealing it is refused until a reviewer commits",
|
||||
"The model said Type 6 and the reviewer said Type 5: the disagreement is recorded, not smoothed over",
|
||||
@@ -102,6 +105,70 @@ def sha256(path: Path) -> str:
|
||||
return digest.hexdigest()
|
||||
|
||||
|
||||
def measure_dead_capture(path: Path, fps: int = 4) -> dict:
|
||||
"""Measure flat, unreadable stretches in the delivered demo.
|
||||
|
||||
A headless compositor that stalls on a contended host emits uniform grey frames: the screen, the
|
||||
caption bar, and every control disappear for as long as the stall lasts. Sampling a shrunken grey
|
||||
raster is enough to tell a dead stretch (near-zero variance) from a terminal card, which is dark
|
||||
but full of text (high variance). A take with a multi-second dead stretch is not reviewable.
|
||||
"""
|
||||
width, height = 72, 128
|
||||
frame_bytes = width * height
|
||||
raw = subprocess.run(
|
||||
["ffmpeg", "-v", "error", "-i", str(path), "-vf", f"fps={fps},scale={width}:{height}",
|
||||
"-pix_fmt", "gray", "-f", "rawvideo", "pipe:1"],
|
||||
check=True, stdout=subprocess.PIPE).stdout
|
||||
frames = len(raw) // frame_bytes
|
||||
runs: list[tuple[int, int]] = []
|
||||
current: list[int] | None = None
|
||||
for index in range(frames):
|
||||
sample = raw[index * frame_bytes:(index + 1) * frame_bytes]
|
||||
mean = sum(sample) / frame_bytes
|
||||
variance = sum((value - mean) ** 2 for value in sample) / frame_bytes
|
||||
flat = variance ** 0.5 < 8 and 90 < mean < 170
|
||||
if flat:
|
||||
if current is None:
|
||||
current = [index, index]
|
||||
else:
|
||||
current[1] = index
|
||||
elif current is not None:
|
||||
runs.append((current[0], current[1]))
|
||||
current = None
|
||||
if current is not None:
|
||||
runs.append((current[0], current[1]))
|
||||
seconds = 1 / fps
|
||||
worst = max(((end - start + 1) * seconds for start, end in runs), default=0.0)
|
||||
total = sum((end - start + 1) * seconds for start, end in runs)
|
||||
duration = frames * seconds
|
||||
return {
|
||||
"sample_fps": fps,
|
||||
"duration_s": round(duration, 2),
|
||||
"runs": [{"start_s": round(start * seconds, 2), "length_s": round((end - start + 1) * seconds, 2)}
|
||||
for start, end in runs],
|
||||
"worst_run_s": round(worst, 2),
|
||||
"total_s": round(total, 2),
|
||||
}
|
||||
|
||||
|
||||
def assert_readable_demo(measurement: dict) -> None:
|
||||
"""Refuse a take whose capture went dead: the recording is the release requirement, not a garnish.
|
||||
|
||||
A single sampled frame of flat grey at a scene change is structural in this pipeline and every
|
||||
accepted take has a dozen of them. A stall that spans several samples is not: it is a dead screen
|
||||
the reviewer is supposed to be watching, so it fails the release.
|
||||
"""
|
||||
stalled = [run["length_s"] for run in measurement["runs"] if run["length_s"] > 0.5]
|
||||
stalled_total = sum(stalled)
|
||||
budget = max(1.0, 0.005 * measurement["duration_s"])
|
||||
if stalled or stalled_total > budget:
|
||||
raise SystemExit(
|
||||
"Release demo capture went dead for "
|
||||
f"{measurement['worst_run_s']}s in one stretch ({stalled_total}s stalled of "
|
||||
f"{measurement['duration_s']}s): re-record on a quiet host instead of shipping a grey screen"
|
||||
)
|
||||
|
||||
|
||||
def assert_port_free(host: str, port: int) -> None:
|
||||
"""Fail closed when something is already listening where the acceptance server must bind."""
|
||||
with socket.socket() as sock:
|
||||
@@ -196,7 +263,10 @@ def main() -> int:
|
||||
run(["python3", "tests/backup-restore.test.py", "-v"], tree)
|
||||
run(["python3", "tests/production-runbook.test.py", "-v"], tree)
|
||||
server_env = dict(os.environ)
|
||||
server_env.update({"HOST": "127.0.0.1", "PORT": "4173", "TIMMY_VISION_ENABLED": "false"})
|
||||
# TIMMY_METRICS_TOKEN gates the operator snapshot for this recording only. It is a demo value
|
||||
# against a loopback-only server, not a credential, and it never appears in an artifact.
|
||||
server_env.update({"HOST": "127.0.0.1", "PORT": "4173", "TIMMY_VISION_ENABLED": "false",
|
||||
"TIMMY_METRICS_TOKEN": "demo-metrics-token-not-a-credential"})
|
||||
# A leftover server from another checkout answers on this port and the readiness probe cannot
|
||||
# tell it apart from ours, so every gate and the recorded demo would silently describe a
|
||||
# different tree. Refuse to build over a live listener, and verify the served bytes afterwards.
|
||||
@@ -233,28 +303,62 @@ def main() -> int:
|
||||
run(["npm", "run", "test:photo-lifecycle"], tree)
|
||||
run(["npm", "run", "test:training-contribution"], tree)
|
||||
run(["npm", "run", "test:portability"], tree)
|
||||
demo_raw = release_dir / f"timmy-talking-turd-{version}-demo.raw.webm"
|
||||
demo = release_dir / f"timmy-talking-turd-{version}-demo.mp4"
|
||||
caption_receipt = release_dir / f"timmy-talking-turd-{version}-demo-captions.json"
|
||||
demo_env = dict(server_env)
|
||||
demo_env["TIMMY_RELEASE_VERSION"] = version
|
||||
demo_env["TIMMY_RELEASE_DEMO_DELTA"] = release_delta
|
||||
demo_env["TIMMY_DEMO_CAPTIONS_OUT"] = str(caption_receipt)
|
||||
run(["node", "scripts/record_release_demo.mjs", str(demo_raw)], tree, env=demo_env)
|
||||
if not caption_receipt.exists():
|
||||
raise SystemExit("Release demo produced no on-camera caption receipt")
|
||||
recorded = json.loads(caption_receipt.read_text(encoding="utf-8"))
|
||||
onscreen = [str(line) for line in (recorded.get("captions") or [])]
|
||||
# A pushed string is not proof of pixels. Only captions the demo measured as a painted,
|
||||
# on-top, in-frame bar (style + elementFromPoint + band pixel change) count as on camera.
|
||||
verified = [str(item.get("text")) for item in (recorded.get("captionsVerified") or [])
|
||||
if item.get("visible") is True and item.get("bandChanged") is True]
|
||||
if recorded.get("releaseDelta") != release_delta or not any(release_delta in line for line in verified):
|
||||
raise SystemExit("Release demo did not state the declared release delta on camera")
|
||||
for required in DEMO_REQUIRED_CAPTIONS:
|
||||
if not any(required in line for line in onscreen):
|
||||
raise SystemExit(f"Release demo is missing a required on-camera caption: {required}")
|
||||
if not any(required in line for line in verified):
|
||||
raise SystemExit(f"Release demo caption never painted on screen: {required}")
|
||||
# A contended host starves the headless compositor and the screencast fills the gap with a
|
||||
# uniform grey screen, caption bar included. That is not a code failure, but it is not
|
||||
# reviewable either, so take a fresh recording until one is readable. Bounded, and how many
|
||||
# takes it took is published in the manifest rather than hidden.
|
||||
attempts = int(os.environ.get("TIMMY_DEMO_ATTEMPTS", "3"))
|
||||
dead_capture = None
|
||||
demo_takes = 0
|
||||
for attempt in range(1, attempts + 1):
|
||||
demo_takes = attempt
|
||||
demo_raw = release_dir / f"timmy-talking-turd-{version}-demo.raw.webm"
|
||||
demo_env = dict(server_env)
|
||||
demo_env["TIMMY_RELEASE_VERSION"] = version
|
||||
demo_env["TIMMY_RELEASE_DEMO_DELTA"] = release_delta
|
||||
demo_env["TIMMY_DEMO_CAPTIONS_OUT"] = str(caption_receipt)
|
||||
run(["node", "scripts/record_release_demo.mjs", str(demo_raw)], tree, env=demo_env)
|
||||
if not caption_receipt.exists():
|
||||
raise SystemExit("Release demo produced no on-camera caption receipt")
|
||||
recorded = json.loads(caption_receipt.read_text(encoding="utf-8"))
|
||||
onscreen = [str(line) for line in (recorded.get("captions") or [])]
|
||||
# A pushed string is not proof of pixels. Only captions the demo measured as a painted,
|
||||
# on-top, in-frame bar (style + elementFromPoint + band pixel change) count as on camera.
|
||||
verified = [str(item.get("text")) for item in (recorded.get("captionsVerified") or [])
|
||||
if item.get("visible") is True and item.get("bandChanged") is True]
|
||||
if recorded.get("releaseDelta") != release_delta or not any(release_delta in line for line in verified):
|
||||
raise SystemExit("Release demo did not state the declared release delta on camera")
|
||||
for required in DEMO_REQUIRED_CAPTIONS:
|
||||
if not any(required in line for line in onscreen):
|
||||
raise SystemExit(f"Release demo is missing a required on-camera caption: {required}")
|
||||
if not any(required in line for line in verified):
|
||||
raise SystemExit(f"Release demo caption never painted on screen: {required}")
|
||||
run(["ffmpeg", "-y", "-v", "error", "-i", str(demo_raw), "-vf", "scale=720:1280:flags=lanczos", "-an", "-c:v", "libx264", "-preset", "fast", "-crf", "20", "-pix_fmt", "yuv420p", "-movflags", "+faststart", str(demo)], tree)
|
||||
demo_raw.unlink()
|
||||
for debris in release_dir.glob("page@*.webm"):
|
||||
debris.unlink()
|
||||
run(["ffmpeg", "-v", "error", "-i", str(demo), "-f", "null", "-"], tree)
|
||||
probe = json.loads(run(["ffprobe", "-v", "error", "-print_format", "json", "-show_streams", "-show_format", str(demo)], tree, capture=True))
|
||||
video_streams = [stream for stream in probe.get("streams", []) if stream.get("codec_type") == "video"]
|
||||
if len(video_streams) != 1 or video_streams[0].get("codec_name") != "h264" or video_streams[0].get("pix_fmt") != "yuv420p" or video_streams[0].get("width") != 720 or video_streams[0].get("height") != 1280:
|
||||
raise SystemExit("Release demo media probe failed")
|
||||
# A stalled compositor paints uniform grey over the whole screen, caption bar included, so
|
||||
# the take reads as a dead channel for as long as the stall lasts. Measure it, do not
|
||||
# eyeball it, and re-record rather than shipping the dead stretch.
|
||||
measurement = measure_dead_capture(demo)
|
||||
try:
|
||||
assert_readable_demo(measurement)
|
||||
except SystemExit:
|
||||
print(json.dumps({"take": attempt, "dead_capture": measurement}), flush=True)
|
||||
if attempt == attempts:
|
||||
raise
|
||||
demo.unlink(missing_ok=True)
|
||||
continue
|
||||
dead_capture = measurement
|
||||
print(json.dumps({"take": attempt, "dead_capture": measurement}), flush=True)
|
||||
break
|
||||
finally:
|
||||
server.terminate()
|
||||
try:
|
||||
@@ -263,14 +367,6 @@ def main() -> int:
|
||||
server.kill()
|
||||
server.wait(timeout=5)
|
||||
server_log.close()
|
||||
demo = release_dir / f"timmy-talking-turd-{version}-demo.mp4"
|
||||
run(["ffmpeg", "-y", "-v", "error", "-i", str(demo_raw), "-vf", "scale=720:1280:flags=lanczos", "-an", "-c:v", "libx264", "-preset", "fast", "-crf", "20", "-pix_fmt", "yuv420p", "-movflags", "+faststart", str(demo)], tree)
|
||||
demo_raw.unlink()
|
||||
run(["ffmpeg", "-v", "error", "-i", str(demo), "-f", "null", "-"], tree)
|
||||
probe = json.loads(run(["ffprobe", "-v", "error", "-print_format", "json", "-show_streams", "-show_format", str(demo)], tree, capture=True))
|
||||
video_streams = [stream for stream in probe.get("streams", []) if stream.get("codec_type") == "video"]
|
||||
if len(video_streams) != 1 or video_streams[0].get("codec_name") != "h264" or video_streams[0].get("pix_fmt") != "yuv420p" or video_streams[0].get("width") != 720 or video_streams[0].get("height") != 1280:
|
||||
raise SystemExit("Release demo media probe failed")
|
||||
contact_sheet = release_dir / f"timmy-talking-turd-{version}-demo-contact-sheet.jpg"
|
||||
# Span the whole recording: a fixed 1/2 fps sheet only covered the first 24s of a longer demo.
|
||||
demo_duration = float(run(["ffprobe", "-v", "error", "-show_entries", "format=duration", "-of", "csv=p=0", str(demo)], tree, capture=True))
|
||||
@@ -406,7 +502,10 @@ def main() -> int:
|
||||
"feature_demo_full_decode": "passed",
|
||||
"feature_demo_media_probe": "passed",
|
||||
"release_delta_visible_on_camera": "passed",
|
||||
"feature_demo_no_dead_capture": "passed",
|
||||
},
|
||||
"demo_dead_capture": dead_capture,
|
||||
"demo_takes": demo_takes,
|
||||
}
|
||||
manifest_path = release_dir / "manifest.json"
|
||||
manifest_path.write_text(json.dumps(manifest, indent=2) + "\n", encoding="utf-8")
|
||||
|
||||
@@ -1537,6 +1537,90 @@ await page.evaluate(node => node.scrollIntoView({ block: 'center' }), await heal
|
||||
await caption('Health counters are disclosed where you read privacy facts — they never include notes, photos, image fingerprints, or identity', 3200);
|
||||
await indicate('[data-health-disclosure]');
|
||||
|
||||
// Issue #19, on camera: the operator report is a command line, not a screen in the app. It runs the
|
||||
// real script against this recording's own server (started with a demo-only loopback token), so every
|
||||
// number printed on the card was produced by the requests this recording just made — the ingress
|
||||
// refusals above are counted, not staged. The same script with a wrong token must be refused rather
|
||||
// than answered, and the token itself must never reach the report.
|
||||
const operatorToken = process.env.TIMMY_METRICS_TOKEN || '';
|
||||
if (!operatorToken) {
|
||||
throw new Error('the demo server must be started with a demo TIMMY_METRICS_TOKEN so the operator report can be exercised');
|
||||
}
|
||||
async function operatorReport(args) {
|
||||
return execFileAsync(process.execPath, ['scripts/model_metrics_report.mjs', ...args], { cwd: process.cwd() })
|
||||
.then(result => ({ code: 0, stdout: result.stdout, stderr: result.stderr }))
|
||||
.catch(error => ({ code: typeof error.code === 'number' ? error.code : 1, stdout: error.stdout || '', stderr: error.stderr || '' }));
|
||||
}
|
||||
const reportRun = await operatorReport(['--url', 'http://127.0.0.1:4173', '--token', operatorToken]);
|
||||
if (reportRun.code !== 0) throw new Error(`the operator report must read the snapshot: ${reportRun.stderr.trim()}`);
|
||||
const refusedRun = await operatorReport(['--url', 'http://127.0.0.1:4173', '--token', 'demo-token-that-is-wrong']);
|
||||
if (refusedRun.code !== 1 || !/rejected the operator token/i.test(refusedRun.stderr)) {
|
||||
throw new Error('a wrong operator token must be refused with a stated reason instead of answered');
|
||||
}
|
||||
if (reportRun.stdout.includes(operatorToken) || refusedRun.stderr.includes('demo-token-that-is-wrong')) {
|
||||
throw new Error('the operator token must never appear in the report or in an error line');
|
||||
}
|
||||
const parsedRows = [];
|
||||
let sections = 0;
|
||||
for (const line of reportRun.stdout.split('\n')) {
|
||||
const match = /^ {2}(\S.*?)\s{2,}(\S.*)$/.exec(line);
|
||||
if (match) { parsedRows.push([match[1].trim(), match[2].trim()]); continue; }
|
||||
const heading = line.trim();
|
||||
if (heading === 'APP' || heading === 'QUEUE' || heading === 'MODEL') {
|
||||
parsedRows.push(['—', '']);
|
||||
parsedRows.push(['section', heading]);
|
||||
sections += 1;
|
||||
}
|
||||
}
|
||||
if (sections !== 3) throw new Error(`the operator report must separate the app, queue, and model boundaries, not ${sections} of them`);
|
||||
const rowValue = pattern => {
|
||||
const found = parsedRows.find(([key]) => pattern.test(key));
|
||||
if (!found) throw new Error(`the operator report is missing the ${pattern} row: ${reportRun.stdout}`);
|
||||
return found[1];
|
||||
};
|
||||
const failureRows = parsedRows.filter(([key]) => /^failure /i.test(key));
|
||||
if (failureRows.length !== 8) throw new Error(`the report must print all eight enumerated failure classes, not ${failureRows.length}`);
|
||||
const failureList = failureRows.map(([key, value]) => `${key.replace(/^failure /i, '')} ${value}`).join(' · ');
|
||||
const analyzeCount = Number(rowValue(/^analyze requests$/i));
|
||||
if (!Number.isFinite(analyzeCount) || analyzeCount < 1) {
|
||||
throw new Error(`the report must count this recording's own requests, not a zero: ${reportRun.stdout}`);
|
||||
}
|
||||
const metricsCard = await evidenceCard({
|
||||
id: 'operator-health-report',
|
||||
title: 'OPERATOR HEALTH REPORT',
|
||||
// Long CLI labels are folded into values on purpose: a key column narrow enough to fit the phone
|
||||
// splits `analyze requests` across two lines and detaches it from its count.
|
||||
subtitle: 'command line, not app UI — loopback :4173, demo token',
|
||||
rows: [
|
||||
['section', 'APP'],
|
||||
['uptime', rowValue(/^uptime$/i)],
|
||||
['requests', `${analyzeCount} analyzed · ${rowValue(/^refused before model$/i)} refused before the model`],
|
||||
['section', 'QUEUE'],
|
||||
['in flight', rowValue(/^in flight$/i)],
|
||||
['accepted', rowValue(/^accepted$/i)],
|
||||
['at capacity', rowValue(/^at capacity$/i)],
|
||||
['section', 'MODEL'],
|
||||
['readiness', rowValue(/^readiness$/i)],
|
||||
['outcomes', rowValue(/^outcomes$/i)],
|
||||
['abstention', rowValue(/^abstention$/i)],
|
||||
['latency', rowValue(/^latency$/i)],
|
||||
['failures', failureList],
|
||||
['—', ''],
|
||||
['wrong token', 'refused · exit 1 · no counters'],
|
||||
],
|
||||
font: '600 9.5px/1.45 ui-monospace, SFMono-Regular, Menlo, monospace',
|
||||
keyWidth: 72,
|
||||
gap: '1px',
|
||||
rowGap: '6px',
|
||||
});
|
||||
await sleep(420);
|
||||
const metricsCardProof = await evidenceCardProof('operator-health-report');
|
||||
if (!metricsCardProof.ok) throw new Error(`Operator report card is not fully readable on screen: ${JSON.stringify(metricsCardProof)}`);
|
||||
await caption('The operator health report is a command line, not a screen in the app — this runs it against this recording’s own server', 3800);
|
||||
await caption('Every counter on this card came from the requests this recording just made, and a wrong token is refused instead of answered', 3600);
|
||||
await caption('The snapshot holds counts, a readiness phase, latency, and enumerated failure classes — no note, photo, image fingerprint, or identity', 4000);
|
||||
await page.evaluate(() => document.querySelector('#operator-health-report')?.remove());
|
||||
|
||||
await indicate('#delete-all');
|
||||
await tap('#delete-all', 650);
|
||||
await page.getByText(/Local ledger and photos deleted/).waitFor();
|
||||
|
||||
@@ -6,7 +6,10 @@
|
||||
// not printed — an unknown failure class is visible as a missing row, never as a new label.
|
||||
import { FAILURE_CLASSES, OUTCOMES } from './model-metrics.js';
|
||||
|
||||
const LABEL_WIDTH = 22;
|
||||
// Wide enough for the longest row label (`failure provider_unreachable`) plus a visible gap: a label
|
||||
// that fills the column renders run-together with its count (`failure ingress_refused0`), which reads
|
||||
// as one broken token instead of a metric.
|
||||
const LABEL_WIDTH = 30;
|
||||
|
||||
function row(label, value) {
|
||||
return ` ${String(label).padEnd(LABEL_WIDTH)}${value}`;
|
||||
|
||||
@@ -80,3 +80,18 @@ test('the report shows queue occupancy against the configured ceiling', () => {
|
||||
assert.match(report, /in flight\s+2 \/ 3/);
|
||||
assert.match(report, /at capacity\s+no/);
|
||||
});
|
||||
|
||||
test('every row keeps a visible gap between its label and its count', () => {
|
||||
const metrics = createModelMetrics({ now: () => Date.parse('2026-11-02T10:00:00.000Z') });
|
||||
// The longest label is the one that used to run together with its value: a column that exactly fits
|
||||
// the text reads as `failure ingress_refused0`, one broken token instead of a metric and its count.
|
||||
metrics.recordAnalyze({ outcome: 'failure', failureClass: 'ingress_refused', durationMs: 5 });
|
||||
const report = formatOperatorReport(metrics.snapshot());
|
||||
|
||||
for (const line of report.split('\n')) {
|
||||
if (!/^ {2}\S/.test(line)) continue;
|
||||
assert.match(line, /^ {2}\S.*?\s{2,}\S/, `row has no gap between label and value: ${JSON.stringify(line)}`);
|
||||
}
|
||||
assert.match(report, /failure ingress_refused\s+1/);
|
||||
assert.match(report, /failure provider_unreachable\s+0/);
|
||||
});
|
||||
@@ -575,3 +575,21 @@ test('release demo shows the privacy-safe health counters where the app disclose
|
||||
assert.match(builder, /Health counters are disclosed where you read privacy facts/);
|
||||
assert.match(builder, /"privacy_safe_health_metrics": "passed"/);
|
||||
});
|
||||
|
||||
test('release demo runs the operator health report against its own server and shows a refused token', async () => {
|
||||
const demo = await readFile(demoPath, 'utf8');
|
||||
const builder = await readFile(builderPath, 'utf8');
|
||||
|
||||
// The disclosure alone does not demonstrate the feature. The recording must run the real CLI, show
|
||||
// counters this recording produced, and prove the wrong-token path is refused rather than answered.
|
||||
assert.match(demo, /scripts\/model_metrics_report\.mjs/);
|
||||
assert.match(demo, /the operator report must read the snapshot/);
|
||||
assert.match(demo, /a wrong operator token must be refused with a stated reason instead of answered/);
|
||||
assert.match(demo, /the report must count this recording's own requests, not a zero/);
|
||||
assert.match(demo, /const metricsCardProof = await evidenceCardProof\('operator-health-report'\)/);
|
||||
// The bearer must never be printed on camera or into an error line.
|
||||
assert.match(demo, /the operator token must never appear in the report or in an error line/);
|
||||
// The demo server has to carry a token, or the report cannot be exercised at all.
|
||||
assert.match(builder, /"TIMMY_METRICS_TOKEN": "demo-metrics-token-not-a-credential"/);
|
||||
assert.match(builder, /The operator health report is a command line, not a screen in the app/);
|
||||
});
|
||||
@@ -2,38 +2,77 @@ import test from 'node:test';
|
||||
import assert from 'node:assert/strict';
|
||||
import { spawn } from 'node:child_process';
|
||||
import { chmod, mkdtemp, rm } from 'node:fs/promises';
|
||||
import { createServer } from 'node:net';
|
||||
import { tmpdir } from 'node:os';
|
||||
import { join } from 'node:path';
|
||||
import { fileURLToPath } from 'node:url';
|
||||
|
||||
const root = fileURLToPath(new URL('..', import.meta.url));
|
||||
const hermesFixture = fileURLToPath(new URL('./fixtures/fake-hermes.mjs', import.meta.url));
|
||||
let nextPort = 43100;
|
||||
|
||||
// A hard-coded base port is not ours to take: 43100 sits inside this host's ephemeral range
|
||||
// (32768-60999), so the kernel can already have handed it to an unrelated outbound socket
|
||||
// (a Caddy -> Gitea connection held 43102) and the spawn dies with EADDRINUSE before any
|
||||
// assertion runs. Ask the kernel for a free port, then retry if one is stolen in the gap.
|
||||
function freePort() {
|
||||
return new Promise((resolve, reject) => {
|
||||
const probe = createServer();
|
||||
probe.once('error', reject);
|
||||
probe.listen(0, '127.0.0.1', () => {
|
||||
const { port } = probe.address();
|
||||
probe.close(() => resolve(port));
|
||||
});
|
||||
});
|
||||
}
|
||||
|
||||
function waitForListening(child, readStdout, timeoutMs = 20_000) {
|
||||
return new Promise(resolve => {
|
||||
let settled = false;
|
||||
const finish = value => {
|
||||
if (settled) return;
|
||||
settled = true;
|
||||
clearTimeout(timer);
|
||||
resolve(value);
|
||||
};
|
||||
const timer = setTimeout(() => finish({ state: 'timeout' }), timeoutMs);
|
||||
child.stdout.on('data', () => {
|
||||
if (/^Timmy is listening on http:\/\//m.test(readStdout())) finish({ state: 'listening' });
|
||||
});
|
||||
child.once('exit', code => finish({ state: 'exit', code }));
|
||||
});
|
||||
}
|
||||
|
||||
async function startServer(t, env = {}) {
|
||||
const port = nextPort++;
|
||||
const origin = `http://127.0.0.1:${port}`;
|
||||
const child = spawn(process.execPath, ['server.mjs'], {
|
||||
cwd: root,
|
||||
env: { ...process.env, PORT: String(port), ...env, ...(env.TIMMY_PUBLIC_ORIGIN === '__ORIGIN__' ? { TIMMY_PUBLIC_ORIGIN: origin } : {}) },
|
||||
stdio: ['ignore', 'pipe', 'pipe'],
|
||||
});
|
||||
let stderr = '';
|
||||
let stdout = '';
|
||||
child.stdout.on('data', chunk => { stdout += chunk; });
|
||||
child.stderr.on('data', chunk => { stderr += chunk; });
|
||||
t.after(() => child.kill('SIGTERM'));
|
||||
const deadline = Date.now() + 10_000;
|
||||
const basePath = (env.TIMMY_BASE_PATH || '').replace(/\/$/, '');
|
||||
while (Date.now() < deadline) {
|
||||
if (child.exitCode !== null) throw new Error(`server exited ${child.exitCode}: ${stderr}`);
|
||||
try {
|
||||
const response = await fetch(`${origin}${basePath}/api/healthz`);
|
||||
if (response.status) return { origin, child, getStdout: () => stdout };
|
||||
} catch {}
|
||||
await new Promise(resolve => setTimeout(resolve, 40));
|
||||
for (let attempt = 1; attempt <= 4; attempt++) {
|
||||
const port = await freePort();
|
||||
const origin = `http://127.0.0.1:${port}`;
|
||||
const child = spawn(process.execPath, ['server.mjs'], {
|
||||
cwd: root,
|
||||
env: { ...process.env, PORT: String(port), ...env, ...(env.TIMMY_PUBLIC_ORIGIN === '__ORIGIN__' ? { TIMMY_PUBLIC_ORIGIN: origin } : {}) },
|
||||
stdio: ['ignore', 'pipe', 'pipe'],
|
||||
});
|
||||
let stderr = '';
|
||||
let stdout = '';
|
||||
child.stdout.on('data', chunk => { stdout += chunk; });
|
||||
child.stderr.on('data', chunk => { stderr += chunk; });
|
||||
|
||||
const outcome = await waitForListening(child, () => stdout);
|
||||
if (outcome.state === 'listening') {
|
||||
t.after(() => child.kill('SIGTERM'));
|
||||
return { origin, child, getStdout: () => stdout };
|
||||
}
|
||||
|
||||
const closed = new Promise(resolve => child.once('close', resolve));
|
||||
if (child.exitCode === null) child.kill('SIGKILL');
|
||||
await closed;
|
||||
|
||||
const stolen = /EADDRINUSE/.test(stderr);
|
||||
if (!stolen || attempt === 4) {
|
||||
throw new Error(outcome.state === 'timeout'
|
||||
? `server did not announce listening: ${stderr}`
|
||||
: `server exited ${outcome.code}${stolen ? ' (port stolen again)' : ''}: ${stderr}`);
|
||||
}
|
||||
}
|
||||
throw new Error(`server did not become ready: ${stderr}`);
|
||||
}
|
||||
|
||||
test('staging host can bind loopback instead of every network interface', async t => {
|
||||
@@ -125,6 +164,30 @@ test('agent cookie is constrained to the normalized base path', async t => {
|
||||
assert.match(response.headers.get('set-cookie'), /; Path=\/timmy-staging\//);
|
||||
});
|
||||
|
||||
// The child's own startup line is the only trustworthy evidence that a base path was accepted.
|
||||
// A fixed timer cannot tell "still importing modules" from "server is up": on a loaded host the
|
||||
// old 800 ms race killed a correctly-rejecting child and reported it as accepted.
|
||||
function startupOutcome(child, deadlineMs = 20_000) {
|
||||
return new Promise(resolve => {
|
||||
let stdout = '';
|
||||
let stderr = '';
|
||||
let settled = false;
|
||||
const finish = outcome => {
|
||||
if (settled) return;
|
||||
settled = true;
|
||||
clearTimeout(timer);
|
||||
resolve({ ...outcome, stdout, stderr });
|
||||
};
|
||||
const timer = setTimeout(() => finish({ timedOut: true }), deadlineMs);
|
||||
child.stdout.on('data', chunk => {
|
||||
stdout += chunk;
|
||||
if (/^Timmy is listening on http:\/\//m.test(stdout)) finish({ listening: true });
|
||||
});
|
||||
child.stderr.on('data', chunk => { stderr += chunk; });
|
||||
child.once('exit', code => finish({ code }));
|
||||
});
|
||||
}
|
||||
|
||||
test('malformed and escaping base paths are rejected at startup', async () => {
|
||||
const invalid = [
|
||||
'timmy-staging',
|
||||
@@ -152,16 +215,17 @@ test('malformed and escaping base paths are rejected at startup', async () => {
|
||||
const child = spawn(process.execPath, ['server.mjs'], {
|
||||
cwd: root,
|
||||
env: { ...process.env, PORT: '0', TIMMY_BASE_PATH: value },
|
||||
stdio: ['ignore', 'ignore', 'pipe'],
|
||||
stdio: ['ignore', 'pipe', 'pipe'],
|
||||
});
|
||||
let stderr = '';
|
||||
child.stderr.on('data', chunk => { stderr += chunk; });
|
||||
const exitCode = await Promise.race([
|
||||
new Promise(resolve => child.once('exit', resolve)),
|
||||
new Promise(resolve => setTimeout(() => { child.kill('SIGTERM'); resolve('timeout'); }, 800)),
|
||||
]);
|
||||
assert.notEqual(exitCode, 'timeout', `${JSON.stringify(value)} was accepted`);
|
||||
assert.notEqual(exitCode, 0, `${JSON.stringify(value)} exited successfully`);
|
||||
assert.match(stderr, /TIMMY_BASE_PATH/);
|
||||
const outcome = await startupOutcome(child);
|
||||
if (outcome.listening) {
|
||||
const closed = new Promise(resolve => child.once('close', resolve));
|
||||
child.kill('SIGKILL');
|
||||
await closed;
|
||||
}
|
||||
assert.equal(outcome.listening, undefined, `${JSON.stringify(value)} was accepted: the server announced it was listening`);
|
||||
assert.notEqual(outcome.timedOut, true, `${JSON.stringify(value)} neither exited nor announced listening within the startup deadline`);
|
||||
assert.notEqual(outcome.code, 0, `${JSON.stringify(value)} exited successfully`);
|
||||
assert.match(outcome.stderr, /TIMMY_BASE_PATH/);
|
||||
}
|
||||
});
|
||||
Reference in new issue
Block a user