diff --git a/scripts/confirmatory_anchor.py b/scripts/confirmatory_anchor.py new file mode 100644 index 00000000..8cd02865 --- /dev/null +++ b/scripts/confirmatory_anchor.py @@ -0,0 +1,106 @@ +"""Push the confirmatory run's anchors outside the run. + +Usage: + python scripts/confirmatory_anchor.py --repo DIR ANCHORS + +The runner calls this every 15 minutes and at its end (with up to three final +tries), with a snapshot of its `anchors.jsonl`: each line holds every log's +line count and chain head at a time. The snapshot is a copy, not a record. +This copies it to `anchors.jsonl` in DIR, a clone checked out on a branch +of its own, commits it and pushes the branch to its remote. The remote's record +of each push is the anchor's time from outside the run: a log edited after an +anchor was pushed no longer matches that anchor's head. + +An exclusive non-blocking lock in the clone's `.git` directory covers every +read, copy, commit and push. Every Git command inherits its descriptor, so a +surviving command keeps the clone busy even if this helper alone is killed. +Ordinary local hooks and remote helpers inherit it too. The per-command +`core.fsmonitor=false` disables normal index-triggered fsmonitor startup. +A configured hook can still run `git fsmonitor--daemon start`, whose child +closes inherited descriptors; this falls under the configured-command limit: +configured commands must retain the descriptor without unlocking it in any +background clone writer. This advisory lock does not cover independent +writers or replacement of the lock file. The lock is local: processes on an +external remote server never hold it. The remote's safety rests on the byte-prefix +check and ordinary non-force pushes. + +A credential-cache daemon or any other descriptor holder can keep the clone +busy up to the holder's lifetime (the credential cache defaults to 900 +seconds), indefinitely if it never exits or closes the descriptor. Every +later try, including all three final tries, then fails as busy and is reported +as a failed push. A busy clone fails without changing its records. Under the +lock, the clone's current file must be a byte prefix of the snapshot (equality +is allowed): a delayed older command cannot replace newer evidence. This +checks bytes, not JSON or line boundaries; the runner supplies complete, +synced lines. Git's own index.lock is left alone; a git failure is a failed +push. Never force-push. +""" + +from __future__ import annotations + +import argparse +import fcntl +import hashlib +import subprocess +import sys +from pathlib import Path + + +def git(repo: Path, lock_fd: int, *args: str) -> str: + """Run Git with the clone lock inherited, retaining failures for the caller.""" + return subprocess.run( + ["git", "-c", "core.fsmonitor=false", "-C", str(repo), *args], + check=True, + capture_output=True, + text=True, + pass_fds=(lock_fd,), + ).stdout + + +def main(argv=None) -> int: + """Push a whole snapshot only while exclusively extending the clone's file.""" + parser = argparse.ArgumentParser(description=__doc__.split("\n\n")[0]) + parser.add_argument("--repo", type=Path, required=True, help="the anchors clone") + parser.add_argument("anchors", type=Path, help="a snapshot of the run's anchors.jsonl") + args = parser.parse_args(argv) + repo = args.repo.expanduser() + target = repo / "anchors.jsonl" + with (repo / ".git" / "confirmatory-anchor.lock").open("a") as lock: + try: + fcntl.flock(lock.fileno(), fcntl.LOCK_EX | fcntl.LOCK_NB) + except BlockingIOError: + print( + "anchor clone busy: another helper or Git process holds its lock", + file=sys.stderr, + ) + return 1 + snapshot = args.anchors.read_bytes() + current = target.read_bytes() if target.exists() else b"" + if not snapshot.startswith(current): + print( + "refusing anchor snapshot: the clone's anchors.jsonl is not a byte " + "prefix of the snapshot", + file=sys.stderr, + ) + return 1 + if snapshot != current or not target.exists(): + target.write_bytes(snapshot) + lines = snapshot.decode().splitlines() + git(repo, lock.fileno(), "add", "anchors.jsonl") + if git(repo, lock.fileno(), "status", "--porcelain", "--", "anchors.jsonl"): + head = hashlib.sha256(lines[-1].encode()).hexdigest() if lines else "none" + git( + repo, + lock.fileno(), + "commit", + "-q", + "-m", + f"anchor {len(lines)}: {head}", + ) + git(repo, lock.fileno(), "push", "-q", "origin", "HEAD") + print(f"pushed {len(lines)} anchors") + return 0 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/scripts/confirmatory_no_tools.py b/scripts/confirmatory_no_tools.py new file mode 100644 index 00000000..d165a950 --- /dev/null +++ b/scripts/confirmatory_no_tools.py @@ -0,0 +1,537 @@ +#!/usr/bin/env python3 +"""Run the confirmatory no-tools stage with complete, recoverable attempts. + +Every model runs in its own thread, in draw order, under a shared $5 ceiling. +A replaced final is moved byte for byte into ``households/attempts`` before +its rerun; the final links every archive by number, hash, status and reason. +Re-invocation resumes solely from those files and is an operator's approval +to rerun a paused account failure. Native harness resume is never used. +""" + +from __future__ import annotations + +import argparse +import fcntl +import json +import math +import os +import re +import signal +import sys +import threading +from pathlib import Path + +# confirmatory_run pins the harness and policybench to this checkout. +from confirmatory_run import ( + CHEAP, + MAX_RERUNS, + PROMPT_VERSION, + action, + attempt_cost, + classify, + default_completion, + pilot, + sha256_file, + write_json, +) + +NO_TOOLS_CAP = 5.0 + + +class StateError(ValueError): + """The files cannot describe an intact no-tools attempt history.""" + + +def component(value: str) -> str: + """A record/model name must name one ordinary path component.""" + if ( + not isinstance(value, str) + or value in ("", ".", "..") + or Path(value).name != value + ): + raise StateError(f"invalid path component {value!r}") + return value + + +def read_record(path: Path) -> dict: + try: + record = json.loads(path.read_text()) + if not isinstance(record, dict): + raise ValueError("record is not a JSON object") + if "prior_attempts" in record: + raise ValueError("native prior_attempts cannot preserve full attempts") + if not isinstance(record.get("attempts"), list): + raise ValueError("record lacks an attempts list") + cost = attempt_cost(record) + if not math.isfinite(cost) or cost < 0: + raise ValueError("attempt cost must be finite and nonnegative") + return record + except (OSError, ValueError, TypeError, AttributeError) as error: + raise StateError(f"{path}: {error}") from error + + +def entry(path: Path, record: dict, n: int) -> dict: + cls, reason = classify(record, 0.0, 0.0, None) + return { + "n": n, + "file": f"attempts/{path.name}", + "sha256": sha256_file(path), + "status": record.get("status"), + "class": cls, + "reason": reason, + } + + +def history(folder: Path) -> tuple[dict[str, dict], float]: + """Validate a model's histories, including an interrupted archive, and sum spend.""" + archives: dict[str, list[tuple[int, Path]]] = {} + for path in sorted((folder / "attempts").glob("*.json")): + match = re.fullmatch(r"(.+)-([1-9][0-9]*)\.json", path.name) + if not match: + raise StateError(f"{path}: invalid attempt number") + archives.setdefault(match[1], []).append((int(match[2]), path)) + finals = {path.stem: path for path in sorted(folder.glob("*.json"))} + states, spent = {}, 0.0 + for sid in sorted(set(finals) | set(archives)): + paths = sorted(archives.get(sid, [])) + numbers = [n for n, _ in paths] + if numbers != list(range(1, len(paths) + 1)): + raise StateError( + f"{folder}: attempt-number gap for {sid}: " + + ", ".join(path.name for _, path in paths) + ) + if len(paths) > MAX_RERUNS: + raise StateError(f"{folder}: {sid} exceeds {MAX_RERUNS} reruns") + entries = [] + for n, path in paths: + record = read_record(path) + if record.get("scenario_id") != sid: + raise StateError(f"{path}: household differs from archive name {sid}") + if record["attempts"] != entries: + raise StateError(f"{path}: attempts disagree with earlier archives") + cls, _ = classify(record, 0.0, 0.0, None) + if action(cls, n) not in ("rerun", "pause-rerun"): + raise StateError(f"{path}: archived attempt was ineligible for rerun") + entries.append(entry(path, record, n)) + spent += attempt_cost(record) + final = None + if sid in finals: + path = finals[sid] + final = read_record(path) + if final.get("scenario_id") != sid: + raise StateError(f"{path}: household differs from final name {sid}") + if final["attempts"] != entries: + raise StateError(f"{path}: attempts disagree with archived files") + spent += attempt_cost(final) + states[sid] = {"entries": entries, "final": final} + return states, spent + + +def stage_problems(design: dict) -> list[str]: + """Read stage histories and standing finals without a board or provider.""" + problems = [] + try: + spec = design["no_tools"] + root = Path(spec["runs"]) + folder, stage = component(spec["folder"]), component(spec["stage"]) + draw_order = [component(sid) for sid in design["draw_order"]] + models = set(CHEAP) + if root.is_dir(): + models.update(path.name for path in root.iterdir() if path.is_dir()) + except (OSError, KeyError, TypeError, ValueError) as error: + return [f"no-tools stage: {error}"] + for model in sorted(models): + try: + states, _ = history(root / model / folder / stage / "households") + if model not in CHEAP: + continue + for sid in draw_order: + state = states.get(sid) + if state is None or state["final"] is None: + problems.append(f"no-tools {model}/{sid}: missing standing final") + continue + outcome = action( + classify(state["final"], 0.0, 0.0, None)[0], + len(state["entries"]) + 1, + ) + if outcome != "stands": + problems.append( + f"no-tools {model}/{sid}: final action is {outcome}" + ) + except (OSError, TypeError, ValueError, AttributeError, KeyError) as error: + problems.append(f"no-tools {model}: {error}") + return problems + + +class Spend: + """The stage's recorded spend, shared by every model and every invocation.""" + + def __init__(self, spent: float, stopped: threading.Event): + self.spent_usd, self.budget_usd = spent, NO_TOOLS_CAP + self.lock, self.stopped = threading.Lock(), stopped + if spent >= self.budget_usd: + stopped.set() + + def exhausted(self, reserve_usd: float = 0.0) -> bool: + with self.lock: + return ( + self.stopped.is_set() or self.spent_usd + reserve_usd >= self.budget_usd + ) + + +class AttemptSpend: + """Count a request in both the stage and its own exception fallback record.""" + + def __init__(self, stage: Spend): + self.stage, self.spent_usd = stage, 0.0 + + def add(self, usd: float | None) -> None: + cost = float(usd or 0.0) + with self.stage.lock: + self.spent_usd += cost + self.stage.spent_usd += cost + if self.stage.spent_usd >= self.stage.budget_usd: + self.stage.stopped.set() + + def exhausted(self, reserve_usd: float = 0.0) -> bool: + return self.stage.exhausted(reserve_usd) + + +class Stage: + """One stage, with injectable providers/board for a provider-free rehearsal.""" + + def __init__( + self, + design: dict, + models=None, + run_household=None, + completion_for=default_completion, + board=None, + out=None, + ): + self.design = design + self.models = tuple(dict.fromkeys(models if models is not None else CHEAP)) + if not self.models: + raise StateError("at least one model is required") + for model in self.models: + component(model) + self.draw_order = [component(sid) for sid in design["draw_order"]] + if len(self.draw_order) != len(set(self.draw_order)): + raise StateError("draw_order repeats a household") + spec = design["no_tools"] + self.root = Path(spec["runs"]) + self.folder, self.stage = component(spec["folder"]), component(spec["stage"]) + self.out = sys.stdout if out is None else out + self._say_lock = threading.RLock() + self.stopped = threading.Event() + self.interrupted = threading.Event() + self.completion_for = completion_for + self.run_household = ( + run_household if run_household is not None else pilot.run_household + ) + self._lock_file = None + try: + baseline = design["baseline_exclusions"] + if sha256_file(Path(baseline["path"])) != baseline["sha256"]: + raise StateError("baseline exclusions do not hash as declared") + except (OSError, KeyError, TypeError) as error: + raise StateError(f"baseline exclusions: {error}") from error + self.root.mkdir(parents=True, exist_ok=True) + self._lock_file = (self.root / ".confirmatory-no-tools.lock").open("a") + try: + fcntl.flock(self._lock_file, fcntl.LOCK_EX | fcntl.LOCK_NB) + except BlockingIOError as error: + self.close() + raise StateError( + f"another no-tools invocation holds the lock in {self.root}" + ) from error + try: + self._load_state(board) + except BaseException: + self.close() + raise + + def _load_state(self, board) -> None: + design = self.design + pilot.set_stated_engine(design["engine"].split()[-1]) + if board is None: + board_path = Path(design["board"]) + if f"policyengine-us {pilot.board_engine(board_path)}" != design["engine"]: + raise StateError("the board's engine differs from the design") + pilot._require_engine(board_path) + board = pilot.load_board(board_path) + self.board = board + missing = set(self.draw_order) - set(board["scenarios"]) + missing |= set(self.draw_order) - set(board["variables"]) + if missing: + raise StateError( + f"drawn households missing from the board: {sorted(missing)}" + ) + self.histories = {} + spent = 0.0 + folders = ( + {p.name for p in self.root.iterdir() if p.is_dir()} + if self.root.is_dir() + else set() + ) + for model in sorted(folders | set(self.models)): + states, cost = history(self.households(model)) + self.histories[model] = states + spent += cost + # A saved ceiling failure is a stage-wide stop on every invocation. + if any( + state["final"] is not None + and action( + classify(state["final"], 0.0, 0.0, None)[0], + len(state["entries"]) + 1, + ) + == "stopped" + for state in states.values() + ): + self.stopped.set() + self.spend = Spend(spent, self.stopped) + self.states = {model: "pending" for model in self.models} + + def close(self) -> None: + """Release the invocation lock, including after initialization failure.""" + lock = getattr(self, "_lock_file", None) + if lock is not None: + lock.close() + self._lock_file = None + + def __enter__(self): + return self + + def __exit__(self, *exc): + self.close() + + def __del__(self): + self.close() + + def households(self, model: str) -> Path: + return self.root / model / self.folder / self.stage / "households" + + def say(self, text: str) -> None: + with self._say_lock: + print(text, file=self.out, flush=True) + + def standing(self, model: str, sid: str) -> bool: + state = self.histories[model].get(sid) + return bool( + state + and state["final"] is not None + and action( + classify(state["final"], 0.0, 0.0, None)[0], len(state["entries"]) + 1 + ) + == "stands" + ) + + def dry_run(self) -> int: + try: + return self._dry_run() + finally: + self.close() + + def _dry_run(self) -> int: + for model in self.models: + done = [sid for sid in self.draw_order if self.standing(model, sid)] + owed = [] + for sid in self.draw_order: + if sid in done: + continue + state = self.histories[model].get(sid, {"entries": [], "final": None}) + n = len(state["entries"]) + 1 + if state["final"] is not None: + outcome = action(classify(state["final"], 0.0, 0.0, None)[0], n) + if outcome in ("stop", "stopped"): + owed.append(f"{sid}:blocked {outcome} at attempt {n}") + continue + n += 1 + owed.append(f"{sid}:{n}") + self.say(f"{model}: done {done}; owed (household:next attempt) {owed}") + self.say(f"stage spend ${self.spend.spent_usd:.6f} of ${NO_TOOLS_CAP:.2f}") + return ( + 0 + if all( + self.standing(model, sid) + for model in self.models + for sid in self.draw_order + ) + else 1 + ) + + def archive(self, model: str, sid: str) -> None: + """Move an eligible final unchanged, then extend its reconstructed links.""" + state = self.histories[model][sid] + record, entries = state["final"], state["entries"] + n = len(entries) + 1 + cls, _ = classify(record, 0.0, 0.0, None) + if action(cls, n) not in ("rerun", "pause-rerun"): + raise StateError(f"{model}/{sid}: attempt {n} is ineligible for rerun") + folder = self.households(model) + target = folder / "attempts" / f"{sid}-{n}.json" + target.parent.mkdir(parents=True, exist_ok=True) + if target.exists(): + raise StateError(f"{target}: would overwrite an archived attempt") + os.replace(folder / f"{sid}.json", target) + entries.append(entry(target, record, n)) + state["final"] = None + + def run_model(self, model: str) -> None: + try: + profile = pilot.model_profile( + model, arm="none", prompt_version=PROMPT_VERSION + ) + if profile.uses_calculator or profile.uses_web: + raise StateError(f"{model}: the none profile offers a tool") + completion = None + completion_loaded = False + for sid in self.draw_order: + if self.interrupted.is_set(): + self.states[model] = "interrupted" + return + state = self.histories[model].setdefault( + sid, {"entries": [], "final": None} + ) + while True: + if self.interrupted.is_set(): + self.states[model] = "interrupted" + return + if state["final"] is not None: + cls, _ = classify(state["final"], 0.0, 0.0, None) + outcome = action(cls, len(state["entries"]) + 1) + if outcome == "stands": + break + if outcome == "stop": + self.states[model] = "harness-stopped" + return + if outcome == "stopped": + self.stopped.set() + if self.spend.exhausted(): + self.states[model] = "budget-stopped" + return + if state["final"] is not None: + if self.interrupted.is_set(): + self.states[model] = "interrupted" + return + self.archive(model, sid) + if not completion_loaded: + completion = self.completion_for(profile) + completion_loaded = True + if self.spend.exhausted(): + self.states[model] = "budget-stopped" + return + if self.interrupted.is_set(): + self.states[model] = "interrupted" + return + spend = AttemptSpend(self.spend) + + def no_tool(arguments): + raise RuntimeError("the no-tools arm cannot call a tool") + + try: + record = self.run_household( + self.board["scenarios"][sid], + self.board["variables"][sid], + no_tool, + completion, + spend, + profile=profile, + ) + except Exception as error: + record = pilot.harness_error_record( + sid, self.board["variables"][sid], profile, error + ) + record["totals"]["cost_usd"] = spend.spent_usd + record["attempts"] = list(state["entries"]) + write_json(self.households(model) / f"{sid}.json", record) + state["final"] = record + n = len(state["entries"]) + 1 + cls, _ = classify(record, 0.0, 0.0, None) + outcome = action(cls, n) + self.say( + f"{model} {sid} {n} {cls} {outcome} ${attempt_cost(record):.6f}" + ) + if self.interrupted.is_set(): + self.states[model] = "interrupted" + return + if outcome == "pause-rerun": + self.states[model] = "operator-paused" + return + if outcome == "stop": + self.states[model] = "harness-stopped" + return + if outcome == "stopped": + self.stopped.set() + self.states[model] = "budget-stopped" + return + if outcome == "stands": + break + self.states[model] = "complete" + except Exception as error: + self.states[model] = "error" + self.say(f"{model}: {type(error).__name__}: {error}") + + def execute(self) -> int: + previous = {} + + def interrupt(signum, frame): + if self.interrupted.is_set(): + self.say( + "Forced interruption: an attempt under way, and its spend, " + "are then lost." + ) + os._exit(128 + signum) + self.interrupted.set() + self.say("Interrupted: attempts under way will finish and save.") + + try: + if threading.current_thread() is threading.main_thread(): + for sig in (signal.SIGINT, signal.SIGTERM): + previous[sig] = signal.signal(sig, interrupt) + return self._execute() + finally: + for sig, handler in previous.items(): + signal.signal(sig, handler) + self.close() + + def _execute(self) -> int: + threads = [ + threading.Thread( + target=self.run_model, args=(model,), name=f"no-tools-{model}" + ) + for model in self.models + ] + for thread in threads: + thread.start() + for thread in threads: + thread.join() + for model in self.models: + self.say(f"{model}: {self.states[model]}") + self.say(f"stage spend ${self.spend.spent_usd:.6f} of ${NO_TOOLS_CAP:.2f}") + return ( + 0 + if not self.interrupted.is_set() + and all(self.states[model] == "complete" for model in self.models) + else 1 + ) + + +def main(argv=None) -> int: + parser = argparse.ArgumentParser(description=__doc__.split("\n\n")[0]) + sub = parser.add_subparsers(dest="command", required=True) + run = sub.add_parser("run") + run.add_argument("design", type=Path) + run.add_argument("--model", action="extend", nargs="+") + run.add_argument("--dry-run", action="store_true") + args = parser.parse_args(argv) + try: + with Stage(json.loads(args.design.read_text()), models=args.model) as stage: + return stage.dry_run() if args.dry_run else stage.execute() + except (StateError, OSError, ValueError, KeyError, TypeError) as error: + print(f"The no-tools stage cannot start: {error}") + return 1 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/scripts/confirmatory_run.py b/scripts/confirmatory_run.py new file mode 100644 index 00000000..3949f239 --- /dev/null +++ b/scripts/confirmatory_run.py @@ -0,0 +1,2333 @@ +"""The confirmatory calculator-interface run. + +Usage: + python scripts/confirmatory_run.py run DESIGN [--workers N] [--dry-run] + python scripts/confirmatory_run.py resume DESIGN MODEL [--note TEXT] + +Runs the frozen pre-registration's "Run procedure" and writes its "Run +records", which the confirmatory report checks before it scores anything. +DESIGN is the JSON file written at the freeze, the file the report reads. + +- **Lanes.** Each model has two lanes. Households alternate between them in + draw order, the first drawn to lane 1. A lane runs one household's arms one + after another, in the order drawn for that household and model (the stream + ``order/``), then its reruns in passes (second attempts before + third, each pass in the household's order), and only then decides its next + household. The six models run at once. +- **One engine pool per model**, started once, with no features of its own. + Each call carries its arm's features in a call frame (``tool_call_frame``), + the message a pool started with those features would send. ``setup-start`` + and ``setup-end`` events bracket startup and pool restarts, so setup time + can be distinguished from an idle lane. +- **Admission.** A lane admits its next household when the spend of the + model's finished households (every attempt, replaced ones included) plus + the reserve for each household under way, this one included, is at most + the model's cap plus $1e-9. A household is finished when its last attempt + has ended. After one refusal every later decision is a refusal. A decision + waits while an operator pause holds, and while any of the model's + households has ended a pass whose reruns are undecided, so that whether it + has finished is known. +- **Spend.** No conversation is stopped for spend, except at the hard + ceiling: the overall cap plus $25, over the spend before the calculator + stage and every model's spend since. At the crossing, no attempt starts, + the conversations under way end ``budget_stop`` at their next turn, and + every model's run log gets a ``ceiling`` event at the crossing's time. + The decision to admit a household and the crossing share one lock, so no + household is decided after the crossing. +- **The attempt deadline.** A conversation still running an hour after it + started is abandoned: its attempt gets a harness-error record + (``AttemptDeadline``) holding the spend so far, the model's lanes stop, + and the conversation ends ``budget_stop`` at its next turn. Its spend after + the deadline still counts toward the ceiling, and goes to the run log as + ``late-cost`` events. +- **Failures.** Each attempt's class follows the pre-registration's table, in + the precedence the report's ``classify`` uses, from its record and the host + evidence for its start and end; its action follows from its class and its + attempt number. An operator failure pauses the model's lanes until + ``resume``, which is accepted only if written after the pause began. A + harness failure stops them, and so does one inconclusive error that ends + runs in more than five of the model's households. A replaced attempt is + saved, before its rerun, as ``households/attempts/-.json``. +- **Stops.** Every ``stop`` event names its cause: ``harness``, + ``inconclusive``, ``deadline``, ``pool`` (the engine pool could not be + started again), ``runner-error`` (an exception in the runner itself, which + stops every model's lanes after writing what had ended), ``interrupt`` or + ``sampler``. The ceiling's events are ``ceiling`` events of cause + ``ceiling``. +- **The host log.** Every 30 seconds: the time, the monotonic clock, the + load average and the kernel's memory-pressure level (None when it could not + be read, which is no sample). At the end, the guard's and the power log's + lines from a day before the run's start to its end. A read of those logs is + tried five times; one that still fails during the run is a runner error, + and at the end leaves ``host-error.txt`` in place of the excerpts. An + attempt's class waits for its host evidence to + be complete: a good sample more than 60 seconds after the pass's last end, + or no good sample for more than 90 seconds. A sampler whose samples have + failed for five minutes, or whose thread has ended, stops every model. +- **Chains and anchors.** Every line of the run logs, the admission logs and + the host log carries ``prev``, the sha256 of the line before it. The first + line's is a seed: for a model's logs, the sha256 of the frozen hash, the + model and the file's name; for the host log, of its name. Every 15 + minutes, and at the end, ``anchors.jsonl`` gets a line with every log's + line count and head and every manifest's sha256, itself chained, and the + design's ``anchor_command`` is run on a synced, atomic copy in the + background. Each ``anchors..push-snapshot.jsonl`` is a copy, not a + record, and is never replaced by a later push's snapshot. Each push's + result goes to ``anchor-pushes.jsonl``. ``confirmatory_anchor.py`` is that + command: under an exclusive, non-blocking clone lock, it accepts only a + snapshot extending the clone's anchors, commits it and pushes it, so the + remote holds each anchor's time from outside the run. Retiring a worker + does not ensure its command has ended. If an old helper or its Git child + still holds the lock, later pushes fail as busy; a final segment left local + is a deviation. + Final pushes get up to three tries per set of heads, waiting a minute + after each failed try ends before starting the next. + +The records' format is the confirmatory report's (its module docstring). The +report recomputes every class, action, order and admission decision from the +records, with its own copy of these rules; the study's differential test runs +this runner on fakes and checks that its records pass the report. + +The runner runs the treatment harness's code. It refuses to start unless its +``tool_pilot_argon.py``, ``policybench`` package and fix module are the +treatment commit's (6b00a6f0), its tree is clean at the design's run commit, +the machine is on AC power with the lid open, and the runs folder holds no +records: a run is never resumed. ``--workers`` must equal the design's +engine workers per model. An interrupt (SIGINT or SIGTERM) only notes the +signal; the main loop then stops every model's lanes with cause +``interrupt`` and lets the conversations under way end. A second interrupt +exits at once until cleanup ignores signals before its final check. Signals +during any re-anchoring after that check are ignored, including a second +interrupt. +""" + +from __future__ import annotations + +import argparse +import hashlib +import json +import math +import os +import re +import shutil +import signal +import subprocess +import sys +import threading +import time +import traceback +from dataclasses import dataclass +from datetime import datetime +from pathlib import Path +from typing import Callable +from zoneinfo import ZoneInfo + +import numpy as np + +# The harness and policybench come from this checkout, whatever else is on the +# path: the preflight refuses any other. +ROOT = Path(__file__).resolve().parents[1] +sys.path[:0] = [str(ROOT), str(ROOT / "scripts")] + +import tool_pilot_argon as pilot # noqa: E402 + +TREATMENT_COMMIT = "6b00a6f0c4997e73b9968b412b57646957cad631" +# The treatment's code, which must be the treatment commit's. +TREATMENT_PATHS = ( + "scripts/tool_pilot_argon.py", + "policybench", + "reference_audit/2026-09-28/fixes", +) +PROMPT_VERSION = "v2-pilot" +CHEAP = ("claude-haiku-5.5", "gpt-6-luna", "gemini-3.5-flash-lite") +FRONTIER = ("gpt-6-sol", "claude-opus-5.5", "gemini-4-argon") +ARMS = ( + "pe", + "pe3", + "pe3-b", + "loo-labels", + "loo-names", + "loo-flat", + "loo-labels-flat", +) +FRONTIER_ARMS = ("pe", "pe3") +# The features each label drops from pe3; None for the tool v1 arm. +DROPPED = { + "pe": None, + "pe3": (), + "pe3-b": (), + "loo-labels": ("labels",), + "loo-names": ("names",), + "loo-flat": ("flat",), + "loo-labels-flat": ("labels", "flat"), +} +HOUSEHOLDS = 120 +MAX_RERUNS = 2 +INCONCLUSIVE_STOP = 5 # households of a model one inconclusive error may end +PRESSURE_WINDOW = 60.0 # seconds +HOST_LOG_GAP = 90.0 # seconds +SAMPLE_SECONDS = 30.0 +CEILING_MARGIN = 25.0 # dollars above the overall cap +ADMISSION_SLACK = 1e-9 # dollars +EXCERPT_LEAD = 86_400.0 # host logs are kept from a day before the run's start +WAIT_SECONDS = 1.0 # how often a waiting lane looks again +ATTEMPT_DEADLINE = 3600.0 # seconds; the longest development attempt took 714 +SAMPLER_SILENCE = 300.0 # seconds without a host-log sample that stop the run +READ_TRIES = 5 # reads of the guard's and the power log before a runner error +READ_WAIT = 10.0 # seconds between them +ANCHOR_SECONDS = 900.0 # how often the logs' chain heads are anchored +ANCHOR_RETRY = 60.0 # seconds to the next anchor after a failed push +ANCHOR_PUSH_TIMEOUT = 300.0 # seconds; then the command's process group is killed +KILL_GRACE = 10.0 # seconds to drain pipes after killing the process group +FINAL_PUSH_TRIES = 3 # includes the first final push +LATE_JOIN = 60.0 # seconds the run's end waits, in all, for abandoned attempts +# What a stop event names as its cause. +STOP_CAUSES = frozenset( + { + "harness", + "inconclusive", + "pool", + "deadline", + "runner-error", + "interrupt", + "sampler", + } +) + +# The pre-registration's error classes (its "Failures" table): the names of +# litellm's exception classes under the harness's retryable classes (transport) +# and under its model-fatal ones (request and account). A record keeps only +# the raised class's name. +TRANSPORT = frozenset( + { + "APIConnectionError", + "APIError", + "APIResponseValidationError", + "BadGatewayError", + "InternalServerError", + "JSONSchemaValidationError", + "MidStreamFallbackError", + "RateLimitError", + "ServiceUnavailableError", + "Timeout", + "RequestWallTimeoutError", + } +) +REQUEST = frozenset( + { + "BadRequestError", + "ContentPolicyViolationError", + "ContextWindowExceededError", + "ImageFetchError", + "InvalidRequestError", + "LiteLLMUnknownProvider", + "RejectedRequestError", + "UnprocessableEntityError", + "UnsupportedParamsError", + } +) +ACCOUNT = frozenset({"AuthenticationError", "PermissionDeniedError", "NotFoundError"}) +# A timeout on the escalated request, the one asking for the escalation +# ceiling after a truncated turn, is the model's long generation timing out. +TIMEOUTS = frozenset({"Timeout", "RequestWallTimeoutError"}) +HOST_ENGINE = frozenset({"MemoryError", "OSError"}) +RERUN = frozenset({"provider", "host", "none", "operator"}) +FINISHED = frozenset({"complete", "incomplete", "turn_limit"}) +# Classes decided without the host evidence: they come before host trouble. +EARLY = frozenset({"operator", "harness", "ceiling", "none"}) + +REQUIRED = ( + "preregistration", + "frozen_sha256", + "runs", + "stage", + "board", + "engine", + "eligible_pool", + "draw_order", + "arms", + "frontier_arms", + "treatment_harness", + "run_commit", + "caps", + "reserves", + "overall_cap", + "spent_before", + "workers", + "anchor_command", +) + + +# ---------------------------------------------------------------- streams + + +def master_seed(frozen_sha256: str) -> int: + if not re.fullmatch(r"[0-9a-f]{64}", frozen_sha256 or ""): + raise ValueError(f"not a sha256: {frozen_sha256!r}") + return int(frozen_sha256[:16], 16) + + +def stream(master: int, name: str) -> np.random.Generator: + key = int.from_bytes(hashlib.sha256(name.encode()).digest()[:8], "big") + return np.random.default_rng(np.random.SeedSequence(master, spawn_key=(key,))) + + +def draw(master: int, pool_ids: list[str], n: int | None = None) -> list[str]: + ids = np.array(sorted(pool_ids)) + size = HOUSEHOLDS if n is None else n + return [ + str(s) for s in stream(master, "draw").choice(ids, size=size, replace=False) + ] + + +def orders( + master: int, model: str, draw_order: list[str], arms: tuple[str, ...] +) -> dict[str, list[str]]: + """Each drawn household's arm order for a model, drawn for every household + in draw order, so no order depends on which households run.""" + generator = stream(master, f"order/{model}") + return { + sid: [str(a) for a in generator.permutation(list(arms))] for sid in draw_order + } + + +# ---------------------------------------------------------------- arms + + +def arm_string(label: str) -> str: + """The harness's arm string for a design label (`TOOL_FEATURES` order).""" + dropped = DROPPED[label] + if dropped is None: + return "pe" + if not dropped: + return "pe3" + return "pe:" + "+".join(f for f in pilot.TOOL_FEATURES if f not in dropped) + + +def arm_profile(model: str, label: str) -> pilot.ModelProfile: + """The treatment harness's profile for a model and design label; refused + unless its calculator features are the ones the label registers.""" + profile = pilot.model_profile( + model, arm=arm_string(label), prompt_version=PROMPT_VERSION + ) + dropped = DROPPED[label] + want = set() if dropped is None else set(pilot.TOOL_FEATURES) - set(dropped) + if not profile.uses_calculator or set(profile.tool_features) != want: + raise ValueError( + f"{model}/{label}: the harness gives features " + f"{sorted(profile.tool_features)}, not {sorted(want)}" + ) + return profile + + +# ---------------------------------------------------------------- classes + + +def error_class(record: dict) -> str: + return str(record.get("error") or "").split(":", 1)[0].strip() + + +def completed_turns(record: dict) -> list: + return [t for t in record.get("turns") or [] if not t.get("truncated_and_retried")] + + +def call_failures(record: dict) -> tuple[list[str], list[str]]: + """(the inconclusive tool failures, the model's engine exceptions) in its + calls: a call's own error, and the errors in its results and in its + explanations (the explain feature's trace of a variable).""" + host, model = [], [] + for turn in record.get("turns") or []: + for call in turn.get("calls") or []: + result = call.get("result") + if not isinstance(result, dict): + continue + error, message = result.get("error"), str(result.get("message") or "") + name = message.split(":", 1)[0] + if error == "timeout": + host.append("tool timeout") + elif error == "engine" and message.startswith("tool worker failed:"): + host.append("tool worker failure") + elif error == "engine": + (host if name in HOST_ENGINE else model).append(name) + for group in ("results", "explanations"): + values = result.get(group) + for value in values.values() if isinstance(values, dict) else (): + if isinstance(value, dict) and value.get("error"): + name = str(value["error"]).split(":", 1)[0] + (host if name in HOST_ENGINE else model).append(name) + return host, model + + +def escalation_timed_out(record: dict) -> bool: + """Whether the attempt ended on a timeout of its escalated request: the + harness records a truncated turn, then asks again at the escalation + ceiling, and an error there leaves the truncated turn last.""" + turns = record.get("turns") or [] + return ( + record.get("status") == "provider_error" + and error_class(record) in TIMEOUTS + and bool(turns) + and bool(turns[-1].get("truncated_and_retried")) + ) + + +def classify(record: dict, start: float, end: float, host) -> tuple[str, str]: + """(class, detail) of one attempt. In order of precedence: operator (an + account class or insufficient_quota); harness (a request class with no + completed model turn yet); ceiling (budget_stop); none (no turn recorded: + no model request returned, truncated or not); host (host trouble during + the attempt); model (a timeout of the escalated request); provider (a + transport class); model (a request class); inconclusive (any other + provider error, any harness error, a tool timeout, a worker failure, + MemoryError or OSError); otherwise ok, or model when the engine raised on + a household the model built. `host` is None to decide only the classes + before host.""" + status, error = record.get("status"), str(record.get("error") or "") + name = error_class(record) + returned = bool(record.get("turns")) + completed = bool(completed_turns(record)) + if status == "provider_error" and ( + name in ACCOUNT or "insufficient_quota" in error + ): + return "operator", name + if status == "provider_error" and name in REQUEST and not completed: + return "harness", name + if status == "budget_stop": + return "ceiling", status + if not returned: + return "none", f"{status}: {name}" if name else str(status) + trouble = host.trouble(start, end) if host is not None else None + if trouble: + return "host", trouble + if status == "provider_error": + if escalation_timed_out(record): + return "model", f"{name} on the escalated request" + if name in TRANSPORT: + return "provider", name + if name in REQUEST: + return "model", name + return "inconclusive", name or "provider_error" + if status == "harness_error": + return "inconclusive", error or "harness_error" + tool, engine = call_failures(record) + if tool: + return "inconclusive", tool[0] + if status not in FINISHED: + return "inconclusive", f"status {status}" + return ("model", engine[0]) if engine else ("ok", str(status)) + + +def action(cls: str, attempt: int) -> str: + if cls == "harness": + return "stop" + if cls == "ceiling": + return "stopped" + if cls in RERUN and attempt <= MAX_RERUNS: + return "pause-rerun" if cls == "operator" else "rerun" + return "stands" + + +def attempt_cost(record: dict) -> float: + return float((record.get("totals") or {}).get("cost_usd") or 0.0) + + +_clock_lock = threading.Lock() +_clock_last = 0.0 + + +def clock() -> float: + """`time.time()`, never earlier than a time it gave before. The wall clock + can step back by about 0.1 ms, even within a thread, and the run records order + attempts, stops, admission decisions and the ceiling's crossing by the + times this gives; each is taken under the lock that orders it.""" + global _clock_last + with _clock_lock: + _clock_last = max(time.time(), _clock_last) + return _clock_last + + +# ---------------------------------------------------------------- host evidence + + +GUARD_LINE = re.compile(r"^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d) \[[^\]]*\] (.*)$") +POWER_LINE = re.compile(r"^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d [+-]\d{4}) ([^\t]*?)\s*\t") +GUARD_LOG = Path.home() / "Library/Logs/clamshell-guard.log" + + +def guard_times(line: str, zone: ZoneInfo) -> tuple[float, float] | None: + """The earliest and latest instants a guard line's local time can be. They + differ only within an hour that a change of offset repeats or skips: on + 2026-11-01, New York's 01:00-02:00 comes twice, and the guard's lines + carry no offset.""" + match = GUARD_LINE.match(line) + if not match: + return None + stamp = datetime.strptime(match.group(1), "%Y-%m-%d %H:%M:%S") + both = [stamp.replace(tzinfo=zone, fold=fold).timestamp() for fold in (0, 1)] + return min(both), max(both) + + +def power_times(line: str) -> tuple[float, float] | None: + """A power-log line's instant, twice (its time carries its offset).""" + match = POWER_LINE.match(line) + if not match: + return None + t = datetime.strptime(match.group(1), "%Y-%m-%d %H:%M:%S %z").timestamp() + return t, t + + +def guard_spans(text: str, timezone: str, end: float) -> list: + """Pauses: from a 'paused pids:' line to the next 'resumed pids:' line (or + `end`), each from the earliest reading of its pause to the latest of its + resume.""" + zone, spans, opened = ZoneInfo(timezone), [], None + for line in text.splitlines(): + times = guard_times(line, zone) + if times is None: + continue + what = GUARD_LINE.match(line).group(2) + if "paused pids:" in what and opened is None: + opened = times[0] + elif "resumed pids:" in what and opened is not None: + spans.append((opened, times[1], "guard pause")) + opened = None + if opened is not None: + spans.append((opened, end, "guard pause")) + return spans + + +def power_spans(text: str, end: float) -> list: + """Sleeps: from a Sleep line to the next Wake or DarkWake line (or `end`).""" + spans, opened = [], None + for line in text.splitlines(): + times = power_times(line) + if times is None: + continue + t = times[0] + kind = POWER_LINE.match(line).group(2).strip() + if kind == "Sleep" and opened is None: + opened = t + elif kind in ("Wake", "DarkWake") and opened is not None: + spans.append((opened, t, "sleep")) + opened = None + if opened is not None: + spans.append((opened, end, "sleep")) + return spans + + +def excerpt( + text: str, + when: Callable[[str], tuple[float, float] | None], + since: float, + until: float, +): + """The lines of a log that one reading of its time puts within [since, + until].""" + keep = [] + for line in text.splitlines(): + times = when(line) + if times is not None and times[0] <= until and times[1] >= since: + keep.append(line + "\n") + return "".join(keep) + + +def memory_pressure() -> int | None: + """`sysctl kern.memorystatus_vm_pressure_level`: 1 when normal on this host.""" + try: + out = subprocess.run( + ["sysctl", "-n", "kern.memorystatus_vm_pressure_level"], + capture_output=True, + text=True, + timeout=10, + check=True, + ) + return int(out.stdout.strip()) + except (OSError, subprocess.SubprocessError, ValueError): + return None + + +def read_guard_log() -> str: + """The guard's log; empty when there is none (the guard never paused + anything). Any other error is raised, for the reader to try again.""" + try: + return GUARD_LOG.read_text(errors="replace") + except FileNotFoundError: + return "" + + +def read_power_log() -> str: + out = subprocess.run( + ["pmset", "-g", "log"], capture_output=True, text=True, timeout=120, check=True + ) + return out.stdout + + +def local_timezone() -> str: + """The IANA name of the host's zone, which the guard log's times are in.""" + target = os.path.realpath("/etc/localtime") + if "zoneinfo/" not in target: + raise SystemExit(f"cannot tell the host's time zone from {target}") + return target.split("zoneinfo/", 1)[1] + + +# The `prev` of the host log's first line. +HOST_SEED = hashlib.sha256(b"host-log.jsonl").hexdigest() + + +class HostEvidenceError(RuntimeError): + """The guard's or the power log could not be read: a runner error.""" + + +class HostLog: + """The host log, written every `interval` seconds, and the host evidence an + attempt's class reads: the guard's pauses, the power log's sleeps, the + host log's gaps and its memory-pressure samples. A sample whose pressure + could not be read is no sample: the silence around it is a gap.""" + + def __init__( + self, + folder: Path, + timezone: str | None = None, + interval: float = SAMPLE_SECONDS, + read_load: Callable[[], tuple] = os.getloadavg, + read_pressure: Callable[[], int | None] = memory_pressure, + read_guard: Callable[[], str] = read_guard_log, + read_power: Callable[[], str] = read_power_log, + ): + self.folder = Path(folder) + self.folder.mkdir(parents=True, exist_ok=True) + self.timezone = timezone or local_timezone() + ZoneInfo(self.timezone) # refused here, not at the first pause + self.interval = interval + self._read_load, self._read_pressure = read_load, read_pressure + self._read_guard, self._read_power = read_guard, read_power + self._cond = threading.Condition() + self._samples: list[tuple[float, int | None]] = [] + self._spans: list = [] # guard pauses and sleeps at the last refresh + self._read_at = -math.inf + self._refresh_lock = threading.Lock() + self._stop = threading.Event() + self.failure: str | None = None # the sampler's last error + self.failing_since: float | None = None # failed samples since then + self._head, self._lines = HOST_SEED, 0 # the log's hash chain + self.start = time.time() + self.written = self.start # the last sample written + self.end: float | None = None + self._write_meta() + self.sample() + self._thread = threading.Thread(target=self._loop, name="host-log", daemon=True) + self._thread.start() + + def _write_meta(self) -> None: + meta = {"timezone": self.timezone, "start": self.start} + if self.end is not None: + meta["end"] = self.end + write_json(self.folder / "host.json", meta) + + def sample(self) -> None: + """One sample. A load or pressure the host would not give is written + as null; a sample that cannot be written is the sampler's failure, + and the silence it leaves is a gap.""" + try: + load1, load5, load15 = self._read_load() + except OSError: + load1 = load5 = load15 = None + pressure = self._read_pressure() + with self._cond: + t = time.time() + line = { + "time": t, + "monotonic": time.monotonic(), + "load1": load1, + "load5": load5, + "load15": load15, + "pressure": pressure, + } + text = json.dumps({**line, "prev": self._head}) + try: + with (self.folder / "host-log.jsonl").open("a") as handle: + handle.write(text + "\n") + except OSError as error: + self.failure = f"{type(error).__name__}: {error}" + self.failing_since = self.failing_since or t + return + self._head, self._lines = line_sha(text), self._lines + 1 + self.written = t + if pressure is None: + self.failure = "no memory-pressure reading" + self.failing_since = self.failing_since or t + else: + self.failure = None + self.failing_since = None + self._samples.append((t, pressure)) + self._cond.notify_all() + + def heads(self) -> dict: + """The host log's line count and last line's sha256, for an anchor.""" + with self._cond: + return {"lines": self._lines, "sha256": self._head} + + def dead(self) -> str | None: + """Why the sampler is taken for dead: no good sample for + SAMPLER_SILENCE seconds while its samples fail, or its thread gone. + A host that slept or was paused is not this: its sampler failed + nothing.""" + if self.end is None and not self._thread.is_alive(): + return "the sampler's thread ended" + since = self.failing_since + if since is not None and time.time() - since > SAMPLER_SILENCE: + return f"samples failing since {since:.1f} ({self.failure})" + return None + + def _loop(self) -> None: + k = 1 + while not self._stop.wait( + max(0.0, self.start + k * self.interval - time.time()) + ): + try: + self.sample() + except Exception as error: # the sampler runs on; watch() sees the silence + self.failure = f"{type(error).__name__}: {error}" + self.failing_since = self.failing_since or time.time() + # After a stall, the next sample is the next tick, with no burst. + k = max(k + 1, math.ceil((time.time() - self.start) / self.interval)) + + def _good(self) -> list[float]: + """The times of the samples with a pressure reading.""" + return [t for t, p in self._samples if p is not None] + + def settled(self, end: float) -> bool: + """Whether every sample that could bear on an attempt ending at `end` is + in: one later than the pressure window, or a silence longer than a + gap (which is itself host trouble when it covers the attempt).""" + with self._cond: + good = self._good() + latest = good[-1] if good else self.start + return latest > end + PRESSURE_WINDOW or time.time() - latest > HOST_LOG_GAP + + def wait_settled(self, end: float) -> None: + with self._cond: + while not self.settled(end): + self._cond.wait(timeout=min(self.interval, 5.0)) + + def _read_logs(self) -> tuple[str, str]: + """The guard's and the power log, read up to READ_TRIES times.""" + for attempt in range(READ_TRIES): + try: + return self._read_guard(), self._read_power() + except (OSError, subprocess.SubprocessError) as error: + failure = f"{type(error).__name__}: {error}" + if attempt < READ_TRIES - 1: + time.sleep(READ_WAIT) + raise HostEvidenceError(f"the guard's or the power log: {failure}") + + def refresh(self, after: float) -> None: + """Read the guard's and the power log again unless read since `after`. + A failed read keeps the last spans and tries again; HostEvidenceError + after READ_TRIES.""" + with self._refresh_lock: + if self._read_at > after: + return + now = time.time() + since = self.start - EXCERPT_LEAD + zone = ZoneInfo(self.timezone) + guard_text, power_text = self._read_logs() + guard = excerpt(guard_text, lambda x: guard_times(x, zone), since, now) + power = excerpt(power_text, power_times, since, now) + spans = guard_spans(guard, self.timezone, now) + power_spans(power, now) + with self._cond: + self._spans, self._read_at = spans, now + + def _evidence(self) -> tuple[list, list[float]]: + """(spans, the times of samples above 1), as the report builds them + from the archived logs, with a silence so far as an open gap.""" + with self._cond: + spans = list(self._spans) + times = self._good() + pressure = [t for t, p in self._samples if p is not None and int(p) > 1] + for a, b in zip([self.start] + times, times): + if b - a > HOST_LOG_GAP: + spans.append((a, b, "host log gap")) + now = time.time() if self.end is None else self.end + last = times[-1] if times else self.start + if now - last > HOST_LOG_GAP: + spans.append((last, now, "host log gap")) + return spans, pressure + + def trouble(self, start: float, end: float) -> str | None: + spans, pressure = self._evidence() + for a, b, what in spans: + if a <= end and b >= start: + return what + for t in pressure: + if start - PRESSURE_WINDOW <= t <= end + PRESSURE_WINDOW: + return "memory pressure" + return None + + def describe(self, start: float, end: float) -> str: + """The host evidence behind an attempt's host class, for its rerun's + reason.""" + spans, _ = self._evidence() + parts = [ + f"{what} {a:.1f}-{b:.1f}" for a, b, what in spans if a <= end and b >= start + ] + with self._cond: + parts += [ + f"memory pressure {p} at {t:.1f}" + for t, p in self._samples + if int(p or 0) > 1 + and start - PRESSURE_WINDOW <= t <= end + PRESSURE_WINDOW + ] + return "; ".join(parts) + + def close(self) -> None: + """A last sample, the run's end, and the guard's and power log's lines + from a day before the run's start to its end. If the logs cannot be + read, `host-error.txt` says why and the excerpts are not written: the + report then has no host evidence to check against.""" + self._stop.set() + self._thread.join(timeout=self.interval + 10) + try: + self.sample() + except Exception as error: + self.failure = f"{type(error).__name__}: {error}" + with self._cond: + self.end = time.time() + self._write_meta() + since, zone = self.start - EXCERPT_LEAD, ZoneInfo(self.timezone) + try: + guard_text, power_text = self._read_logs() + except HostEvidenceError as error: + (self.folder / "host-error.txt").write_text(f"{error}\n") + return + guard = excerpt(guard_text, lambda x: guard_times(x, zone), since, self.end) + (self.folder / "clamshell-guard.log").write_text(guard) + power = excerpt(power_text, power_times, since, self.end) + (self.folder / "pmset.log").write_text(power) + + +# ---------------------------------------------------------------- spend + + +class Ceiling(pilot.Spend): + """The hard ceiling over every model's spend: once the total reaches it, + `exhausted` is true for good, which ends each conversation under way at + its next turn and lets no attempt start.""" + + def __init__(self, ceiling_usd: float, spent_before: float): + super().__init__(ceiling_usd, spent_before) + self.crossed_at: float | None = None + self.closed = False # the records are final: spend is no longer counted + self.unrecorded_usd = 0.0 # spend after that, in no record + + @property + def lock(self) -> threading.Lock: + return self._lock + + def charge(self, usd: float) -> bool: + """Count `usd`, with the lock held; False, and the spend unrecorded, + once the ledger has closed.""" + if self.closed: + self.unrecorded_usd += usd + return False + self.spent_usd += usd + if self.crossed_at is None and self.spent_usd >= self.budget_usd: + self.crossed_at = clock() + return True + + def add(self, usd: float | None) -> None: + with self._lock: + self.charge(float(usd or 0.0)) + + def close(self, pending: list[dict] | None = None) -> list[dict]: + """Close the ledger at the run's end: what the ceiling has counted is + then what the records hold. Snapshot unresolved requests under the + same lock: one finishing afterward cannot disappear from recovery.""" + with self._lock: + self.closed = True + return [item for item in pending or [] if item["thread"].is_alive()] + + def exhausted(self, reserve_usd: float = 0.0) -> bool: + with self._lock: + return self.crossed_at is not None + + +class AttemptSpend: + """The hard ceiling as one attempt's conversation sees it. Every cost goes + to the ceiling, and the attempt keeps its own total, so an attempt that + raises still records what it spent. Once the attempt is abandoned at its + deadline, the conversation ends `budget_stop` at its next turn, and what + it spends after is kept apart as late spend. The attempt's totals and the + ceiling's change under the ceiling's lock, so they always agree; once + the ledger has closed, neither counts more.""" + + def __init__(self, ceiling: Ceiling): + self.ceiling = ceiling + self.spent_usd = 0.0 + self.late_usd = 0.0 + self.abandoned = False + + def add(self, usd: float | None) -> None: + usd = float(usd or 0.0) + with self.ceiling.lock: + if not self.ceiling.charge(usd): + return + if self.abandoned: + self.late_usd += usd + else: + self.spent_usd += usd + + def exhausted(self, reserve_usd: float = 0.0) -> bool: + return self.abandoned or self.ceiling.exhausted() + + def abandon(self) -> float: + """Abandon the attempt; what it had spent.""" + with self.ceiling.lock: + self.abandoned = True + return self.spent_usd + + +# ---------------------------------------------------------------- files + + +def sha256_bytes(data: bytes) -> str: + return hashlib.sha256(data).hexdigest() + + +def sha256_file(path: Path) -> str: + return sha256_bytes(Path(path).read_bytes()) + + +def write_json(path: Path, payload, indent: int | None = 1) -> str: + """Write a file whole (to a temporary name, synced, then renamed); its + sha256.""" + data = json.dumps(payload, indent=indent, default=str).encode() + path.parent.mkdir(parents=True, exist_ok=True) + tmp = path.with_name(f".{path.name}.tmp") + with tmp.open("wb") as handle: + handle.write(data) + handle.flush() + os.fsync(handle.fileno()) + os.replace(tmp, path) + return sha256_bytes(data) + + +def chain_seed(frozen_sha256: str, model: str, name: str) -> str: + """The `prev` of a log's first line: the log's place in the design.""" + return sha256_bytes(f"{frozen_sha256}/{model}/{name}".encode()) + + +def line_sha(text: str) -> str: + """A log line's hash, the next line's `prev`: its JSON, no newline.""" + return sha256_bytes(text.encode()) + + +# ---------------------------------------------------------------- one model + + +@dataclass +class Attempt: + label: str + n: int + start: float + end: float + record: dict + cls: str = "" + detail: str = "" + reason: str = "" + settled: bool = False # classed with its pass's host evidence + logged: bool = False # its run-log line written + + +class AttemptDeadline(RuntimeError): + """An attempt ran past ATTEMPT_DEADLINE and was abandoned.""" + + +def converse_with_harness( + lanes: "Lanes", sid: str, label: str, tool_call, spend: AttemptSpend +) -> dict: + """One attempt: the treatment harness's conversation for the arm, under the + hard ceiling.""" + board = lanes.run.board + return pilot.run_household( + board["scenarios"][sid], + board["variables"][sid], + tool_call, + lanes.completion, + spend, + profile=lanes.profiles[label], + ) + + +class Lanes: + """One model's two lanes: its admission, its attempts and its records.""" + + def __init__(self, run: "Run", model: str, labels: tuple[str, ...], folders: dict): + self.run, self.model, self.labels = run, model, labels + design = run.design + self.folder = Path(design["runs"]) / model + self.households_dir = { + label: self.folder / folders[label] / design["stage"] / "households" + for label in labels + } + self.profiles = {label: arm_profile(model, label) for label in labels} + self.cap = float(design["caps"][model]) + self.reserve = float(design["reserves"][model]) + self.orders = orders(run.master, model, run.draw_order, labels) + self.cond = threading.Condition() + self._log_lock = threading.Lock() + self.state: dict[str, str] = {} # household -> running, settling, finished + self.spent: dict[str, float] = {} # household -> its attempts' cost so far + self.refused = False + self.paused = False + self.paused_at: float | None = None + self.stopped = False + self.inconclusive: dict[str, list[str]] = {} + self.pool = None + self._pool_lock = threading.Lock() + self.completion = None + self.manifest_sha256: str | None = None + # Each log is a hash chain: a line's `prev` is the line before's sha256. + self._heads = { + name: chain_seed(design["frozen_sha256"], model, name) + for name in ("run-log.jsonl", "admission-log.jsonl") + } + self._counts = {name: 0 for name in self._heads} + # Attempts abandoned at their deadline, whose spend after it is logged. + self.abandoned: list[dict] = [] + + # The records. + + def households(self, lane: int) -> list[str]: + return [ + sid + for i, sid in enumerate(self.run.draw_order) + if i % 2 == lane - 1 and sid not in self.run.no_output + ] + + def write_line(self, line: dict, name: str = "run-log.jsonl") -> None: + with self._log_lock: + text = json.dumps({**line, "prev": self._heads[name]}) + self.folder.mkdir(parents=True, exist_ok=True) + with (self.folder / name).open("a") as handle: + handle.write(text + "\n") + handle.flush() + os.fsync(handle.fileno()) + self._heads[name] = line_sha(text) + self._counts[name] += 1 + + def heads(self) -> dict: + """Each log's line count and last line's sha256, for an anchor.""" + with self._log_lock: + return { + name: {"lines": self._counts[name], "sha256": self._heads[name]} + for name in self._heads + } + + def event( + self, kind: str, reason: str, at: float | None = None, cause=None, **extra + ) -> None: + line = {"event": kind, "time": clock() if at is None else at, "reason": reason} + if cause is not None: + line["cause"] = cause + self.write_line({**line, **extra}) + self.run.say(f"{self.model}: {kind} ({reason})") + + def attempt_line(self, sid: str, lane: int, a: Attempt, sha: str) -> None: + self.write_line( + { + "household": sid, + "arm": a.label, + "lane": lane, + "attempt": a.n, + "start": a.start, + "end": a.end, + "status": a.record.get("status"), + "class": a.cls, + "action": action(a.cls, a.n), + "sha256": sha, + } + ) + a.logged = True + + # Stops and pauses. + + def halted(self) -> bool: + return self.stopped or self.run._failed.is_set() or self.run.ceiling.exhausted() + + def stop( + self, reason: str, cause: str, kind: str = "stop", at: float | None = None + ) -> None: + """Stop the lanes. Every rule that stops them writes its own event, + naming its cause.""" + if (kind, cause) != ("ceiling", "ceiling") and cause not in STOP_CAUSES: + raise ValueError(f"no stop has the cause {cause!r}") + with self.cond: + self.stopped = True + self.cond.notify_all() + self.event(kind, reason, at, cause=cause) + + def resume(self, note: str, noted_at: float) -> bool: + """A note may end only a pause it was written during; another lane's + later operator failure cannot be cleared by the older note.""" + with self.cond: + if not (self.paused and noted_at >= self.paused_at): + return False + self.paused = False + self.cond.notify_all() + self.event("resume", note) + return True + + # One household. + + def admit(self, sid: str, lane: int) -> bool: + with self.cond: + while not self.halted() and ( + self.paused or "settling" in self.state.values() + ): + self.cond.wait(timeout=WAIT_SECONDS) + # Taken under the ceiling's lock, so no decision follows the crossing. + with self.run.ceiling.lock: + if ( + self.stopped + or self.run._failed.is_set() + or self.run.ceiling.crossed_at is not None + ): + return False + now = clock() + finished = [h for h, s in self.state.items() if s == "finished"] + spend = sum(self.spent[h] for h in finished) + under_way = len(self.state) - len(finished) + 1 + ok = ( + not self.refused + and spend + under_way * self.reserve <= self.cap + ADMISSION_SLACK + ) + self.write_line( + { + "household": sid, + "lane": lane, + "time": now, + "decision": "admit" if ok else "refuse", + "finished_spend": spend, + "under_way": under_way, + "reserve": self.reserve, + "cap": self.cap, + }, + "admission-log.jsonl", + ) + if ok: + self.state[sid], self.spent[sid] = "running", 0.0 + else: + self.refused = True + self.cond.notify_all() + return ok + + def start_attempt(self) -> float | None: + """The attempt's start, or None when the lanes have stopped. Waits out a + pause. The start is taken under the ceiling's lock, so no attempt + starts after the crossing.""" + with self.cond: + while self.paused and not self.halted(): + self.cond.wait(timeout=WAIT_SECONDS) + with self.run.ceiling.lock: + if ( + self.stopped + or self.run._failed.is_set() + or self.run.ceiling.crossed_at is not None + ): + return None + return clock() + + def end_attempt( + self, + sid: str, + label: str, + n: int, + start: float, + record: dict, + last: bool, + deadline: bool = False, + retained: list[Attempt] | None = None, + ) -> Attempt: + """The attempt's end. A class decided without the host evidence acts at + once: an operator failure pauses the lanes, a harness failure stops + them, before any other attempt can start; so does an attempt + abandoned at its deadline.""" + with self.cond: + end = clock() + self.spent[sid] += attempt_cost(record) + attempt = Attempt(label, n, start, end, record) + if retained is not None: + retained.append(attempt) # recovery owns it before any event I/O + cls, detail = classify(record, start, end, None) + if cls in EARLY: + attempt.cls, attempt.detail = cls, detail + if cls == "operator": + self.paused, self.paused_at = True, clock() + if cls == "harness" or deadline: + self.stopped = True + if last: + self.state[sid] = "settling" + self.cond.notify_all() + if cls == "operator": + self.event( + "pause", f"{label}/{sid} attempt {n}: {detail}", at=self.paused_at + ) + if cls == "harness": + self.event( + "stop", + f"{label}/{sid}: a request class on the first request ({detail})", + cause="harness", + ) + if deadline: + self.event( + "stop", + f"{label}/{sid} attempt {n} ran past the attempt deadline " + f"of {ATTEMPT_DEADLINE:.0f} s", + cause="deadline", + ) + return attempt + + def settle(self, sid: str, done: list[Attempt]) -> None: + """Each attempt's class once the host evidence for the pass is in.""" + last = max(a.end for a in done) + host = self.run.host + host.wait_settled(last) + host.refresh(after=last) + stop = None + for a in done: + cls, detail = classify(a.record, a.start, a.end, host) + if a.cls and a.cls != cls: + raise RuntimeError(f"{a.label}/{sid}: class {a.cls} became {cls}") + a.cls, a.detail, a.settled = cls, detail, True + a.reason = ( + f"{detail}: {host.describe(a.start, a.end)}" + if cls == "host" + else detail + ) + status = a.record.get("status") + if cls == "inconclusive" and status in ("provider_error", "harness_error"): + key = f"{status}: {error_class(a.record) or a.record.get('error')}" + with self.cond: + seen = self.inconclusive.setdefault(key, []) + if sid not in seen: + seen.append(sid) + if len(seen) > INCONCLUSIVE_STOP and stop is None: + stop = f"{key} ended runs in {len(seen)} households" + if stop: + self.stop(stop, cause="inconclusive") + + def converse(self, sid: str, label: str, n: int) -> tuple[dict, bool]: + """(the attempt's record, whether it was abandoned). The conversation + runs in a thread of its own. One that raises leaves a harness-error + record with the spend it counted; one still running at + ATTEMPT_DEADLINE is abandoned with a harness-error record holding + the spend so far, ends `budget_stop` at its next turn, and writes + nothing.""" + profile = self.profiles[label] + variables = self.run.board["variables"][sid] + features = frozenset(profile.tool_features) + spend = AttemptSpend(self.run.ceiling) + + def tool_call(arguments): + message = ( + pilot.tool_call_frame(features, arguments) if features else arguments + ) + return self.pool.call(message) + + box: dict = {} + + def work(): + try: + box["record"] = self.run.converse(self, sid, label, tool_call, spend) + except Exception as error: # an attempt that left no record of its own + box["error"] = error + + thread = threading.Thread( + target=work, name=f"{self.model}-{sid}-{label}-{n}", daemon=True + ) + thread.start() + thread.join(timeout=ATTEMPT_DEADLINE) + if thread.is_alive(): + spent = spend.abandon() + with self.cond: + self.abandoned.append( + { + "household": sid, + "arm": label, + "attempt": n, + "spend": spend, + "thread": thread, + "logged": 0.0, + } + ) + error = AttemptDeadline( + f"past the attempt deadline of {ATTEMPT_DEADLINE:.0f} s" + ) + record = pilot.harness_error_record(sid, variables, profile, error) + record["totals"]["cost_usd"] = spent + return record, True + if "error" in box: + record = pilot.harness_error_record(sid, variables, profile, box["error"]) + record["totals"]["cost_usd"] = spend.spent_usd + return record, False + return box["record"], False + + def log_late(self, final: bool = False) -> None: + """A `late-cost` event for each abandoned attempt that has ended (or, + at the end of the run, for each one still running) with spend after + its deadline not yet logged.""" + with self.cond: + pending = list(self.abandoned) + for item in pending: + ended = not item["thread"].is_alive() + late = item["spend"].late_usd + if (ended or final) and late > item["logged"]: + self.event( + "late-cost", + f"{item['arm']}/{item['household']} attempt {item['attempt']}: " + "spend after its deadline", + household=item["household"], + arm=item["arm"], + attempt=item["attempt"], + cost_usd=late - item["logged"], + ) + item["logged"] = late + if ended: + with self.cond: + self.abandoned.remove(item) + + def ensure_pool(self, startup: bool = False) -> bool: + """The model's pool, started again if it has lost every worker; False + if it cannot be.""" + with self._pool_lock: + if self.halted(): + return False + if ( + self.pool is not None + and self.pool.counters()["lost"] < self.run.workers + ): + return True + old = self.pool + start, outcome = clock(), "failed" + if not startup: + self.event( + "setup-start", + "engine pool restart", + at=start, + phase="restart", + start=start, + ) + try: + try: + self.pool = self.run.pool_factory(self) + except RuntimeError as error: + self.run.say( + f"{self.model}: the engine pool did not start: {error}" + ) + return False + if old is not None: + self.run.say( + f"{self.model}: the engine pool lost every worker; " + "started again" + ) + old.close() + outcome = "stopped" if self.halted() else "ready" + return outcome == "ready" + finally: + if not startup: + self.event( + "setup-end", + "engine pool restart", + phase="restart", + start=start, + outcome=outcome, + ) + + def replace(self, sid: str, lane: int, previous: Attempt, entries: list) -> None: + """Save the attempt a rerun replaces, before the rerun.""" + folder = self.households_dir[previous.label] / "attempts" + name = f"{sid}-{previous.n}.json" + sha = write_json(folder / name, previous.record) + entries.append( + { + "n": previous.n, + "file": f"attempts/{name}", + "sha256": sha, + "status": previous.record.get("status"), + "class": previous.cls, + "reason": previous.reason, + } + ) + self.attempt_line(sid, lane, previous, sha) + + def passes( + self, sid: str, lane: int, attempts: dict, entries: dict, in_flight: Path + ) -> None: + """The household's arms in its drawn order, then its reruns in passes, + each pass classed once its host evidence is in.""" + todo = [(1, label) for label in self.orders[sid]] + while todo: + done: list[Attempt] = [] + for i, (n, label) in enumerate(todo): + if not self.ensure_pool(): + if not self.halted(): + self.stop("the engine pool could not be started again", "pool") + break + start = self.start_attempt() + if start is None: + break + if n > 1: + self.replace(sid, lane, attempts[label][-1], entries[label]) + record, abandoned = self.converse(sid, label, n) + a = self.end_attempt( + sid, + label, + n, + start, + record, + i == len(todo) - 1, + abandoned, + retained=attempts[label], + ) + done.append(a) + write_json(in_flight / f"{label}-{n}.json", record) + self.run.say( + f"{self.model} lane {lane} {sid} {label} #{n}: " + f"{record.get('status')} ${attempt_cost(record):.4f} " + f"(total ${self.run.ceiling.spent_usd:.2f})" + ) + if not done: + break + self.settle(sid, done) + cut = len(done) < len(todo) + todo = ( + [] + if cut or self.halted() + else [ + (a.n + 1, a.label) + for a in done + if a.n <= MAX_RERUNS and a.cls in RERUN + ] + ) + with self.cond: + self.state[sid] = "running" if todo else "finished" + self.cond.notify_all() + + def run_household(self, sid: str, lane: int) -> bool: + """One household; False when the runner failed part way. Then every + model stops, and the attempts that ended are classed (as `unsettled` + when their host evidence cannot be read) and written before the lane + ends.""" + attempts: dict[str, list[Attempt]] = {label: [] for label in self.orders[sid]} + entries: dict[str, list[dict]] = {label: [] for label in self.orders[sid]} + in_flight = self.folder / "in-flight" / sid + failure = None + try: + self.passes(sid, lane, attempts, entries, in_flight) + except Exception as error: + self.run._failed.set() # block starts while records are recovered + failure = ( + f"runner error on {self.model} lane {lane} ({sid}): " + f"{type(error).__name__}: {error}" + ) + self.run.say(traceback.format_exc()) + pending = [a for mine in attempts.values() for a in mine if not a.settled] + if pending: + try: + self.settle(sid, pending) + except Exception as again: + self.run.say(traceback.format_exc()) + for a in pending: + a.cls, a.settled = "unsettled", True + a.detail = a.reason = ( + f"unsettled: {type(again).__name__}: {again}" + ) + for label, mine in attempts.items(): + if mine and not mine[-1].logged: + final = mine[-1] + try: + sha = write_json( + self.households_dir[label] / f"{sid}.json", + { + **final.record, + "attempts": [ + entry + for entry in entries[label] + if entry["n"] < final.n + ], + }, + ) + self.attempt_line(sid, lane, final, sha) + except Exception as error: # the other arms still get written + self.run._failed.set() + failure = failure or ( + f"runner error writing {self.model} lane {lane} ({sid}): " + f"{type(error).__name__}: {error}" + ) + self.run.say(traceback.format_exc()) + if failure is not None: + self.run.stop_all(failure, cause="runner-error") + with self.cond: + self.state[sid] = "finished" + self.cond.notify_all() + if failure is None: + shutil.rmtree(in_flight, ignore_errors=True) + return failure is None + + def lane(self, lane: int) -> None: + try: + for sid in self.households(lane): + if not self.admit(sid, lane) or not self.run_household(sid, lane): + return + except Exception as error: # a runner defect: every model stops + self.run.say(traceback.format_exc()) + self.run.stop_all( + f"runner error on {self.model} lane {lane}: " + f"{type(error).__name__}: {error}", + cause="runner-error", + ) + + def manifest(self) -> dict: + board, design = self.run.board, self.run.design + pe3 = arm_profile(self.model, "pe3") + first = sorted(board["scenarios"])[0] + + def timeout(profile): + built = pilot.build_initial_request( + board["scenarios"][first], board["variables"][first], profile + ) + return built[1].get("timeout") + + board_path = Path(design["board"]) + return { + "started_at_utc": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()), + "git_head": pilot._git("rev-parse", "HEAD"), + "git_dirty": bool(pilot._git("status", "--porcelain")), + "script_sha256": sha256_file(Path(__file__)), + "harness_sha256": sha256_file(Path(pilot.__file__)), + "treatment_commit": TREATMENT_COMMIT, + "versions": pilot._versions(), + "fix_module": str(pilot.FIX_MODULE.relative_to(pilot.ROOT)), + "fix_module_sha256": sha256_file(pilot.FIX_MODULE), + "board": str(board_path), + "board_engine": f"policyengine-us {pilot.board_engine(board_path)}", + "board_reference_sha256": sha256_file(board_path / "reference_outputs.csv"), + "model": self.model, + "model_id": pe3.model_id, + "api": pe3.api, + "answer_contract": pe3.contract, + "prompt_version": PROMPT_VERSION, + "prompt_wording_sha256": pilot.prompt_wording_sha256(pe3), + "request_timeout_seconds": timeout(pe3), + "turn_cap": pilot.TOOL_TURN_CAP, + "max_calculations_per_turn": pilot.MAX_CALCULATIONS_PER_TURN, + "tool_timeout_seconds": pilot.TOOL_TIMEOUT_SECONDS, + "arms": { + label: { + "arm": arm_string(label), + "features": sorted(self.profiles[label].tool_features), + } + for label in self.labels + }, + "arm_settings": { + label: { + "tool_notice_sha256": hashlib.sha256( + profile.notice.encode() + ).hexdigest(), + **pilot.profile_treatment(profile), + "tool_version": profile.tool_version, + "request_timeout_seconds": timeout(profile), + } + for label, profile in self.profiles.items() + }, + "folders": { + label: str(path) for label, path in self.households_dir.items() + }, + "cap_usd": self.cap, + "reserve_usd": self.reserve, + "overall_cap_usd": float(design["overall_cap"]), + "ceiling_usd": self.run.ceiling.budget_usd, + "spent_before_usd": float(design["spent_before"]), + "lanes": {lane: self.households(lane) for lane in (1, 2)}, + "no_scored_output": sorted(self.run.no_output), + "workers": self.run.workers, + "attempt_deadline_seconds": ATTEMPT_DEADLINE, + "anchor_seconds": ANCHOR_SECONDS, + "anchor_command": list(design["anchor_command"]), + } + + def summary(self) -> dict: + records = [] + for label, folder in self.households_dir.items(): + for path in sorted(folder.glob("*.json")) if folder.is_dir() else []: + records.append(json.loads(path.read_text())) + lines = [] + path = self.folder / "run-log.jsonl" + if path.exists(): + lines = [json.loads(x) for x in path.read_text().splitlines() if x.strip()] + attempts = [x for x in lines if "event" not in x] + count: dict[str, int] = {} + for x in attempts: + count[x["class"]] = count.get(x["class"], 0) + 1 + return { + "finished_at_utc": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()), + "model": self.model, + "households_finished": sorted( + h for h, s in self.state.items() if s == "finished" + ), + "refused": self.refused, + "stopped": self.stopped, + "spent_usd": sum(self.spent.values()), + "final_records": len(records), + "attempts": len(attempts), + "classes": dict(sorted(count.items())), + "events": [x for x in lines if "event" in x], + "tool_pool": self.pool.counters() if self.pool is not None else None, + "abandoned_running": len(self.abandoned), + } + + +# ---------------------------------------------------------------- the run + + +def default_pool(lanes: Lanes): + return pilot.ToolPool( + size=lanes.run.workers, + board=Path(lanes.run.design["board"]), + tool_features=frozenset(), + ) + + +def default_completion(profile: pilot.ModelProfile): + from litellm import completion, responses + + return responses if profile.api == "responses" else completion + + +class Run: + """The six models' lanes, the host log and the hard ceiling.""" + + def __init__( + self, + design: dict, + workers: int | None = None, + models: tuple[str, ...] | None = None, + converse: Callable = converse_with_harness, + pool_factory: Callable = default_pool, + completion_for: Callable = default_completion, + host_factory: Callable | None = None, + out=sys.stdout, + ): + self.design, self.out = design, out + self.workers = int(design["workers"]) if workers is None else workers + self.converse, self.pool_factory = converse, pool_factory + self.completion_for = completion_for + self.host_factory = host_factory or (lambda folder: HostLog(folder)) + self._say_lock = threading.Lock() + self.master = master_seed(design["frozen_sha256"]) + self.draw_order = list(design["draw_order"]) + board_path = Path(design["board"]) + pilot.set_stated_engine(pilot.board_engine(board_path)) + self.board = pilot.load_board(board_path) + scored = {str(s) for s in self.board["scored"]["scenario_id"]} + self.no_output = {sid for sid in self.draw_order if sid not in scored} + self.ceiling = Ceiling( + float(design["overall_cap"]) + CEILING_MARGIN, float(design["spent_before"]) + ) + self.models = tuple(models or CHEAP + FRONTIER) + self.lanes = { + model: Lanes( + self, + model, + ARMS if model in CHEAP else FRONTIER_ARMS, + design["arms"] if model in CHEAP else design["frontier_arms"], + ) + for model in self.models + } + self.host: HostLog | None = None + self._ceiling_written = False + self.interrupts = 0 + self.signalled: int | None = None # set by the signal handler alone + self._interrupted = False + self._sampler_stopped = False + self._failed = threading.Event() # recovery blocks starts before stop I/O + self._anchor_head = chain_seed(design["frozen_sha256"], "", "anchors.jsonl") + self._anchored = -math.inf + self._pushing = threading.Lock() + self._next_anchor = -math.inf + self._push: threading.Thread | None = None + self._push_error: OSError | None = None + self._push_pending: dict | None = None + self._last_push_outcome: str | None = None + + def say(self, text: str) -> None: + with self._say_lock: + print(text, file=self.out, flush=True) + + def stop_all( + self, reason: str, cause: str, kind: str = "stop", at: float | None = None + ) -> None: + # Set every state before the first fallible write; notify even if a + # disk error prevents a model's event from being recorded. + for lanes in self.lanes.values(): + with lanes.cond: + lanes.stopped = True + lanes.cond.notify_all() + for lanes in self.lanes.values(): + try: + lanes.event(kind, reason, at, cause=cause) + except Exception: + self.say(traceback.format_exc()) + + # Anchors: the logs' chain heads, written and pushed outside the run. + + def _check_push_error(self) -> None: + with self._pushing: + error = self._push_error + if error is not None: + raise OSError( + f"anchor push outcome could not be recorded: {error}" + ) from error + + def anchor_due(self) -> bool: + self._check_push_error() + with self._pushing: + return clock() >= self._next_anchor + + def anchor(self, wait: bool = False, push: bool = True) -> None: + """Every log's chain head to `anchors.jsonl`, itself a chain, then the + design's anchor command on a synced snapshot, in the background (one + current worker at a time; an anchor whose push would wait is written + but not pushed until the next). A snapshot is a copy, not a record, + and its path is unique even if a push thread has to be abandoned. + Each push's result goes to `anchor-pushes.jsonl`.""" + runs = Path(self.design["runs"]) + line = { + "time": clock(), + "models": { + model: {**lanes.heads(), "manifest": lanes.manifest_sha256} + for model, lanes in self.lanes.items() + }, + "host-log.jsonl": self.host.heads() if self.host is not None else None, + "prev": self._anchor_head, + } + text = json.dumps(line) + with (runs / "anchors.jsonl").open("a") as handle: + handle.write(text + "\n") + handle.flush() + os.fsync(handle.fileno()) + self._anchor_head, self._anchored = line_sha(text), clock() + with self._pushing: + self._next_anchor = self._anchored + ANCHOR_SECONDS + if not push: + return # a push-log failure still leaves the final local heads + if self._push is not None and self._push.is_alive(): + if not wait: + return + self._join_push() + snapshot = runs / f"anchors.{self._anchor_head}.push-snapshot.jsonl" + tmp = snapshot.with_suffix(".tmp") + with tmp.open("wb") as handle: + handle.write((runs / "anchors.jsonl").read_bytes()) + handle.flush() + os.fsync(handle.fileno()) + os.replace(tmp, snapshot) + with self._pushing: + self._push_pending = { + "anchor": self._anchor_head, + "anchor_time": line["time"], + "started": clock(), + } + self._last_push_outcome = None + self._push = threading.Thread( + target=self._push_anchor, + args=(self._anchor_head, line["time"]), + daemon=True, + ) + self._push.start() + if wait: + self._join_push() + + def _join_push(self) -> None: + """Bound the thread join and retire its outcome if it cannot end. + Its command may survive; the helper's lock and prefix check protect + the clone. Waiting for _pushing still assumes a responsive filesystem.""" + self._push.join(timeout=ANCHOR_PUSH_TIMEOUT + KILL_GRACE + 30) + if self._push.is_alive(): + with self._pushing: + pending = self._push_pending + if pending is not None: + self._record_push( + { + **pending, + "ended": clock(), + "outcome": "error", + "returncode": None, + "output": "the anchor push thread did not end after its time limit; " + "its command may still be running", + } + ) + self._check_push_error() + + def _record_push(self, line: dict) -> None: + """Claim one outcome under the push lock; a late worker cannot repeat it. + The lock covers writing and fsync, so a wedged filesystem can delay + supervision and retirement beyond the thread join's bound.""" + with self._pushing: + pending = self._push_pending + if pending is None or pending["anchor"] != line["anchor"]: + return + self._push_pending = None + self._last_push_outcome = line["outcome"] + if line["outcome"] != "success": + self._next_anchor = min( + self._next_anchor, line["ended"] + ANCHOR_RETRY + ) + try: + path = Path(self.design["runs"]) / "anchor-pushes.jsonl" + with path.open("a") as handle: + handle.write(json.dumps(line) + "\n") + handle.flush() + os.fsync(handle.fileno()) + except OSError as error: + # A daemon's exception must reach the supervisor or final join. + self._push_error = self._push_error or error + return + if line["outcome"] != "success": + self.say( + f"the anchor push failed ({line['outcome']}, " + f"{line['returncode']}): {line['output']}" + ) + + def _push_anchor(self, head: str, anchor_time: float) -> None: + """Push one immutable snapshot and record its bounded command's outcome.""" + runs = Path(self.design["runs"]) + command = [str(x) for x in self.design["anchor_command"]] + command.append(str(runs / f"anchors.{head}.push-snapshot.jsonl")) + with self._pushing: + pending = self._push_pending + if pending is None or pending["anchor"] != head: + return + started = pending["started"] = clock() + try: + child = subprocess.Popen( + command, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + text=True, + start_new_session=True, + ) + try: + stdout, stderr = child.communicate(timeout=ANCHOR_PUSH_TIMEOUT) + outcome = "success" if child.returncode == 0 else "failed" + except subprocess.TimeoutExpired: + # The command is a session leader: git and ssh share its group. + # Killing just the command leaves its push running after timeout. + try: + os.killpg(child.pid, signal.SIGKILL) + except ProcessLookupError: + pass + try: + stdout, stderr = child.communicate(timeout=KILL_GRACE) + except subprocess.TimeoutExpired as error: + for pipe in (child.stdout, child.stderr): + if pipe is not None: + pipe.close() + stdout, stderr = error.output or b"", error.stderr or b"" + if isinstance(stdout, bytes): + stdout = stdout.decode(errors="replace") + if isinstance(stderr, bytes): + stderr = stderr.decode(errors="replace") + stderr += "\npipes were held open after the kill" + outcome = "timeout" + code, text = child.returncode, (stdout + stderr)[-2000:] + except (OSError, subprocess.SubprocessError) as error: + code, outcome, text = None, "error", f"{type(error).__name__}: {error}" + ended = clock() + line = { + "anchor": head, + "anchor_time": anchor_time, + "started": started, + "ended": ended, + "outcome": outcome, + "returncode": code, + "output": text, + } + self._record_push(line) + + # The main loop's work. + + def watch(self, anchor: bool = True) -> None: + """The ceiling's events, an interrupt, a dead sampler, resumes after + operator pauses, late spend and the anchors.""" + crossed = self.ceiling.crossed_at + if crossed is not None and not self._ceiling_written: + self._ceiling_written = True + reason = ( + f"total spend ${self.ceiling.spent_usd:.2f} reached the hard ceiling " + f"${self.ceiling.budget_usd:.2f}" + ) + self.stop_all(reason, "ceiling", kind="ceiling", at=crossed) + if self.signalled is not None and not self._interrupted: + self._interrupted = True + self.say( + f"signal {self.signalled}: stopping every model's lanes; " + "the conversations under way finish" + ) + self.stop_all(f"operator stop (signal {self.signalled})", "interrupt") + dead = self.host.dead() if self.host is not None else None + if dead and not self._sampler_stopped: + self._sampler_stopped = True + self.stop_all(f"the host log stopped: {dead}", "sampler") + for lanes in self.lanes.values(): + path = lanes.folder / "RESUME.json" + if not path.exists(): + continue + try: + note = json.loads(path.read_text()) + except (OSError, ValueError): + continue # still being written + stamp = f"{time.time():.3f}" + if lanes.resume( + note.get("note") or "resumed", float(note.get("time") or 0.0) + ): + path.rename(lanes.folder / f"resume-{stamp}.json") + else: + # Written before the pause it would end, or with no pause. + path.rename(lanes.folder / f"resume-ignored-{stamp}.json") + self.say(f"{lanes.model}: a resume written before any pause, ignored") + for lanes in self.lanes.values(): + lanes.log_late() + if anchor and self.anchor_due(): + self.anchor() + + def execute(self) -> None: + runs = Path(self.design["runs"]) + starting, threads = {}, [] + setup_open = set() + try: + self.host = self.host_factory(runs / "host") + ready, failures = {}, {} + startup = clock() + for lanes in self.lanes.values(): + lanes.event( + "setup-start", + "run startup", + at=startup, + phase="startup", + start=startup, + ) + setup_open.add(lanes.model) + for model, lanes in self.lanes.items(): + self.watch(anchor=False) + lanes.completion = self.completion_for(lanes.profiles["pe3"]) + stamp = time.strftime("%Y-%m-%dT%H%M%SZ", time.gmtime()) + lanes.manifest_sha256 = write_json( + lanes.folder / f"manifest-{stamp}.json", lanes.manifest(), indent=2 + ) + # A model whose lanes never decide still has both logs. + for name in ("run-log.jsonl", "admission-log.jsonl"): + (lanes.folder / name).touch() + + def start_pool(model, lanes): + try: + ready[model] = lanes.ensure_pool(startup=True) + except Exception as error: + failures[model] = error + self._failed.set() + + for model, lanes in self.lanes.items(): + self.watch() + if lanes.halted(): + continue + starting[model] = threading.Thread( + target=start_pool, args=(model, lanes), daemon=True + ) + starting[model].start() + while any(t.is_alive() for t in starting.values()): + self.watch() + for thread in starting.values(): + thread.join(timeout=0.5 / len(starting)) + self.watch() + for model, lanes in self.lanes.items(): + outcome = ( + "failed" + if model in failures + else "stopped" + if lanes.halted() + else "ready" + if ready.get(model) + else "failed" + ) + lanes.event( + "setup-end", + "run startup", + phase="startup", + start=startup, + outcome=outcome, + ) + setup_open.discard(model) + if outcome == "failed" and model not in failures: + lanes.stop("the engine pool could not be started", "pool") + if failures: + raise next(iter(failures.values())) + threads = [] + for model, lanes in self.lanes.items(): + for lane in (1, 2): + self.watch() + with lanes.cond: + if lanes.halted() or self.signalled is not None: + continue + thread = threading.Thread( + target=lanes.lane, + args=(lane,), + name=f"{model}-{lane}", + daemon=True, + ) + thread.start() + threads.append(thread) + while any(t.is_alive() for t in threads): + self.watch() + for t in threads: + t.join(timeout=0.5 / len(threads)) + self.watch() + except Exception as error: + self._failed.set() + # Supervisors finish their bounded attempts and recovery before + # the ledger, host and final anchor can close underneath them. + for lanes in self.lanes.values(): + with lanes.cond: + lanes.cond.notify_all() + for thread in [*starting.values(), *threads]: + while thread.is_alive(): + thread.join(timeout=WAIT_SECONDS) + try: + self.watch(anchor=False) + except Exception: + self.say(traceback.format_exc()) + for model in setup_open: + try: + self.lanes[model].event( + "setup-end", + "run startup", + phase="startup", + start=startup, + outcome="failed", + ) + except Exception: + self.say(traceback.format_exc()) + self.stop_all( + f"runner error: {type(error).__name__}: {error}", "runner-error" + ) + raise + finally: + self.finish() + + def finish(self) -> None: + """One join deadline, then close pools and host before closing the + ledger. Its final late costs, crossings and signals precede the last + anchor. An unresolved request makes future spend unknowable: record + it explicitly, with a runner-error stop, rather than claim it settled. + Retry the final push up to three times per set of heads, waiting + ANCHOR_RETRY after each failed try ends. Then ignore signals and check + once more for a first signal needing coverage. Signals during the + resulting re-anchoring are ignored, including a second interrupt.""" + errors = [] + + def attempt(work): + try: + work() + return True + except Exception as error: + errors.append(error) + self._failed.set() + self.say(traceback.format_exc()) + self.stop_all( + f"runner error during cleanup: {type(error).__name__}: {error}", + "runner-error", + ) + return False + + until = time.monotonic() + LATE_JOIN + for lanes in self.lanes.values(): + for item in list(lanes.abandoned): + while item["thread"].is_alive() and time.monotonic() < until: + item["thread"].join( + timeout=min(WAIT_SECONDS, max(0.0, until - time.monotonic())) + ) + attempt(lambda: self.watch(anchor=False)) + for lanes in self.lanes.values(): + if lanes.pool is not None: + attempt(lanes.pool.close) + if self.host is not None: + attempt(self.host.close) + pending = [] + for lanes in self.lanes.values(): + with lanes.cond: + pending.extend({**item, "lanes": lanes} for item in lanes.abandoned) + unresolved = self.ceiling.close(pending) + for lanes in self.lanes.values(): + attempt(lambda: lanes.log_late(final=True)) + for item in unresolved: + attempt( + lambda: item["lanes"].event( + "late-unresolved", + "request unresolved when the ledger closed; " + "future spend is unrecorded", + household=item["household"], + arm=item["arm"], + attempt=item["attempt"], + outcome="unresolved-at-ledger-close", + counted_usd=item["spend"].spent_usd + item["spend"].late_usd, + ) + ) + if unresolved: + self._failed.set() + self.stop_all( + f"{len(unresolved)} abandoned requests unresolved at ledger close; " + "future spend is unrecorded", + "runner-error", + ) + # A first signal can also arrive while the final push is running. + while True: + attempt(lambda: self.watch(anchor=False)) + for lanes in self.lanes.values(): + stamp = time.strftime("%Y-%m-%dT%H%M%SZ", time.gmtime()) + attempt( + lambda: write_json( + lanes.folder / f"run-summary-{stamp}.json", + lanes.summary(), + indent=2, + ) + ) + for push_try in range(FINAL_PUSH_TRIES): + if push_try: + time.sleep(ANCHOR_RETRY) + if not attempt(lambda: self.anchor(wait=True)): + attempt(lambda: self.watch(anchor=False)) + # The error handler appended stops after that snapshot. Keep + # them covered locally even if pushing cannot be recorded. + try: + self.anchor(push=False) + except Exception as error: + errors.append(error) + self.say(traceback.format_exc()) + break + if self._last_push_outcome == "success": + break + if self.signalled is not None and not self._interrupted: + continue + self._ignore_signals() + if self.signalled is not None and not self._interrupted: + continue + break + if errors: + raise errors[0] + + def _ignore_signals(self) -> None: + """Close signal delivery before the last check; the process is ending.""" + signal.signal(signal.SIGINT, signal.SIG_IGN) + signal.signal(signal.SIGTERM, signal.SIG_IGN) + + def interrupt(self, signum, frame) -> None: + """The signal handler. It only notes the signal; the main loop stops + every model's lanes. A second signal exits at once while this handler + is installed; cleanup ignores signals before its final check.""" + self.interrupts += 1 + if self.interrupts > 1: + os._exit(130) + self.signalled = signum + + +# ---------------------------------------------------------------- before a run + + +def host_power() -> tuple[bool, bool]: + """(on AC power, lid open).""" + batt = subprocess.run( + ["pmset", "-g", "batt"], capture_output=True, text=True + ).stdout + lid = subprocess.run( + ["ioreg", "-r", "-k", "AppleClamshellState", "-d", "1"], + capture_output=True, + text=True, + ).stdout + return "'AC Power'" in batt, '"AppleClamshellState" = No' in lid + + +def preflight(design: dict, models: tuple[str, ...]) -> list[str]: + """What stops the run from starting.""" + missing = [k for k in REQUIRED if k not in design] + if missing: + return [f"the design has no {', '.join(missing)}"] + problems = [] + from confirmatory_no_tools import stage_problems + + problems.extend(stage_problems(design)) + try: + no_tools_root = Path(design["no_tools"]["runs"]).resolve() + calculator_root = Path(design["runs"]).resolve() + if no_tools_root.is_relative_to( + calculator_root + ) or calculator_root.is_relative_to(no_tools_root): + problems.append("the no-tools and calculator runs roots overlap") + except (KeyError, TypeError, OSError, ValueError) as error: + problems.append(f"the no-tools runs root is invalid: {error}") + command = design["anchor_command"] + if ( + not isinstance(command, list) + or not command + or shutil.which(str(command[0])) is None + ): + problems.append(f"the anchor command {command!r} is not a command here") + if design.get("stated_engine_overrides"): + problems.append("the confirmatory run states the board's engine: no overrides") + if sha256_file(Path(design["preregistration"])) != design["frozen_sha256"]: + problems.append("the frozen copy does not hash to frozen_sha256") + pool = design["eligible_pool"] + if sha256_file(Path(pool["path"])) != pool["sha256"]: + problems.append("the eligible pool does not hash as frozen") + else: + ids = [e["id"] for e in json.loads(Path(pool["path"]).read_text())] + if draw(master_seed(design["frozen_sha256"]), ids) != list( + design["draw_order"] + ): + problems.append( + "the draw, recomputed from the stream 'draw', is not the design's" + ) + head, dirty = pilot._git("rev-parse", "HEAD"), pilot._git("status", "--porcelain") + if head != design["run_commit"] or dirty: + problems.append( + f"the runner is at {head[:12]} (dirty {bool(dirty)}), " + "not the run commit, clean" + ) + changed = subprocess.run( + [ + "git", + "-C", + str(pilot.ROOT), + "diff", + "--quiet", + TREATMENT_COMMIT, + "HEAD", + "--", + *TREATMENT_PATHS, + ] + ).returncode + if changed: + problems.append(f"the treatment's code differs from {TREATMENT_COMMIT[:12]}'s") + import policybench + + places = [Path(p).resolve() for p in policybench.__path__] + if pilot.ROOT != ROOT or not all(p.is_relative_to(ROOT) for p in places): + problems.append( + f"the harness ({pilot.__file__}) or policybench ({places}) is not " + "this checkout's" + ) + harness = design["treatment_harness"] + harness_head = subprocess.run( + ["git", "-C", harness, "rev-parse", "HEAD"], capture_output=True, text=True + ).stdout.strip() + if harness_head != TREATMENT_COMMIT: + problems.append( + f"the treatment harness is at {harness_head[:12]}, " + f"not {TREATMENT_COMMIT[:12]}" + ) + board = Path(design["board"]) + engine = pilot.board_engine(board) + if f"policyengine-us {engine}" != design["engine"]: + problems.append( + f"the board's engine {engine} is not the design's {design['engine']}" + ) + installed = pilot._versions()["policyengine-us"] + if installed != engine: + problems.append(f"policyengine-us {installed} is installed, not {engine}") + if set(design["arms"]) != set(ARMS) or set(design["frontier_arms"]) != set( + FRONTIER_ARMS + ): + problems.append("the design's arms are not the registered ones") + for name in ("arms", "frontier_arms"): + if len(set(design[name].values())) != len(design[name]): + problems.append(f"two {name} share a folder") + for model in models: + if model not in design["caps"] or model not in design["reserves"]: + problems.append(f"{model}: no cap or reserve") + for label in ARMS if model in CHEAP else FRONTIER_ARMS: + try: + arm_profile(model, label) + except (ValueError, SystemExit) as error: + problems.append(str(error)) + key = pilot.provider_key(pilot.model_profile(model).model_id) + if not os.environ.get(key): + problems.append(f"{model}: {key} is not set") + folder = Path(design["runs"]) / model + if (folder / "run-log.jsonl").exists() or any( + folder.glob("*/*/households/*.json") + ): + problems.append(f"{folder} already holds records; a run is never resumed") + if (Path(design["runs"]) / "host" / "host-log.jsonl").exists(): + problems.append("the runs folder already holds a host log") + ac, lid = host_power() + if not (ac and lid): + problems.append( + f"the host is not on AC power with the lid open (AC {ac}, lid open {lid})" + ) + return problems + + +def main(argv=None) -> int: + parser = argparse.ArgumentParser(description=__doc__.split("\n\n")[0]) + sub = parser.add_subparsers(dest="command", required=True) + run = sub.add_parser("run", help="run the confirmatory stage") + run.add_argument("design", type=Path) + run.add_argument( + "--workers", type=int, help="engine workers per model: the design's alone" + ) + run.add_argument("--dry-run", action="store_true", help="check and print the plan") + resume = sub.add_parser("resume", help="end an operator pause") + resume.add_argument("design", type=Path) + resume.add_argument("model") + resume.add_argument("--note", default="the account was fixed") + args = parser.parse_args(argv) + design = json.loads(args.design.read_text()) + if args.command == "resume": + folder = Path(design["runs"]) / args.model + write_json(folder / "RESUME.json", {"time": time.time(), "note": args.note}) + print(f"{args.model}: resume requested; the runner resumes within a second") + return 0 + if args.workers is not None and args.workers != design.get("workers"): + print( + f"The run cannot start: --workers {args.workers}, and the design " + f"runs {design.get('workers')} engine workers per model." + ) + return 1 + models = CHEAP + FRONTIER + problems = preflight(design, models) + pilot._require_engine(Path(design["board"])) + if problems: + print("The run cannot start:\n" + "\n".join(f"- {p}" for p in problems)) + return 1 + plan = Run(design) + if args.dry_run: + for model, lanes in plan.lanes.items(): + sizes = [len(lanes.households(lane)) for lane in (1, 2)] + print( + f"{model}: arms {', '.join(lanes.labels)}; lanes {sizes[0]} and " + f"{sizes[1]} households; cap ${lanes.cap:.2f}, " + f"reserve ${lanes.reserve:.2f}" + ) + print( + f"no scored output: {sorted(plan.no_output)}; hard ceiling " + f"${plan.ceiling.budget_usd:.2f} " + f"(${plan.ceiling.spent_usd:.2f} spent before)" + ) + return 0 + signal.signal(signal.SIGINT, plan.interrupt) + signal.signal(signal.SIGTERM, plan.interrupt) + plan.execute() + return 0 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/tests/fake_anchor.py b/tests/fake_anchor.py new file mode 100644 index 00000000..73b5c32f --- /dev/null +++ b/tests/fake_anchor.py @@ -0,0 +1,13 @@ +"""The confirmatory runner's anchor command in its tests: a copy of the run's +anchors.jsonl to FOLDER/anchored.jsonl. + +Usage: python fake_anchor.py FOLDER ANCHORS +""" + +import shutil +import sys +from pathlib import Path + +folder, anchors = Path(sys.argv[1]), Path(sys.argv[2]) +shutil.copyfile(anchors, folder / "anchored.jsonl") +print("anchored") diff --git a/tests/test_confirmatory_anchor.py b/tests/test_confirmatory_anchor.py new file mode 100644 index 00000000..fbc5a367 --- /dev/null +++ b/tests/test_confirmatory_anchor.py @@ -0,0 +1,1147 @@ +"""The anchor command: each call commits the run's anchors and pushes them.""" + +import fcntl +import hashlib +import io +import json +import math +import os +import select +import signal +import subprocess +import sys +import threading +import time +from pathlib import Path + +import pytest + +sys.path.insert(0, str(Path(__file__).resolve().parents[1] / "scripts")) + +import confirmatory_anchor # noqa: E402 +import confirmatory_run as cr # noqa: E402 + +SCRIPT = Path(confirmatory_anchor.__file__) + + +@pytest.fixture +def clone(tmp_path, monkeypatch): + """A clone of an empty bare remote, with git's own settings only.""" + empty = tmp_path / "gitconfig" + empty.write_text("") + monkeypatch.setenv("GIT_CONFIG_GLOBAL", str(empty)) + monkeypatch.setenv("GIT_CONFIG_NOSYSTEM", "1") + for role in ("AUTHOR", "COMMITTER"): + monkeypatch.setenv(f"GIT_{role}_NAME", "anchor test") + monkeypatch.setenv(f"GIT_{role}_EMAIL", "anchor@example.invalid") + remote = tmp_path / "remote.git" + subprocess.run(["git", "init", "-q", "--bare", str(remote)], check=True) + repo = tmp_path / "anchors" + subprocess.run(["git", "clone", "-q", str(remote), str(repo)], check=True) + return remote, repo + + +def remote_log(remote: Path) -> list[str]: + out = subprocess.run( + ["git", "-C", str(remote), "log", "--format=%s", "HEAD"], + check=True, + capture_output=True, + text=True, + ) + return out.stdout.splitlines() + + +def remote_file(remote: Path) -> str: + out = subprocess.run( + ["git", "-C", str(remote), "show", "HEAD:anchors.jsonl"], + check=True, + capture_output=True, + text=True, + ) + return out.stdout + + +def anchor_command(repo: Path, anchors: Path): + """Run the real helper and retain its failure message and exit status.""" + return subprocess.run( + [sys.executable, str(SCRIPT), "--repo", str(repo), str(anchors)], + capture_output=True, + text=True, + ) + + +@pytest.mark.parametrize("name", ["anchors.jsonl", "anchors.push-snapshot.jsonl"]) +def test_each_anchor_is_committed_and_pushed(clone, tmp_path, name): + """A snapshot's local name never changes the remote record's name.""" + remote, repo = clone + anchors = tmp_path / name + lines = ['{"time": 1.0, "prev": "a"}', '{"time": 2.0, "prev": "b"}'] + shas = [hashlib.sha256(line.encode()).hexdigest() for line in lines] + anchors.write_text(lines[0] + "\n") + assert confirmatory_anchor.main(["--repo", str(repo), str(anchors)]) == 0 + anchors.write_text("\n".join(lines) + "\n") + assert confirmatory_anchor.main(["--repo", str(repo), str(anchors)]) == 0 + assert remote_log(remote) == [f"anchor 2: {shas[1]}", f"anchor 1: {shas[0]}"] + assert remote_file(remote) == anchors.read_text() + assert sorted(path.name for path in repo.iterdir() if path.name != ".git") == [ + "anchors.jsonl" + ] + + +def test_an_unchanged_file_makes_no_commit(clone, tmp_path): + """An equal snapshot succeeds without changing the file or remote history.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + anchors.write_text('{"time": 1.0}\n') + for _ in range(2): + assert confirmatory_anchor.main(["--repo", str(repo), str(anchors)]) == 0 + assert len(remote_log(remote)) == 1 + assert remote_file(remote) == anchors.read_text() + + +def test_an_older_snapshot_cannot_replace_a_newer_remote_file(clone, tmp_path): + """A delayed helper cannot commit or push a prefix after the newer snapshot.""" + remote, repo = clone + older, newer = tmp_path / "older.jsonl", tmp_path / "newer.jsonl" + older.write_bytes(b'{"time": 1.0}\n') + newer.write_bytes(older.read_bytes() + b'{"time": 2.0}\n') + assert anchor_command(repo, newer).returncode == 0 + history, index = remote_log(remote), (repo / ".git" / "index").read_bytes() + out = anchor_command(repo, older) + assert out.returncode != 0 and "not a byte prefix" in out.stderr + assert (repo / "anchors.jsonl").read_bytes() == newer.read_bytes() + assert (repo / ".git" / "index").read_bytes() == index + assert remote_file(remote).encode() == newer.read_bytes() + assert remote_log(remote) == history + + +def test_a_busy_clone_is_refused_without_changing_its_records(clone, tmp_path): + """A held flock prevents target, index, commit and remote writes.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + first = b'{"time": 1.0}\n' + anchors.write_bytes(first) + assert anchor_command(repo, anchors).returncode == 0 + history, index = remote_log(remote), (repo / ".git" / "index").read_bytes() + anchors.write_bytes(first + b'{"time": 2.0}\n') + with (repo / ".git" / "confirmatory-anchor.lock").open("a") as lock: + fcntl.flock(lock.fileno(), fcntl.LOCK_EX | fcntl.LOCK_NB) + out = anchor_command(repo, anchors) + assert out.returncode != 0 and "busy" in out.stderr + assert (repo / "anchors.jsonl").read_bytes() == first + assert (repo / ".git" / "index").read_bytes() == index + assert remote_file(remote).encode() == first + assert remote_log(remote) == history + + +@pytest.mark.parametrize("hook_name", ["pre-commit", "pre-push", "pre-receive"]) +def test_killing_only_the_helper_keeps_its_git_writer_locked( + clone, tmp_path, hook_name +): + """A Git child already using the clone retains the lock after helper death.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + first = b'{"time": 1.0}\n' + older = first + b'{"time": 2.0}\n' + snapshots = [older + b'{"time": 3.0}\n', older + b'{"time": 3.0}\n{"time": 4.0}\n'] + anchors.write_bytes(first) + assert anchor_command(repo, anchors).returncode == 0 + ready, release = tmp_path / "ready", tmp_path / "release" + for path in (ready, release): + os.mkfifo(path) + hook_lock = tmp_path / "hook-lock.json" + hooks = remote / "hooks" if hook_name == "pre-receive" else repo / ".git" / "hooks" + hook = hooks / hook_name + hook.write_text( + f"#!{sys.executable}\n" + "import json, os\n" + "from pathlib import Path\n" + "if os.environ.get('ANCHOR_TEST_BLOCK') == '1':\n" + f" lock = Path({str(repo / '.git' / 'confirmatory-anchor.lock')!r}).stat()\n" + " inherited = []\n" + " for fd in range(3, 256):\n" + " try:\n" + " info = os.fstat(fd)\n" + " except OSError:\n" + " continue\n" + " if (info.st_dev, info.st_ino) == (lock.st_dev, lock.st_ino):\n" + " inherited.append(os.get_inheritable(fd))\n" + f" Path({str(hook_lock)!r}).write_text(json.dumps(inherited))\n" + f" with open({str(ready)!r}, 'wb', buffering=0) as pipe:\n" + " pipe.write(b'1')\n" + f" with open({str(release)!r}, 'rb', buffering=0) as pipe:\n" + " pipe.read(1)\n" + ) + hook.chmod(0o755) + + def records(): + """Read the clone's file, index, HEAD and the remote without writing.""" + objects = [ + subprocess.run( + ["git", "-C", str(repo), "show", obj], check=True, capture_output=True + ).stdout + for obj in (":anchors.jsonl", "HEAD:anchors.jsonl") + ] + return ( + (repo / "anchors.jsonl").read_bytes(), + (repo / ".git" / "index").read_bytes(), + *objects, + remote_file(remote).encode(), + remote_log(remote), + ) + + ready_fd, release_fd = (os.open(path, os.O_RDWR) for path in (ready, release)) + child = None + try: + anchors.write_bytes(older) + child = subprocess.Popen( + [sys.executable, str(SCRIPT), "--repo", str(repo), str(anchors)], + env={**os.environ, "ANCHOR_TEST_BLOCK": "1"}, + start_new_session=True, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + ) + assert select.select([ready_fd], [], [], 15.0)[0], "Git did not reach its hook" + assert os.read(ready_fd, 1) == b"1" + before = records() + assert before[0] == before[2] == older + child.kill() + assert child.wait(timeout=15.0) == -signal.SIGKILL + for snapshot in snapshots: + anchors.write_bytes(snapshot) + out = anchor_command(repo, anchors) + assert out.returncode == 1 and "busy" in out.stderr, ( + "a surviving Git writer lost the helper's clone lock: " + out.stderr + ) + assert records() == before + assert json.loads(hook_lock.read_text()) == [True] + os.write(release_fd, b"1") + child.communicate(timeout=15.0) + # Pipe closure need not mean every inherited lock holder has ended. + with (repo / ".git" / "confirmatory-anchor.lock").open("a") as lock: + deadline = time.monotonic() + 15.0 + while True: + try: + fcntl.flock(lock.fileno(), fcntl.LOCK_EX | fcntl.LOCK_NB) + break + except BlockingIOError: + assert time.monotonic() < deadline, "a Git child did not finish" + threading.Event().wait(0.01) + after = records() + assert after[0] == after[2] == after[3] == older + assert after[4] in (first, older) + for snapshot in snapshots: + anchors.write_bytes(snapshot) + out = anchor_command(repo, anchors) + assert out.returncode == 0, out.stderr + state = records() + assert state[0] == state[2] == state[3] == state[4] == snapshot + history = subprocess.run( + ["git", "-C", str(remote), "rev-list", "--reverse", "HEAD"], + check=True, + capture_output=True, + text=True, + ).stdout.splitlines() + previous = b"" + for commit in history: + content = subprocess.run( + ["git", "-C", str(remote), "show", f"{commit}:anchors.jsonl"], + check=True, + capture_output=True, + ).stdout + assert content.startswith(previous) + previous = content + assert previous == snapshots[-1] + finally: + if child is not None: + try: + os.killpg(child.pid, signal.SIGKILL) + except ProcessLookupError: + pass + child.communicate(timeout=15.0) + for fd in (ready_fd, release_fd): + os.close(fd) + + +@pytest.mark.parametrize("command", ["add", "status"]) +def test_killing_only_the_helper_during_add_or_status_keeps_the_clone_locked( + clone, tmp_path, command +): + """A clean filter pins each real Git command across helper-only death.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + first = b'{"time": 1.0}\n' + older = first + b'{"time": 2.0}\n' + snapshots = [older + b'{"time": 3.0}\n', older + b'{"time": 3.0}\n{"time": 4.0}\n'] + anchors.write_bytes(first) + assert anchor_command(repo, anchors).returncode == 0 + ready, release = tmp_path / "ready", tmp_path / "release" + for path in (ready, release): + os.mkfifo(path) + invocation = tmp_path / "filter-invocation" + filter_lock = tmp_path / "filter-lock.json" + clean = tmp_path / "clean-filter" + block_at = 1 if command == "add" else 2 + clean.write_text( + f"#!{sys.executable}\n" + "import json, os, sys\n" + "from pathlib import Path\n" + "content = sys.stdin.buffer.read()\n" + "if os.environ.get('ANCHOR_TEST_BLOCK') == '1':\n" + f" invocation = Path({str(invocation)!r})\n" + " count = int(invocation.read_text()) + 1 if invocation.exists() else 1\n" + " invocation.write_text(str(count))\n" + f" if count == {block_at}:\n" + f" lock = Path({str(repo / '.git' / 'confirmatory-anchor.lock')!r})" + ".stat()\n" + " inherited = []\n" + " for fd in range(3, 256):\n" + " try:\n" + " info = os.fstat(fd)\n" + " except OSError:\n" + " continue\n" + " if (info.st_dev, info.st_ino) == (lock.st_dev, lock.st_ino):\n" + " inherited.append(os.get_inheritable(fd))\n" + f" Path({str(filter_lock)!r}).write_text(json.dumps(inherited))\n" + f" with open({str(ready)!r}, 'wb', buffering=0) as pipe:\n" + " pipe.write(b'1')\n" + f" with open({str(release)!r}, 'rb', buffering=0) as pipe:\n" + " pipe.read(1)\n" + f" elif count == 1 and {command == 'status'!r}:\n" + f" target = Path({str(repo / 'anchors.jsonl')!r})\n" + " info = target.stat()\n" + " os.utime(target, ns=(info.st_atime_ns, " + "info.st_mtime_ns - 2000000000))\n" + "sys.stdout.buffer.write(content)\n" + ) + clean.chmod(0o755) + (repo / ".git" / "info" / "attributes").write_text("anchors.jsonl filter=anchor\n") + for name, value in (("clean", str(clean)), ("required", "true")): + subprocess.run( + ["git", "-C", str(repo), "config", f"filter.anchor.{name}", value], + check=True, + ) + + def records(): + """Read file, raw index, staged and committed bytes and remote history.""" + objects = [ + subprocess.run( + ["git", "-C", str(repo), "show", obj], check=True, capture_output=True + ).stdout + for obj in (":anchors.jsonl", "HEAD:anchors.jsonl") + ] + return ( + (repo / "anchors.jsonl").read_bytes(), + (repo / ".git" / "index").read_bytes(), + *objects, + remote_file(remote).encode(), + remote_log(remote), + ) + + ready_fd, release_fd = (os.open(path, os.O_RDWR) for path in (ready, release)) + child = None + try: + anchors.write_bytes(older) + child = subprocess.Popen( + [sys.executable, str(SCRIPT), "--repo", str(repo), str(anchors)], + env={**os.environ, "ANCHOR_TEST_BLOCK": "1"}, + start_new_session=True, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + ) + assert select.select([ready_fd], [], [], 15.0)[0], ( + f"Git {command} did not reach its clean filter" + ) + assert os.read(ready_fd, 1) == b"1" + # The first conversion runs in add; changing its stat forces status's second. + assert invocation.read_text() == str(block_at) + before = records() + assert before[0] == older + assert before[2] == (first if command == "add" else older) + assert before[3] == before[4] == first + child.kill() + assert child.wait(timeout=15.0) == -signal.SIGKILL + for snapshot in snapshots: + anchors.write_bytes(snapshot) + out = anchor_command(repo, anchors) + assert out.returncode == 1 and "busy" in out.stderr, ( + f"a surviving Git {command} lost the helper's clone lock: " + out.stderr + ) + assert records() == before + assert json.loads(filter_lock.read_text()) == [True] + os.write(release_fd, b"1") + child.communicate(timeout=15.0) + with (repo / ".git" / "confirmatory-anchor.lock").open("a") as lock: + deadline = time.monotonic() + 15.0 + while True: + try: + fcntl.flock(lock.fileno(), fcntl.LOCK_EX | fcntl.LOCK_NB) + break + except BlockingIOError: + assert time.monotonic() < deadline, f"Git {command} did not finish" + threading.Event().wait(0.01) + after = records() + assert after[0] == after[2] == older + assert after[3] == after[4] == first + for snapshot in snapshots: + anchors.write_bytes(snapshot) + out = anchor_command(repo, anchors) + assert out.returncode == 0, out.stderr + state = records() + assert state[0] == state[2] == state[3] == state[4] == snapshot + history = subprocess.run( + ["git", "-C", str(remote), "rev-list", "--reverse", "HEAD"], + check=True, + capture_output=True, + text=True, + ).stdout.splitlines() + previous = b"" + for commit in history: + content = subprocess.run( + ["git", "-C", str(remote), "show", f"{commit}:anchors.jsonl"], + check=True, + capture_output=True, + ).stdout + assert content.startswith(previous) + previous = content + assert previous == snapshots[-1] + finally: + if child is not None: + try: + os.killpg(child.pid, signal.SIGKILL) + except ProcessLookupError: + pass + child.communicate(timeout=15.0) + for fd in (ready_fd, release_fd): + os.close(fd) + + +def test_a_detached_hook_descendant_keeps_the_clone_locked(clone, tmp_path): + """A double-forked holder outlives its hook and helper until explicitly released.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + first = b'{"time": 1.0}\n' + older = first + b'{"time": 2.0}\n' + snapshots = [older + b'{"time": 3.0}\n', older + b'{"time": 3.0}\n{"time": 4.0}\n'] + anchors.write_bytes(first) + assert anchor_command(repo, anchors).returncode == 0 + ready, release = tmp_path / "ready", tmp_path / "release" + for path in (ready, release): + os.mkfifo(path) + holder = tmp_path / "detached-holder.json" + hook = repo / ".git" / "hooks" / "pre-push" + hook.write_text( + f"#!{sys.executable}\n" + "import json, os\n" + "from pathlib import Path\n" + "if os.environ.get('ANCHOR_TEST_DETACH') == '1':\n" + f" ready = os.open({str(ready)!r}, os.O_WRONLY)\n" + f" release = os.open({str(release)!r}, os.O_RDONLY)\n" + " hook_pid = os.getpid()\n" + " child = os.fork()\n" + " if child:\n" + " os.waitpid(child, 0)\n" + " raise SystemExit(0)\n" + " os.setsid()\n" + " if os.fork():\n" + " os._exit(0)\n" + " with open(os.devnull, 'r+b', buffering=0) as null:\n" + " for fd in range(3):\n" + " os.dup2(null.fileno(), fd)\n" + f" lock = Path({str(repo / '.git' / 'confirmatory-anchor.lock')!r}).stat()\n" + " inherited = []\n" + " for fd in range(3, 256):\n" + " try:\n" + " info = os.fstat(fd)\n" + " except OSError:\n" + " continue\n" + " if (info.st_dev, info.st_ino) == (lock.st_dev, lock.st_ino):\n" + " inherited.append(os.get_inheritable(fd))\n" + " state = dict(pid=os.getpid(), sid=os.getsid(0), pgid=os.getpgrp(),\n" + " hook_pid=hook_pid, inherited=inherited)\n" + f" Path({str(holder)!r}).write_text(json.dumps(state))\n" + " os.write(ready, b'1')\n" + " os.read(release, 1)\n" + " os._exit(0)\n" + ) + hook.chmod(0o755) + + def records(): + """Read the clone's file, index, HEAD and remote without writing.""" + objects = [ + subprocess.run( + ["git", "-C", str(repo), "show", obj], check=True, capture_output=True + ).stdout + for obj in (":anchors.jsonl", "HEAD:anchors.jsonl") + ] + return ( + (repo / "anchors.jsonl").read_bytes(), + (repo / ".git" / "index").read_bytes(), + *objects, + remote_file(remote).encode(), + remote_log(remote), + ) + + ready_fd, release_fd = (os.open(path, os.O_RDWR) for path in (ready, release)) + child = None + descendant = None + try: + anchors.write_bytes(older) + child = subprocess.Popen( + [sys.executable, str(SCRIPT), "--repo", str(repo), str(anchors)], + env={**os.environ, "ANCHOR_TEST_DETACH": "1"}, + start_new_session=True, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + ) + assert select.select([ready_fd], [], [], 15.0)[0], ( + "hook did not detach its holder" + ) + assert os.read(ready_fd, 1) == b"1" + state = json.loads(holder.read_text()) + descendant = state["pid"] + stdout, stderr = child.communicate(timeout=15.0) + assert child.returncode == 0, stderr.decode() + assert stdout == b"pushed 2 anchors\n" + assert state["sid"] != child.pid and state["pgid"] != child.pid + assert descendant != state["sid"] + os.kill(descendant, 0) + with pytest.raises(ProcessLookupError): + os.kill(state["hook_pid"], 0) + before = records() + assert before[0] == before[2] == before[3] == before[4] == older + for snapshot in snapshots: + anchors.write_bytes(snapshot) + out = anchor_command(repo, anchors) + assert out.returncode == 1 and "busy" in out.stderr, ( + "a detached hook descendant lost the helper's clone lock: " + out.stderr + ) + assert records() == before + assert state["inherited"] == [True] + os.write(release_fd, b"1") + with (repo / ".git" / "confirmatory-anchor.lock").open("a") as lock: + deadline = time.monotonic() + 15.0 + while True: + try: + fcntl.flock(lock.fileno(), fcntl.LOCK_EX | fcntl.LOCK_NB) + break + except BlockingIOError: + assert time.monotonic() < deadline, ( + "the detached holder did not exit" + ) + threading.Event().wait(0.01) + descendant = None + for snapshot in snapshots: + anchors.write_bytes(snapshot) + out = anchor_command(repo, anchors) + assert out.returncode == 0, out.stderr + state = records() + assert state[0] == state[2] == state[3] == state[4] == snapshot + finally: + os.write(release_fd, b"1") + if descendant is not None: + try: + os.kill(descendant, signal.SIGKILL) + except ProcessLookupError: + pass + if child is not None: + try: + os.killpg(child.pid, signal.SIGKILL) + except ProcessLookupError: + pass + child.communicate(timeout=15.0) + for fd in (ready_fd, release_fd): + os.close(fd) + + +def test_a_changed_middle_line_is_refused_without_writing(clone, tmp_path): + """A longer snapshot still fails when it rewrites an existing line.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + first = b'{"time": 1.0}\n{"time": 2.0}\n{"time": 3.0}\n' + anchors.write_bytes(first) + assert anchor_command(repo, anchors).returncode == 0 + history, index = remote_log(remote), (repo / ".git" / "index").read_bytes() + anchors.write_bytes(first.replace(b"2.0", b"9.0") + b'{"time": 4.0}\n') + out = anchor_command(repo, anchors) + assert out.returncode != 0 and "not a byte prefix" in out.stderr + assert (repo / "anchors.jsonl").read_bytes() == first + assert (repo / ".git" / "index").read_bytes() == index + assert remote_file(remote).encode() == first + assert remote_log(remote) == history + + +def test_a_stale_git_index_lock_is_left_alone(clone, tmp_path): + """A failed git command never removes another command's index lock.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + first = b'{"time": 1.0}\n' + anchors.write_bytes(first) + assert anchor_command(repo, anchors).returncode == 0 + history = remote_log(remote) + index_lock = repo / ".git" / "index.lock" + index_lock.write_bytes(b"stale lock kept for its owner\n") + anchors.write_bytes(first + b'{"time": 2.0}\n') + out = anchor_command(repo, anchors) + assert out.returncode != 0 and "CalledProcessError" in out.stderr + assert index_lock.read_bytes() == b"stale lock kept for its owner\n" + assert remote_file(remote).encode() == first + assert remote_log(remote) == history + + +def test_normal_index_fsmonitor_startup_is_disabled(clone, tmp_path): + """The per-command override suppresses a configured index-triggered monitor.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + anchors.write_bytes(b'{"time": 1.0}\n') + assert anchor_command(repo, anchors).returncode == 0 + invoked, monitor = tmp_path / "monitor-invoked", tmp_path / "fsmonitor" + monitor.write_text( + f"#!{sys.executable}\n" + "from pathlib import Path\n" + f"Path({str(invoked)!r}).touch()\n" + ) + monitor.chmod(0o755) + subprocess.run( + ["git", "-C", str(repo), "config", "core.fsmonitor", str(monitor)], check=True + ) + anchors.write_bytes(anchors.read_bytes() + b'{"time": 2.0}\n') + out = anchor_command(repo, anchors) + assert out.returncode == 0, out.stderr + assert not invoked.exists() + assert remote_file(remote).encode() == anchors.read_bytes() + + +def test_a_failed_push_exits_nonzero(clone, tmp_path): + """The runner records the command's return code; a push that fails must + not look like one that landed.""" + remote, repo = clone + anchors = tmp_path / "anchors.jsonl" + anchors.write_text('{"time": 1.0}\n') + subprocess.run( + ["git", "-C", str(repo), "remote", "set-url", "origin", str(tmp_path / "gone")], + check=True, + ) + out = subprocess.run( + [sys.executable, str(SCRIPT), "--repo", str(repo), str(anchors)], + capture_output=True, + text=True, + ) + assert out.returncode != 0 + + +def bare_run(folder, command): + """Just the anchor writer, without the board, engines or providers.""" + run = object.__new__(cr.Run) + run.design = {"runs": str(folder), "anchor_command": command} + run.out, run._say_lock = io.StringIO(), threading.Lock() + run.lanes, run.host = {}, None + run._anchor_head = cr.chain_seed("a" * 64, "", "anchors.jsonl") + run._anchored = run._next_anchor = -math.inf + run._pushing, run._push = threading.Lock(), None + run._push_error = None + return run + + +def bare_finish_run(folder, command): + """An anchor writer with an empty, already closed run to finish.""" + + class Ledger: + def close(self, pending): + return [] + + run = bare_run(folder, command) + run.ceiling, run._failed = Ledger(), threading.Event() + run.signalled, run._interrupted = None, False + run.watch = lambda anchor=True: None + return run + + +def test_failed_pushes_retry_and_keep_every_outcome(tmp_path, monkeypatch): + """A failed remote never looks anchored; retry follows the failure's end, + then a successful push restores the ordinary cadence.""" + now, calls = [1000.0], [] + monkeypatch.setattr(cr.time, "time", lambda: now[0]) + monkeypatch.setattr(cr, "clock", lambda: now[0]) + monkeypatch.setattr(cr, "ANCHOR_SECONDS", 900.0) + monkeypatch.setattr(cr, "ANCHOR_RETRY", 60.0) + monkeypatch.setattr(cr, "ANCHOR_PUSH_TIMEOUT", 123.0) + + class Push: + def __init__(self, command, **kwargs): + calls.append((command, kwargs)) + self.returncode = 1 if len(calls) < 4 else 0 + + def communicate(self, timeout): + assert timeout == cr.ANCHOR_PUSH_TIMEOUT + now[0] += 7.0 + return "", "remote unavailable" if self.returncode else "pushed" + + monkeypatch.setattr(cr.subprocess, "Popen", Push) + run = bare_run(tmp_path, ["push-anchors"]) + assert run.anchor_due() + for i in range(4): + started = now[0] + run.anchor(wait=True) + assert not run.anchor_due() + expected = now[0] + cr.ANCHOR_RETRY if i < 3 else started + cr.ANCHOR_SECONDS + assert run._next_anchor == expected + now[0] = expected + assert run.anchor_due() + anchors = [ + json.loads(x) for x in (tmp_path / "anchors.jsonl").read_text().splitlines() + ] + pushes = [ + json.loads(x) + for x in (tmp_path / "anchor-pushes.jsonl").read_text().splitlines() + ] + assert [x["outcome"] for x in pushes] == ["failed"] * 3 + ["success"] + assert [x["returncode"] for x in pushes] == [1, 1, 1, 0] + assert [x["anchor_time"] for x in pushes] == [x["time"] for x in anchors] + assert all(x["started"] == x["anchor_time"] < x["ended"] for x in pushes) + assert all(x[1]["start_new_session"] for x in calls) + assert len({x["anchor"] for x in pushes}) == 4 + + +def test_an_anchor_command_that_cannot_start_is_recorded(tmp_path): + run = bare_run(tmp_path, [str(tmp_path / "missing-command")]) + run.anchor(wait=True) + push = json.loads((tmp_path / "anchor-pushes.jsonl").read_text()) + assert push["outcome"] == "error" and push["returncode"] is None + assert "FileNotFoundError" in push["output"] + assert run._next_anchor == push["ended"] + cr.ANCHOR_RETRY + + +@pytest.mark.parametrize("wait", [False, True]) +def test_push_log_io_failure_reaches_the_supervisor(tmp_path, monkeypatch, wait): + """A successful remote push whose outcome could not be synced is still a + runner error, both in supervision and in the final blocking anchor.""" + calls, fsync = [], os.fsync + + class Push: + returncode = 0 + + def __init__(self, *args, **kwargs): + pass + + def communicate(self, timeout): + return "pushed", "" + + def fail_push_sync(fd): + calls.append(fd) + if (tmp_path / "anchor-pushes.jsonl").exists(): + # The anchor and its copy synced; only the outcome's sync fails. + raise OSError("push-log fsync failed") + return fsync(fd) + + monkeypatch.setattr(cr.subprocess, "Popen", Push) + monkeypatch.setattr(cr.os, "fsync", fail_push_sync) + run = bare_run(tmp_path, ["push-anchors"]) + if wait: + with pytest.raises(OSError, match="anchor push outcome could not be recorded"): + run.anchor(wait=True) + else: + run.anchor() + run._push.join() + with pytest.raises(OSError, match="push-log fsync failed"): + run.anchor_due() + assert not run._push.is_alive() + assert len(calls) == 3 + + +def test_a_running_push_reads_a_snapshot_while_the_final_anchor_is_appended( + tmp_path, monkeypatch +): + """A push released after the final append still sees its own whole prefix.""" + reading, release, joining = threading.Event(), threading.Event(), threading.Event() + calls, copies, errors = [], [], [] + + class Push: + returncode = 0 + + def __init__(self, command, **kwargs): + self.source = Path(command[-1]) + calls.append(self.source) + self.first = len(calls) == 1 + + def communicate(self, timeout): + if self.first: + reading.set() + assert release.wait(15.0), "the first push was never released" + copies.append(self.source.read_bytes()) + return "pushed", "" + + monkeypatch.setattr(cr.subprocess, "Popen", Push) + run = bare_run(tmp_path, ["push-anchors"]) + run.anchor() + assert reading.wait(15.0), "the first push did not start" + first, join = run._push, run._push.join + + def joining_push(timeout=None): + joining.set() + return join(timeout=timeout) + + def final_anchor(): + try: + run.anchor(wait=True) + except BaseException as error: + errors.append(error) + + monkeypatch.setattr(first, "join", joining_push) + final = threading.Thread(target=final_anchor, daemon=True) + final.start() + try: + assert joining.wait(15.0), "the final anchor did not join the blocked push" + live = (tmp_path / "anchors.jsonl").read_bytes() + assert len(live.splitlines()) == 2 + assert calls[0] != tmp_path / "anchors.jsonl" + assert calls[0].name.endswith("push-snapshot.jsonl") + assert len(calls[0].read_bytes().splitlines()) == 1 + finally: + release.set() + final.join(timeout=15.0) + assert not final.is_alive() and not errors + live = (tmp_path / "anchors.jsonl").read_bytes() + assert len(copies) == 2 and copies[-1] == live + assert all(copy.endswith(b"\n") and live.startswith(copy) for copy in copies) + assert len(set(calls)) == 2 + + +def test_push_times_use_the_ordered_clock_after_a_wall_clock_step_back( + tmp_path, monkeypatch +): + """The anchor, its cadence and its push never precede that anchor's time.""" + base = time.time() + 1000.0 + readings = iter([base, base - 0.0001]) + monkeypatch.setattr(cr, "_clock_last", 0.0) + monkeypatch.setattr(cr.time, "time", lambda: next(readings, base - 0.0001)) + + class Push: + returncode = 0 + + def __init__(self, *args, **kwargs): + pass + + def communicate(self, timeout): + return "pushed", "" + + monkeypatch.setattr(cr.subprocess, "Popen", Push) + run = bare_run(tmp_path, ["push-anchors"]) + run.anchor(wait=True) + anchor = json.loads((tmp_path / "anchors.jsonl").read_text()) + push = json.loads((tmp_path / "anchor-pushes.jsonl").read_text()) + assert anchor["time"] <= run._anchored <= push["started"] <= push["ended"] + assert push["anchor_time"] == anchor["time"] + + +def test_a_push_timeout_kills_its_children_and_grandchildren(tmp_path, monkeypatch): + """All descendants inherit the captured pipe: reaping the command cannot + finish until they close it. The timeout starts after both have launched.""" + script = tmp_path / "push.py" + script.write_text( + "import os, subprocess, sys, threading\n" + "from pathlib import Path\n" + "folder, level = Path(sys.argv[1]), int(sys.argv[2])\n" + "(folder / f'pid-{level}').write_text(str(os.getpid()))\n" + "if level < 2:\n" + " child = subprocess.Popen(\n" + " [sys.executable, __file__, str(folder), str(level + 1)])\n" + "threading.Event().wait()\n" + ) + run = bare_run(tmp_path, [sys.executable, str(script), str(tmp_path), "0"]) + real_popen, real_killpg = subprocess.Popen, os.killpg + children, kills, errors = [], [], [] + done = threading.Event() + + def popen(*args, **kwargs): + child = real_popen(*args, **kwargs) + children.append(child) + communicate = child.communicate + + def ready_communicate(timeout=None): + if timeout is not None: + deadline = time.monotonic() + 30.0 + ready = tmp_path / "pid-2" + while not ready.exists() or not ready.read_text().strip(): + assert time.monotonic() < deadline, "the descendants did not start" + done.wait(0.01) + return communicate(timeout=timeout) + + child.communicate = ready_communicate + return child + + def killpg(pid, signum): + kills.append((pid, signum)) + return real_killpg(pid, signum) + + def push(): + try: + run.anchor(wait=True) + except BaseException as error: + errors.append(error) + finally: + done.set() + + with monkeypatch.context() as patch: + patch.setattr(cr.subprocess, "Popen", popen) + patch.setattr(cr.os, "killpg", killpg) + patch.setattr(cr, "ANCHOR_PUSH_TIMEOUT", 0.05) + thread = threading.Thread(target=push, daemon=True) + thread.start() + finished = done.wait(45.0) + if not finished: + for child in children: + try: + real_killpg(child.pid, signal.SIGKILL) + except ProcessLookupError: + pass + thread.join(timeout=5.0) + assert finished, "the timed-out command left descendants holding its pipes" + assert not errors + assert len(children) == 1 and kills == [(children[0].pid, signal.SIGKILL)] + push = json.loads((tmp_path / "anchor-pushes.jsonl").read_text()) + assert push["outcome"] == "timeout" and push["returncode"] == -signal.SIGKILL + assert push["started"] <= push["ended"] + for level in (1, 2): + assert int((tmp_path / f"pid-{level}").read_text()) > 0 + + +def test_finish_abandons_pipes_held_by_a_descendant_outside_the_push_group( + tmp_path, monkeypatch +): + """An escaped grandchild cannot hold finish open after the kill's grace.""" + script = tmp_path / "escaped-push.py" + script.write_text( + "import os, subprocess, sys, threading\n" + "from pathlib import Path\n" + "folder = Path(sys.argv[1])\n" + "if len(sys.argv) > 2 and sys.argv[2] == 'escaped':\n" + " (folder / 'escaped-pid').write_text(str(os.getpid()))\n" + "else:\n" + " subprocess.Popen(\n" + " [sys.executable, __file__, str(folder), 'escaped'],\n" + " start_new_session=True)\n" + "threading.Event().wait()\n" + ) + run = bare_finish_run(tmp_path, [sys.executable, str(script), str(tmp_path)]) + real_popen = subprocess.Popen + ready, done = threading.Event(), threading.Event() + children, errors = [], [] + + def popen(*args, **kwargs): + child = real_popen(*args, **kwargs) + children.append(child) + communicate = child.communicate + + def ready_communicate(timeout=None): + if not ready.is_set(): + deadline = time.monotonic() + 15.0 + pid = tmp_path / "escaped-pid" + while not pid.exists() or not pid.read_text().strip(): + assert time.monotonic() < deadline, "the grandchild did not start" + done.wait(0.01) + ready.set() + return communicate(timeout=timeout) + + child.communicate = ready_communicate + return child + + def finish(): + try: + run.finish() + except BaseException as error: + errors.append(error) + finally: + done.set() + + monkeypatch.setattr(cr.subprocess, "Popen", popen) + monkeypatch.setattr(cr.signal, "signal", lambda *args: None) + monkeypatch.setattr(cr, "ANCHOR_PUSH_TIMEOUT", 0.05) + monkeypatch.setattr(cr, "KILL_GRACE", 0.05) + monkeypatch.setattr(cr, "FINAL_PUSH_TRIES", 1) + thread = threading.Thread(target=finish, daemon=True) + thread.start() + try: + assert ready.wait(15.0), "the push never launched its grandchild" + started = time.monotonic() + finished = done.wait(10.0) + elapsed = time.monotonic() - started + finally: + pid = tmp_path / "escaped-pid" + if pid.exists() and pid.read_text().strip(): + try: + os.kill(int(pid.read_text()), signal.SIGKILL) + except ProcessLookupError: + pass + for child in children: + if child.poll() is None: + try: + os.killpg(child.pid, signal.SIGKILL) + except ProcessLookupError: + pass + thread.join(timeout=15.0) + assert finished and elapsed < 10.0, "finish waited for the escaped child's pipe" + assert not errors and not thread.is_alive() + rows = [ + json.loads(line) + for line in (tmp_path / "anchor-pushes.jsonl").read_text().splitlines() + ] + assert len(rows) == 1 and rows[0]["outcome"] == "timeout" + assert "pipes" in rows[0]["output"] and "held open after the kill" in rows[0]["output"] + + +def test_finish_records_a_stuck_push_once_even_if_its_thread_later_ends( + tmp_path, monkeypatch +): + """A bounded join retires the worker's right to append a second outcome.""" + started, release = threading.Event(), threading.Event() + calls, waits, copies = [], [], {} + + class Push: + returncode = 0 + + def __init__(self, command, **kwargs): + calls.append(command) + self.first = len(calls) == 1 + self.source = Path(command[-1]) + self.returncode = 1 if self.first else 0 + + def communicate(self, timeout): + if self.first: + started.set() + assert release.wait(15.0), "the abandoned worker was never released" + copies[self.source] = self.source.read_bytes() + return "pushed", "" + + monkeypatch.setattr(cr.subprocess, "Popen", Push) + monkeypatch.setattr(cr.signal, "signal", lambda *args: None) + monkeypatch.setattr(cr, "ANCHOR_PUSH_TIMEOUT", 0.05) + monkeypatch.setattr(cr, "KILL_GRACE", 0.05) + run = bare_finish_run(tmp_path, ["push-anchors"]) + run.anchor() + assert started.wait(15.0), "the periodic push did not start" + worker, join = run._push, run._push.join + + def short_join(timeout=None): + waits.append(timeout) + return join(timeout=0.02) + + monkeypatch.setattr(worker, "join", short_join) + try: + began = time.monotonic() + run.finish() + assert time.monotonic() - began < 10.0 + path = tmp_path / "anchor-pushes.jsonl" + before = path.read_bytes() + rows = [json.loads(line) for line in before.splitlines()] + assert waits == [pytest.approx(cr.ANCHOR_PUSH_TIMEOUT + cr.KILL_GRACE + 30)] + assert len(rows) == 2 + assert rows[0]["outcome"] == "error" and rows[0]["returncode"] is None + assert "push thread did not end" in rows[0]["output"] + assert "command may still be running" in rows[0]["output"] + assert rows[1]["outcome"] == "success" + next_anchor = run._next_anchor + finally: + release.set() + join(timeout=15.0) + assert not worker.is_alive() + assert path.read_bytes() == before + assert len({row["anchor"] for row in rows}) == len(rows) + assert run._last_push_outcome == "success" and run._next_anchor == next_anchor + live = (tmp_path / "anchors.jsonl").read_bytes() + assert len(copies[Path(calls[0][-1])].splitlines()) == 1 + assert len(copies[Path(calls[1][-1])].splitlines()) == 2 + assert all(copy.endswith(b"\n") and live.startswith(copy) for copy in copies.values()) + + +def test_a_retired_command_cannot_shrink_the_remote_after_the_final_push( + clone, tmp_path, monkeypatch +): + """A live old command released after finish cannot replace newer evidence.""" + remote, repo = clone + folder = tmp_path / "run" + folder.mkdir() + delayed = tmp_path / "delayed-helper.py" + delayed.write_text( + "import os, sys\n" + "ready, release = map(int, sys.argv[1:3])\n" + "os.write(ready, b'1')\n" + "os.close(ready)\n" + "os.read(release, 1)\n" + "os.close(release)\n" + "os.execv(sys.executable, [sys.executable, *sys.argv[3:]])\n" + ) + ready_read, ready_write = os.pipe() + release_read, release_write = os.pipe() + real_popen, children, waits = subprocess.Popen, [], [] + run = bare_finish_run( + folder, [sys.executable, str(SCRIPT), "--repo", str(repo)] + ) + + def popen(command, **kwargs): + """Delay only the first real helper, before it can acquire the clone lock.""" + if len(command) > 1 and command[1] == str(SCRIPT): + if not children: + command = [ + sys.executable, + str(delayed), + str(ready_write), + str(release_read), + *command[1:], + ] + kwargs["pass_fds"] = (ready_write, release_read) + child = real_popen(command, **kwargs) + children.append(child) + return child + return real_popen(command, **kwargs) + + def short_join(timeout=None): + """Exercise retirement without waiting for the production join bound.""" + waits.append(timeout) + return join(timeout=0.02) + + monkeypatch.setattr(cr.subprocess, "Popen", popen) + monkeypatch.setattr(cr.signal, "signal", lambda *args: None) + monkeypatch.setattr(cr, "ANCHOR_PUSH_TIMEOUT", 30.0) + worker = join = None + try: + run.anchor() + worker, join = run._push, run._push.join + assert select.select([ready_read], [], [], 15.0)[0], ( + "the old command did not start" + ) + assert os.read(ready_read, 1) == b"1" + monkeypatch.setattr(worker, "join", short_join) + run.finish() + assert children[0].poll() is None + newer = (folder / "anchors.jsonl").read_bytes() + assert len(newer.splitlines()) == 2 + assert remote_file(remote).encode() == newer + history = remote_log(remote) + path = folder / "anchor-pushes.jsonl" + before = path.read_bytes() + rows = [json.loads(line) for line in before.splitlines()] + assert waits == [pytest.approx(cr.ANCHOR_PUSH_TIMEOUT + cr.KILL_GRACE + 30)] + assert [row["outcome"] for row in rows] == ["error", "success"] + assert rows[0]["returncode"] is None + assert "command may still be running" in rows[0]["output"] + finally: + try: + os.write(release_write, b"1") + except BrokenPipeError: + pass + if join is not None: + join(timeout=45.0) + for child in children: + if child.poll() is None: + try: + os.killpg(child.pid, signal.SIGKILL) + except ProcessLookupError: + pass + for fd in (ready_read, ready_write, release_read, release_write): + os.close(fd) + assert not worker.is_alive() and len(children) == 2 + assert children[0].returncode == 1 + assert path.read_bytes() == before + assert remote_file(remote).encode() == newer + assert remote_log(remote) == history diff --git a/tests/test_confirmatory_no_tools.py b/tests/test_confirmatory_no_tools.py new file mode 100644 index 00000000..7c77f876 --- /dev/null +++ b/tests/test_confirmatory_no_tools.py @@ -0,0 +1,641 @@ +"""Provider-free tests of the no-tools stage's files, retries and shared spend.""" + +from __future__ import annotations + +import ast +import io +import json +import os +import signal +import sys +import threading +from pathlib import Path +from types import SimpleNamespace + +import pytest + +sys.path.insert(0, str(Path(__file__).resolve().parents[1] / "scripts")) + +import confirmatory_no_tools as nt # noqa: E402 + + +@pytest.fixture +def setup(tmp_path): + draw = ["h2", "h1"] + baseline = tmp_path / "baseline-exclusions.json" + baseline.write_text("[]\n") + return { + "design": { + "board": "synthetic.csv", + "engine": "policyengine-us 2.60.4", + "draw_order": draw, + "baseline_exclusions": { + "path": str(baseline), + "sha256": nt.sha256_file(baseline), + }, + "no_tools": { + "runs": str(tmp_path / "no-tools"), + "folder": "none", + "stage": "confirmatory", + }, + }, + "board": { + "scenarios": {sid: SimpleNamespace(id=sid) for sid in draw}, + "variables": {sid: ["snap"] for sid in draw}, + }, + } + + +def record(sid, profile, status="complete", error=None, cost=0.1): + return { + "scenario_id": sid, + "model": profile.name, + "arm": profile.arm, + "status": status, + "error": error, + "turns": [] if status == "harness_error" else [{"model": profile.model_id}], + "predictions": {"snap": 1}, + "totals": {"cost_usd": cost}, + } + + +class Provider: + def __init__(self, planted=None): + self.planted, self.calls = planted or {}, [] + self.lock = threading.Lock() + + def __call__( + self, scenario, variables, tool_call, completion_fn, spend, *, profile + ): + key = profile.name, scenario.id + with self.lock: + n = 1 + sum(call[:2] == key for call in self.calls) + self.calls.append((*key, n)) + spec = self.planted.get((*key, n), {}) + cost = spec.get("cost", 0.1) + spend.add(cost) + if spec.get("raise"): + raise RuntimeError("synthetic harness failure") + return record( + scenario.id, + profile, + cost=cost, + status=spec.get("status", "complete"), + error=spec.get("error"), + ) + + +def stage(setup, provider=None, models=None, **kwargs): + return nt.Stage( + setup["design"], + models=models, + board=setup["board"], + run_household=provider or Provider(), + completion_for=lambda profile: None, + out=io.StringIO(), + **kwargs, + ) + + +def final(plan, model=nt.CHEAP[0], sid="h2"): + return plan.households(model) / f"{sid}.json" + + +def load(path): + return json.loads(path.read_text()) + + +def plant(setup, status, error, n=1, **extra): + return {(nt.CHEAP[0], "h2", n): {"status": status, "error": error, **extra}} + + +def test_every_household_ok_in_draw_order_and_each_model_has_its_thread(setup): + provider, threads = Provider(), {} + + def fake(*args, **kwargs): + threads.setdefault(kwargs["profile"].name, threading.current_thread().name) + return provider(*args, **kwargs) + + plan = stage(setup, fake) + assert plan.execute() == 0 + assert all(plan.states[m] == "complete" for m in nt.CHEAP) + assert len(set(threads.values())) == len(nt.CHEAP) + for model in nt.CHEAP: + assert [call[1] for call in provider.calls if call[0] == model] == ["h2", "h1"] + for sid in setup["design"]["draw_order"]: + assert load(final(plan, model, sid))["attempts"] == [] + assert plan.spend.spent_usd == pytest.approx(0.6) + + +def test_provider_rerun_links_the_unchanged_archived_bytes(setup): + provider = Provider(plant(setup, "provider_error", "APIConnectionError: synthetic")) + plan = stage(setup, provider, models=[nt.CHEAP[0]]) + written = {} + original = nt.write_json + + def capture(path, payload, *args, **kwargs): + result = original(path, payload, *args, **kwargs) + written.setdefault(path.name, path.read_bytes()) + return result + + with pytest.MonkeyPatch.context() as patch: + patch.setattr(nt, "write_json", capture) + assert plan.execute() == 0 + path = final(plan) + archive = path.parent / "attempts/h2-1.json" + assert archive.read_bytes() == written["h2.json"] + assert load(path)["attempts"] == [ + { + "n": 1, + "file": "attempts/h2-1.json", + "sha256": nt.sha256_file(archive), + "status": "provider_error", + "class": "provider", + "reason": "APIConnectionError", + } + ] + assert stage(setup, models=[nt.CHEAP[0]]).spend.spent_usd == pytest.approx(0.3) + + +def test_third_provider_failure_stands_and_has_only_two_archives(setup): + planted = { + **plant(setup, "provider_error", "APIConnectionError", 1), + **plant(setup, "provider_error", "APIConnectionError", 2), + **plant(setup, "provider_error", "APIConnectionError", 3), + } + provider = Provider(planted) + plan = stage(setup, provider, models=[nt.CHEAP[0]]) + assert plan.execute() == 0 + assert [n for m, sid, n in provider.calls if sid == "h2"] == [1, 2, 3] + assert len(load(final(plan))["attempts"]) == nt.MAX_RERUNS + assert load(final(plan))["status"] == "provider_error" + + +def test_operator_pause_stops_its_model_and_reinvocation_resumes(setup): + provider = Provider( + plant(setup, "provider_error", "AuthenticationError: synthetic") + ) + first = stage(setup, provider) + assert first.execute() == 1 + assert first.states[nt.CHEAP[0]] == "operator-paused" + assert not final(first, sid="h1").exists() + assert first.states[nt.CHEAP[1]] == "complete" + before = final(first).read_bytes() + resumed = stage(setup, models=[nt.CHEAP[0]]) + assert resumed.execute() == 0 + assert (final(resumed).parent / "attempts/h2-1.json").read_bytes() == before + assert load(final(resumed))["attempts"][0]["class"] == "operator" + + +def test_harness_stop_prevents_later_households_and_persists(setup): + provider = Provider(plant(setup, "provider_error", "BadRequestError: synthetic")) + + # A request error is a harness class only before a completed turn. + def early_failure(*args, **kwargs): + result = provider(*args, **kwargs) + if result["status"] == "provider_error": + result["turns"] = [] + return result + + plan = stage(setup, early_failure, models=[nt.CHEAP[0]]) + assert plan.execute() == 1 + assert plan.states[nt.CHEAP[0]] == "harness-stopped" + assert not final(plan, sid="h1").exists() + resumed_provider = Provider() + resumed = stage(setup, resumed_provider, models=[nt.CHEAP[0]]) + assert resumed.execute() == 1 + assert resumed_provider.calls == [] + + +def paused(setup): + plan = stage( + setup, + Provider(plant(setup, "provider_error", "AuthenticationError")), + models=[nt.CHEAP[0]], + ) + assert plan.execute() == 1 + return plan + + +def test_crash_after_archive_resumes_at_the_next_attempt_number(setup, monkeypatch): + first = paused(setup) + original = nt.os.replace + + def interrupted(source, target): + original(source, target) + if Path(target).parent.name == "attempts": + raise RuntimeError("synthetic crash after archive") + + monkeypatch.setattr(nt.os, "replace", interrupted) + with pytest.raises(RuntimeError, match="synthetic crash"): + first.archive(nt.CHEAP[0], "h2") + monkeypatch.setattr(nt.os, "replace", original) + assert not final(first).exists() + resumed = stage(setup, models=[nt.CHEAP[0]]) + assert resumed.execute() == 0 + assert load(final(resumed))["attempts"][0]["n"] == 1 + assert " h2 2 ok stands " in resumed.out.getvalue() + + +def test_spend_in_archives_and_optional_models_carries_across_invocations(setup): + first = paused(setup) + first.archive(nt.CHEAP[0], "h2") + optional = stage(setup, models=["gpt-6-sol"]) + assert optional.execute() == 0 + resumed = stage(setup, models=[nt.CHEAP[0]]) + assert resumed.spend.spent_usd == pytest.approx(0.3) + assert resumed.execute() == 0 + assert resumed.spend.spent_usd == pytest.approx(0.5) + + +def test_reaching_the_cap_prevents_every_new_attempt_across_invocations( + setup, monkeypatch +): + monkeypatch.setattr(nt, "NO_TOOLS_CAP", 0.1) + plan = stage(setup, models=[nt.CHEAP[0]]) + assert plan.execute() == 1 + assert len(list(plan.households(nt.CHEAP[0]).glob("*.json"))) == 1 + provider = Provider() + resumed = stage(setup, provider, models=[nt.CHEAP[1]]) + assert resumed.execute() == 1 + assert provider.calls == [] + assert resumed.spend.spent_usd == pytest.approx(0.1) + + +def test_budget_stop_is_shared_by_all_models(setup): + provider = Provider(plant(setup, "budget_stop", None)) + plan = stage(setup, provider, models=[nt.CHEAP[0]]) + assert plan.execute() == 1 + assert plan.stopped.is_set() + resumed = stage(setup, Provider(), models=[nt.CHEAP[1]]) + assert resumed.execute() == 1 + assert resumed.states[nt.CHEAP[1]] == "budget-stopped" + + +@pytest.mark.parametrize( + "mutation,match", + [ + (lambda r: r.update(prior_attempts=[]), "prior_attempts"), + (lambda r: r.pop("attempts"), "attempts list"), + ], +) +def test_refuse_a_final_not_written_by_this_script(setup, mutation, match): + first = paused(setup) + path = final(first) + payload = load(path) + mutation(payload) + path.write_text(json.dumps(payload)) + with pytest.raises(nt.StateError, match=match): + stage(setup) + + +def test_refuse_an_attempt_number_gap_and_name_its_files(setup): + first = paused(setup) + first.archive(nt.CHEAP[0], "h2") + archive = final(first).parent / "attempts/h2-1.json" + archive.rename(archive.with_name("h2-2.json")) + with pytest.raises(nt.StateError, match="attempt-number gap.*h2-2.json"): + stage(setup) + + +@pytest.mark.parametrize( + "field,value", [("sha256", "wrong"), ("n", 2), ("reason", "edited")] +) +def test_refuse_a_final_with_corrupted_attempt_links(setup, field, value): + paused(setup) + resumed = stage(setup, models=[nt.CHEAP[0]]) + assert resumed.execute() == 0 + path = final(resumed) + payload = load(path) + payload["attempts"][0][field] = value + path.write_text(json.dumps(payload)) + with pytest.raises(nt.StateError, match="attempts disagree"): + stage(setup) + + +def test_an_attempt_that_raises_keeps_its_spend(setup): + provider = Provider(plant(setup, "complete", None, **{"raise": True, "cost": 0.27})) + plan = stage(setup, provider, models=[nt.CHEAP[0]]) + assert plan.execute() == 0 + archive = final(plan).parent / "attempts/h2-1.json" + assert load(archive)["status"] == "harness_error" + assert load(archive)["totals"]["cost_usd"] == 0.27 + assert plan.spend.spent_usd == pytest.approx(0.47) + assert stage(setup, models=[nt.CHEAP[0]]).spend.spent_usd == pytest.approx(0.47) + + +def test_dry_run_lists_done_households_and_next_owed_attempt_without_providers(setup): + first = paused(setup) + first.archive(nt.CHEAP[0], "h2") + provider = Provider() + plan = stage(setup, provider, models=[nt.CHEAP[0]]) + assert plan.dry_run() == 1 + text = plan.out.getvalue() + assert "done []" in text and "h2:2" in text and "h1:1" in text + assert "$0.100000" in text + assert provider.calls == [] + + +def test_each_attempt_uses_none_profile_and_refuses_a_tool_call(setup): + def fake(scenario, variables, tool_call, completion, spend, *, profile): + assert profile.arm == "none" and profile.prompt_version == nt.PROMPT_VERSION + assert variables == ["snap"] + with pytest.raises(RuntimeError, match="cannot call a tool"): + tool_call({}) + return record(scenario.id, profile, cost=0) + + assert stage(setup, fake, models=[nt.CHEAP[0]]).execute() == 0 + + +def test_registered_cap_matches_the_report_when_available(): + """The local report is separate from this public repository's dependency tree.""" + configured = os.environ.get("CONFIRMATORY_REPORT") + candidates = ( + [Path(configured)] + if configured + else [Path(__file__).resolve().parents[2] / "report" / "confirmatory_report.py"] + ) + path = next((p for p in candidates if p.is_file()), None) + if path is None: + pytest.skip("set CONFIRMATORY_REPORT to compare the separate report checkout") + tree = ast.parse(path.read_text()) + cap = next( + ast.literal_eval(node.value) + for node in tree.body + if isinstance(node, ast.Assign) + and any( + isinstance(target, ast.Name) and target.id == "NO_TOOLS_CAP" + for target in node.targets + ) + ) + assert nt.NO_TOOLS_CAP == cap == 5.0 + + +def test_main_supports_multiple_model_options_and_dry_run( + setup, tmp_path, monkeypatch, capsys +): + path = tmp_path / "design.json" + path.write_text(json.dumps(setup["design"])) + monkeypatch.setattr(nt.pilot, "board_engine", lambda path: "2.60.4") + monkeypatch.setattr(nt.pilot, "_require_engine", lambda path: None) + monkeypatch.setattr(nt.pilot, "load_board", lambda path: setup["board"]) + assert ( + nt.main( + [ + "run", + str(path), + "--model", + nt.CHEAP[0], + nt.CHEAP[1], + "--model", + nt.CHEAP[2], + "--dry-run", + ] + ) + == 1 + ) + output = capsys.readouterr().out + assert all(model in output for model in nt.CHEAP) + + +def test_in_flight_models_observe_the_shared_cap_before_their_next_turn( + setup, monkeypatch +): + monkeypatch.setattr(nt, "NO_TOOLS_CAP", 0.1) + ready, charged = threading.Barrier(3), threading.Barrier(3) + calls = [] + + def fake(scenario, variables, tool_call, completion, spend, *, profile): + calls.append((profile.name, scenario.id)) + ready.wait(timeout=30) + cost = 0.1 if profile.name == nt.CHEAP[0] else 0.0 + spend.add(cost) + charged.wait(timeout=30) + assert spend.exhausted() + return record(scenario.id, profile, cost=cost) + + plan = stage(setup, fake) + assert plan.execute() == 1 + assert len(calls) == 3 and all(sid == "h2" for _, sid in calls) + assert plan.spend.spent_usd == pytest.approx(0.1) + + +@pytest.mark.parametrize( + "status,error,expected", + [ + ("budget_stop", None, "stopped"), + ("provider_error", "BadRequestError: synthetic", "stop"), + ], +) +def test_dry_run_marks_harness_and_budget_finals_as_blocked( + setup, status, error, expected +): + plan = stage(setup, models=[nt.CHEAP[0]]) + profile = nt.pilot.model_profile( + nt.CHEAP[0], arm="none", prompt_version=nt.PROMPT_VERSION + ) + payload = record("h2", profile, status=status, error=error, cost=0) + payload["turns"] = [] + payload["attempts"] = [] + nt.write_json(final(plan), payload) + if hasattr(plan, "close"): + plan.close() + resumed = stage(setup, models=[nt.CHEAP[0]]) + assert resumed.dry_run() == 1 + assert f"h2:blocked {expected} at attempt 1" in resumed.out.getvalue() + + +def test_sigint_finishes_saves_and_stops_before_the_next_household(setup): + calls = [] + saved_handlers = { + sig: signal.getsignal(sig) for sig in (signal.SIGINT, signal.SIGTERM) + } + continued = threading.Event() + + def interrupted(scenario, variables, tool_call, completion, spend, *, profile): + calls.append(scenario.id) + spend.add(0.17) + if scenario.id == "h2": + os.kill(os.getpid(), signal.SIGINT) + continued.wait(0.05) + return record(scenario.id, profile, cost=0.17) + + plan = stage(setup, interrupted, models=[nt.CHEAP[0]]) + try: + result = plan.execute() + except KeyboardInterrupt: + # Let the old implementation's uncoordinated worker finish before the + # regression assertion, so a red run leaves no worker behind. + continued.set() + for worker in threading.enumerate(): + if worker.name.startswith("no-tools-"): + worker.join(timeout=30) + result = 0 + assert result != 0, "SIGINT must give a coordinated nonzero exit" + assert calls == ["h2"] + assert load(final(plan))["totals"]["cost_usd"] == 0.17 + assert plan.states[nt.CHEAP[0]] == "interrupted" + assert not plan.stopped.is_set(), "interrupts must preserve the budget event" + assert not final(plan, sid="h1").exists() + assert all( + signal.getsignal(sig) == handler for sig, handler in saved_handlers.items() + ) + assert "finish and save" in plan.out.getvalue() + + +def test_stage_lock_refuses_a_second_invocation_and_releases_after_dry_run(setup): + first = stage(setup, models=[nt.CHEAP[0]]) + with pytest.raises(nt.StateError, match="another no-tools invocation"): + stage(setup, models=[nt.CHEAP[1]]) + assert first.dry_run() == 1 + second = stage(setup, models=[nt.CHEAP[1]]) + assert second.dry_run() == 1 + + +@pytest.mark.parametrize("fault", ["missing", "hash"]) +def test_baseline_exclusions_must_exist_and_hash_before_startup(setup, fault): + spec = setup["design"]["baseline_exclusions"] + if fault == "missing": + Path(spec["path"]).unlink() + else: + spec["sha256"] = "0" * 64 + with pytest.raises(nt.StateError, match="baseline exclusions"): + stage(setup) + + +def test_archive_identity_and_rerun_eligibility_are_checked_directly(setup): + first = paused(setup) + first.archive(nt.CHEAP[0], "h2") + path = final(first).parent / "attempts/h2-1.json" + payload = load(path) + payload["scenario_id"] = "h1" + path.write_text(json.dumps(payload)) + with pytest.raises(nt.StateError, match="household differs from archive name h2"): + stage(setup) + payload.update(scenario_id="h2", status="complete", error=None) + path.write_text(json.dumps(payload)) + with pytest.raises(nt.StateError, match="archived attempt was ineligible"): + stage(setup) + + +def test_two_provider_failures_then_harness_failure_has_no_standing_final(setup): + provider = Provider( + { + **plant(setup, "provider_error", "APIConnectionError", 1), + **plant(setup, "provider_error", "APIConnectionError", 2), + **plant(setup, "provider_error", "BadRequestError", 3), + } + ) + + def failure(*args, **kwargs): + result = provider(*args, **kwargs) + if result["error"] == "BadRequestError": + result["turns"] = [] + return result + + plan = stage(setup, failure, models=[nt.CHEAP[0]]) + assert plan.execute() == 1 + assert plan.states[nt.CHEAP[0]] == "harness-stopped" + assert [n for _, _, n in provider.calls] == [1, 2, 3] + assert len(load(final(plan))["attempts"]) == 2 + assert not plan.standing(nt.CHEAP[0], "h2") + assert not final(plan, sid="h1").exists() + + +@pytest.mark.parametrize( + "status,error,expected", + [ + ("provider_error", "BadRequestError", "stop"), + ("budget_stop", None, "stopped"), + ], +) +def test_stage_problems_requires_every_cheap_model_final_to_stand( + setup, status, error, expected, monkeypatch +): + plan = stage(setup) + assert plan.execute() == 0 + path = final(plan, model=nt.CHEAP[-1], sid="h1") + payload = load(path) + payload.update(status=status, error=error, turns=[]) + path.write_text(json.dumps(payload)) + monkeypatch.setattr( + nt.pilot, "load_board", lambda _: pytest.fail("helper loads board") + ) + problems = nt.stage_problems(setup["design"]) + assert any(nt.CHEAP[-1] in p and "h1" in p and expected in p for p in problems) + + +def test_stage_problems_reports_missing_finals_and_invalid_optional_history(setup): + plan = stage(setup) + assert plan.execute() == 0 + assert nt.stage_problems(setup["design"]) == [] + final(plan, sid="h1").unlink() + optional = plan.households("gpt-6-sol") / "attempts/h2-2.json" + optional.parent.mkdir(parents=True) + optional.write_text("{}") + problems = nt.stage_problems(setup["design"]) + assert any(nt.CHEAP[0] in p and "h1" in p and "missing" in p for p in problems) + assert any("attempt-number gap" in p and "gpt-6-sol" in p for p in problems) + + +def test_real_harness_checks_other_models_spend_before_the_next_turn( + setup, monkeypatch +): + from policybench import eval_no_tools + + monkeypatch.setattr(nt, "NO_TOOLS_CAP", 0.1) + for scenario in setup["board"]["scenarios"].values(): + scenario.country = "us" + + def prompt(scenario, variables, profile): + return "Synthetic household", { + "_board_prompt_sha256": "synthetic", + "_sent_board_prompt_sha256": "synthetic", + "_budget_ceiling": 100, + "_answer_tool": nt.pilot.answer_tool_for( + profile, variables, scenario.country + ), + "max_tokens": 100, + } + + monkeypatch.setattr(nt.pilot, "build_initial_request", prompt) + monkeypatch.setattr( + eval_no_tools, + "_extract_usage_metadata", + lambda response, *args: {"total_cost_usd": response.synthetic_cost}, + ) + entered = threading.Barrier(2) + requests = [] + models = [nt.CHEAP[0], nt.CHEAP[2]] + first_id = nt.pilot.model_profile(models[0], arm="none").model_id + + def completion(**kwargs): + requests.append(kwargs["model"]) + entered.wait(timeout=30) + if kwargs["model"] != first_id: + assert plan.stopped.wait(timeout=30), "other model must cross shared cap" + message = SimpleNamespace( + role="assistant", content="", tool_calls=None, function_call=None + ) + return SimpleNamespace( + choices=[SimpleNamespace(message=message, finish_reason="stop")], + synthetic_cost=0.11 if kwargs["model"] == first_id else 0.0, + id="synthetic-response", + ) + + plan = nt.Stage( + setup["design"], + models=models, + board=setup["board"], + run_household=nt.pilot.run_household, + completion_for=lambda profile: completion, + out=io.StringIO(), + ) + assert plan.execute() == 1 + assert len(requests) == 2 + for model in models: + payload = load(final(plan, model=model)) + assert payload["status"] == "budget_stop", payload.get("error") + assert len(payload["turns"]) == 1 + assert not final(plan, model=model, sid="h1").exists() + assert plan.spend.spent_usd == pytest.approx(0.11) diff --git a/tests/test_confirmatory_run.py b/tests/test_confirmatory_run.py new file mode 100644 index 00000000..0b39c5a6 --- /dev/null +++ b/tests/test_confirmatory_run.py @@ -0,0 +1,3240 @@ +"""The confirmatory runner (scripts/confirmatory_run.py). + +The runs here are fakes: a fake provider whose conversations a test plants, +a fake engine pool and a host log sampled every 20 ms, on a fake board. Each +run is checked by `run_problems`, which recomputes, from the files the runner +wrote and nothing else, every rule the run procedure states: the records and +their hashes, each attempt's class and action, the lanes and the schedule, +admission, pauses, stops and the ceiling. The study's differential test runs +the runner and checks its records with the confirmatory report itself. +""" + +from __future__ import annotations + +import copy +import hashlib +import io +import json +import math +import os +import signal +import subprocess +import sys +import threading +import time +from datetime import datetime +from pathlib import Path +from zoneinfo import ZoneInfo + +import numpy as np +import pandas as pd +import pytest +from hypothesis import HealthCheck, given, settings +from hypothesis import strategies as st + +sys.path.insert(0, str(Path(__file__).resolve().parents[1] / "scripts")) + +import confirmatory_run as cr # noqa: E402 +import tool_pilot_argon as pilot # noqa: E402 + +from policybench.scenarios import Person, Scenario # noqa: E402 + +VARIABLES = ["snap", "federal_income_tax_before_refundable_credits"] +POOL = [f"h{i:02d}" for i in range(12)] +N_DRAW = 6 +COST = 0.01 +TZ = "America/New_York" +PREREG = "A frozen pre-registration for a test.\n" +ENGINE = "2.60.4" +# The harness times requests with the raw wall clock, which steps back by +# about 0.1 ms on this host, even within a thread; the report allows a second, as +# here, which also covers a small correction of the clock. +CLOCK_SLACK = 1.0 +# The anchor command in a test: a copy of the anchors to the test's folder. +ANCHOR_SCRIPT = Path(__file__).resolve().parent / "fake_anchor.py" +# How far apart anchors and their triggers' stops may be in a test, on a +# loaded host. +ANCHOR_SLACK = 30.0 +TRIGGER_BOUND = 5.0 + + +# ---------------------------------------------------------------- streams + + +def test_the_master_seed_is_the_first_sixteen_hex_digits(): + sha = hashlib.sha256(b"x").hexdigest() + assert cr.master_seed(sha) == int(sha[:16], 16) + with pytest.raises(ValueError): + cr.master_seed("not a sha") + + +def test_a_stream_is_keyed_by_its_name_alone(): + a = cr.stream(7, "order/m").integers(0, 1 << 30, 5) + b = cr.stream(7, "order/m").integers(0, 1 << 30, 5) + c = cr.stream(7, "order/n").integers(0, 1 << 30, 5) + assert list(a) == list(b) and list(a) != list(c) + key = int.from_bytes(hashlib.sha256(b"draw").digest()[:8], "big") + want = np.random.default_rng(np.random.SeedSequence(7, spawn_key=(key,))) + assert list(cr.stream(7, "draw").integers(0, 100, 8)) == list( + want.integers(0, 100, 8) + ) + + +@settings(deadline=None) +@given(st.integers(0, (1 << 64) - 1), st.integers(1, 12)) +def test_the_draw_is_seeded_and_without_replacement(master, n): + got = cr.draw(master, list(reversed(POOL)), n=n) + assert got == cr.draw(master, POOL, n=n) # the pool is sorted first + assert len(set(got)) == n and set(got) <= set(POOL) + + +def test_orders_are_permutations_drawn_for_every_household_in_draw_order(): + got = cr.orders(9, "m", POOL, cr.ARMS) + assert list(got) == POOL + assert all(sorted(o) == sorted(cr.ARMS) for o in got.values()) + generator = cr.stream(9, "order/m") + assert got[POOL[0]] == [str(a) for a in generator.permutation(list(cr.ARMS))] + # The first households' orders do not depend on the later ones. + assert cr.orders(9, "m", POOL[:3], cr.ARMS) == {s: got[s] for s in POOL[:3]} + + +# ---------------------------------------------------------------- arms + + +def test_arm_strings_follow_the_harness_feature_order(): + assert cr.arm_string("pe") == "pe" + assert cr.arm_string("pe3") == cr.arm_string("pe3-b") == "pe3" + for label, dropped in cr.DROPPED.items(): + if dropped: + kept = [f for f in pilot.TOOL_FEATURES if f not in dropped] + assert cr.arm_string(label) == "pe:" + "+".join(kept) + + +@pytest.mark.parametrize("model", cr.CHEAP + cr.FRONTIER) +def test_each_arm_has_its_registered_features(model): + for label in cr.ARMS if model in cr.CHEAP else cr.FRONTIER_ARMS: + profile = cr.arm_profile(model, label) + dropped = cr.DROPPED[label] + want = set() if dropped is None else set(pilot.TOOL_FEATURES) - set(dropped) + assert profile.uses_calculator and set(profile.tool_features) == want + assert profile.prompt_version == cr.PROMPT_VERSION + + +def test_an_arm_whose_features_are_not_registered_is_refused(monkeypatch): + # The harness builds an arm's features from its arm string: a string that + # does not give the label's registered features is refused. + monkeypatch.setattr(cr, "arm_string", lambda label: "pe:names+labels") + with pytest.raises(ValueError, match="features"): + cr.arm_profile("gpt-6-luna", "loo-flat") + + +def litellm_names(groups) -> set[str]: + """The names of litellm's exception classes under any of `groups`.""" + import inspect + + import litellm + + found = set() + for module in (litellm, litellm.exceptions): + for obj in vars(module).values(): + if inspect.isclass(obj) and issubclass(obj, BaseException): + if issubclass(obj, groups): + found.add(obj.__name__) + return found + + +def test_the_error_classes_are_policybench_s(): + """A record keeps the raised class's name, and the harness groups classes + by inheritance: so each list holds every litellm class under the + harness's group.""" + from policybench import eval_no_tools as e + + fatal = litellm_names(e.MODEL_FATAL_ERRORS) + retryable = litellm_names(e.RETRYABLE_PROVIDER_ERRORS) - fatal + assert cr.REQUEST | cr.ACCOUNT == fatal + assert cr.TRANSPORT - {"RequestWallTimeoutError"} == retryable + assert "RequestWallTimeoutError" in { + c.__name__ for c in e.RETRYABLE_PROVIDER_ERRORS + } + assert {"ContentPolicyViolationError", "RejectedRequestError"} <= cr.REQUEST + assert not cr.REQUEST & cr.ACCOUNT + assert not cr.TRANSPORT & (cr.REQUEST | cr.ACCOUNT) + assert cr.TIMEOUTS <= cr.TRANSPORT + + +# ---------------------------------------------------------------- classes + + +def record(status="complete", error=None, turns=1, calls=(), truncated=False): + """`truncated`: the record's last turn is a truncated one, its escalated + request then failing (with `turns` - 1 completed turns before it).""" + turn = {"calls": [{"result": r} for r in calls]} + out = [dict(turn) for _ in range(turns)] + if truncated: + out = out[: max(turns - 1, 0)] + [{"truncated_and_retried": True}] + return {"status": status, "error": error, "turns": out} + + +class AlwaysTrouble: + def trouble(self, start, end): + return "memory pressure" + + +CASES = [ + (record(), "ok"), + (record("incomplete"), "ok"), + (record("turn_limit"), "ok"), + (record("provider_error", "RateLimitError: slow down"), "provider"), + (record("provider_error", "BadRequestError: too long"), "model"), + (record("provider_error", "BadRequestError: bad", turns=0), "harness"), + (record("provider_error", "BadRequestError: x", truncated=True), "harness"), + (record("provider_error", "BadRequestError: x", 2, truncated=True), "model"), + (record("provider_error", "ContentPolicyViolationError: x", turns=0), "harness"), + (record("provider_error", "ContentPolicyViolationError: x"), "model"), + (record("provider_error", "RejectedRequestError: x", turns=0), "harness"), + # The escalated request's timeout is the model's long generation. + (record("provider_error", "Timeout: 300 s", truncated=True), "model"), + (record("provider_error", "Timeout: 300 s", 3, truncated=True), "model"), + (record("provider_error", "Timeout: 300 s"), "provider"), + # A truncated return is a return: no longer `none`. + (record("provider_error", "RateLimitError: x", truncated=True), "provider"), + ( + record("provider_error", "ProviderEmpty: no choices", truncated=True), + "inconclusive", + ), + (record("provider_error", "ProviderEmpty: no choices", turns=0), "none"), + (record("provider_error", "JSONSchemaValidationError: x"), "provider"), + (record("provider_error", "AuthenticationError: key", turns=0), "operator"), + (record("provider_error", "RateLimitError: insufficient_quota"), "operator"), + (record("provider_error", "ProviderEmpty: no choices"), "inconclusive"), + (record("provider_error", "RateLimitError: x", turns=0), "none"), + ( + record("harness_error", "RuntimeError: every tool worker was lost", turns=0), + "none", + ), + (record("harness_error", "the tool pool had no worker"), "inconclusive"), + (record("budget_stop"), "ceiling"), + (record("budget_stop", turns=0), "ceiling"), + (record(calls=[{"error": "timeout", "message": "slow"}]), "inconclusive"), + ( + record(calls=[{"error": "engine", "message": "tool worker failed: EOF"}]), + "inconclusive", + ), + (record(calls=[{"error": "engine", "message": "MemoryError: x"}]), "inconclusive"), + (record(calls=[{"error": "engine", "message": "ValueError: no person"}]), "model"), + (record(calls=[{"results": {"snap": {"error": "OSError: disk"}}}]), "inconclusive"), + (record(calls=[{"results": {"snap": {"error": "KeyError: x"}}}]), "model"), + # The explain feature's trace of a variable, which catches its own errors. + ( + record(calls=[{"explanations": {"snap": {"error": "MemoryError: x"}}}]), + "inconclusive", + ), + ( + record(calls=[{"explanations": {"snap": {"error": "OSError: disk"}}}]), + "inconclusive", + ), + (record(calls=[{"explanations": {"snap": {"error": "KeyError: x"}}}]), "model"), + (record(calls=[{"explanations": {"snap": {"value": 1.0}}}]), "ok"), + (record("running"), "inconclusive"), +] + + +@pytest.mark.parametrize("rec, want", CASES) +def test_each_failure_takes_its_class(rec, want): + assert cr.classify(rec, 0.0, 1.0, None)[0] == want + + +@pytest.mark.parametrize("rec, want", CASES) +def test_host_trouble_outranks_every_class_but_the_early_four(rec, want): + got = cr.classify(rec, 0.0, 1.0, AlwaysTrouble())[0] + assert got == (want if want in cr.EARLY else "host") + + +@pytest.mark.parametrize("rec, want", CASES) +def test_an_early_class_needs_no_host_evidence(rec, want): + early = cr.classify(rec, 0.0, 1.0, None)[0] + assert (early in cr.EARLY) == (want in cr.EARLY) + + +def test_actions_follow_the_class_and_the_attempt(): + for cls in ("ok", "model", "provider", "host", "none", "operator", "harness"): + for n in (1, 2, 3): + got = cr.action(cls, n) + if cls == "harness": + assert got == "stop" + elif cls in ("provider", "host", "none") and n <= 2: + assert got == "rerun" + elif cls == "operator" and n <= 2: + assert got == "pause-rerun" + else: + assert got == "stands" + assert cr.action("ceiling", 1) == "stopped" + assert cr.action("inconclusive", 1) == "stands" + + +# ---------------------------------------------------------------- host evidence + + +def guard_line(t: float, what: str) -> str: + stamp = datetime.fromtimestamp(t, ZoneInfo(TZ)).strftime("%Y-%m-%d %H:%M:%S") + return f"{stamp} [poll] lid closed on battery: {what} pids: 1 2" + + +def power_line(t: float, kind: str) -> str: + stamp = datetime.fromtimestamp(t, ZoneInfo(TZ)).strftime("%Y-%m-%d %H:%M:%S %z") + return f"{stamp} {kind:<20}\t{kind} due to a test" + + +def test_guard_pauses_and_power_sleeps_are_spans(): + t = 1_800_000_000.0 + guard = "\n".join( + [ + guard_line(t, "paused"), + guard_line(t + 10, "resumed"), + "junk", + guard_line(t + 20, "paused"), + ] + ) + assert cr.guard_spans(guard, TZ, end=t + 99) == [ + (t, t + 10, "guard pause"), + (t + 20, t + 99, "guard pause"), + ] + power = "\n".join( + [ + power_line(t, "Sleep"), + power_line(t + 5, "DarkWake"), + power_line(t + 7, "Sleep"), + ] + ) + assert cr.power_spans(power, end=t + 50) == [ + (t, t + 5, "sleep"), + (t + 7, t + 50, "sleep"), + ] + + +def test_an_excerpt_keeps_the_lines_stamped_in_its_window(): + t = 1_800_000_000.0 + text = "\n".join(guard_line(t + k, "paused") for k in (-5, 0, 5, 10)) + "\nx" + zone = ZoneInfo(TZ) + kept = cr.excerpt(text, lambda x: cr.guard_times(x, zone), t, t + 5) + assert kept.splitlines() == [guard_line(t, "paused"), guard_line(t + 5, "paused")] + + +class Readers: + """The host log's inputs, which a test can change while it runs.""" + + def __init__(self): + self.pressure = 1 + self.pressing = 0 # attempts under way that raise the pressure + self.stall = 0.0 + self.guard: list[str] = [] + self.power: list[str] = [] + self.lock = threading.Lock() + + def read_pressure(self): + with self.lock: + stall, self.stall = self.stall, 0.0 + if stall: + time.sleep(stall) + return 2 if self.pressing else self.pressure + + def host(self, folder): + return cr.HostLog( + folder, + timezone=TZ, + interval=0.02, + read_load=lambda: (1.0, 2.0, 3.0), + read_pressure=self.read_pressure, + read_guard=lambda: "\n".join(self.guard), + read_power=lambda: "\n".join(self.power), + ) + + +def wait_for_samples(log: Path, enough, seconds: float = 5.0) -> None: + """Wait until the host log's complete samples satisfy `enough`. A loaded + host can stretch the 0.02 s sampler past any fixed sleep.""" + deadline = time.monotonic() + seconds + while time.monotonic() < deadline: + text = log.read_text() if log.exists() else "" + if enough([json.loads(x) for x in text.split("\n")[:-1]]): + return + time.sleep(0.01) + + +@pytest.fixture +def fast(monkeypatch): + """Short evidence windows, with room for the shared host's scheduler. + Intentional gaps scale with this bound; ordinary stalls must not turn + an untouched fake run into a host-failure test.""" + monkeypatch.setattr(cr, "PRESSURE_WINDOW", 0.06) + monkeypatch.setattr(cr, "HOST_LOG_GAP", 5.0) + monkeypatch.setattr(cr, "WAIT_SECONDS", 0.005) + monkeypatch.setattr(cr, "HOUSEHOLDS", N_DRAW) + monkeypatch.setattr(cr, "SAMPLER_SILENCE", 1.0) + monkeypatch.setattr(cr, "READ_WAIT", 0.01) + monkeypatch.setattr(cr, "ANCHOR_SECONDS", 0.3) + handlers = {s: signal.getsignal(s) for s in (signal.SIGINT, signal.SIGTERM)} + yield + for signum, handler in handlers.items(): + signal.signal(signum, handler) + + +def test_the_host_log_samples_and_closes(tmp_path, fast): + readers = Readers() + host = readers.host(tmp_path) + wait_for_samples(tmp_path / "host-log.jsonl", lambda samples: len(samples) >= 4) + host.close() + meta = json.loads((tmp_path / "host.json").read_text()) + samples = [ + json.loads(x) for x in (tmp_path / "host-log.jsonl").read_text().splitlines() + ] + assert meta["timezone"] == TZ and meta["start"] <= samples[0]["time"] + assert samples[-1]["time"] <= meta["end"] + assert len(samples) >= 4 + assert samples[0]["load1"] == 1.0 and samples[0]["pressure"] == 1 + times = [s["time"] for s in samples] + assert times == sorted(times) + + +def test_pressure_near_an_attempt_is_host_trouble_once_settled(tmp_path, fast): + readers = Readers() + host = readers.host(tmp_path) + start = time.time() + readers.pressure = 2 + wait_for_samples( + tmp_path / "host-log.jsonl", + lambda samples: any(x["pressure"] == 2 for x in samples), + ) + readers.pressure = 1 + end = time.time() + host.wait_settled(end) + assert host.settled(end) + host.refresh(after=end) + assert host.trouble(start, end) == "memory pressure" + assert host.trouble(end + 1, end + 2) is None + host.close() + + +def test_a_stalled_host_log_is_a_gap(tmp_path, fast): + readers = Readers() + host = readers.host(tmp_path) + time.sleep(0.03) + start = time.time() + stall = cr.HOST_LOG_GAP + 0.3 + readers.stall = stall + time.sleep(stall + 0.05) + end = time.time() + host.wait_settled(end) + host.refresh(after=end) + assert host.trouble(start, end) == "host log gap" + host.close() + + +def test_guard_pauses_and_sleeps_reach_an_attempt_after_a_refresh(tmp_path, fast): + readers = Readers() + host = readers.host(tmp_path) + start = time.time() + readers.guard += [guard_line(start, "paused"), guard_line(start + 1, "resumed")] + end = time.time() + host.wait_settled(end) + assert host.trouble(start, end) is None # not read yet + host.refresh(after=end) + assert host.trouble(start, end) == "guard pause" + readers.guard.clear() + readers.power += [power_line(start, "Sleep"), power_line(start + 1, "Wake")] + host.refresh(after=time.time()) + assert host.trouble(start, end) == "sleep" + host.close() + assert "Sleep" in (tmp_path / "pmset.log").read_text() + + +def test_a_failed_pressure_reading_is_no_sample(tmp_path, fast): + """A sample with no pressure reading is written, but it is no sample: a + failing reading under pressure would hide the evidence the rule reads, + so the silence it leaves is a gap.""" + readers = Readers() + host = readers.host(tmp_path) + time.sleep(0.03) + start = time.time() + readers.pressure = None + time.sleep(cr.HOST_LOG_GAP + 0.2) + readers.pressure = 1 + end = time.time() + host.wait_settled(end) + host.refresh(after=end) + assert host.trouble(start, end) == "host log gap" + host.close() + samples = [ + json.loads(x) for x in (tmp_path / "host-log.jsonl").read_text().splitlines() + ] + assert any(x["pressure"] is None for x in samples) + folder_host = host_from_files(tmp_path) + assert folder_host.trouble(start, end) == "host log gap" # the report's reading + + +def test_the_host_log_is_a_hash_chain_with_a_monotonic_time(tmp_path, fast): + readers = Readers() + host = readers.host(tmp_path) + time.sleep(0.1) + host.close() + path = tmp_path / "host-log.jsonl" + assert chain_problems(path, cr.HOST_SEED) == [] + lines = path.read_text().splitlines() + assert host.heads() == {"lines": len(lines), "sha256": cr.line_sha(lines[-1])} + ticks = [json.loads(x)["monotonic"] for x in lines] + assert ticks == sorted(ticks) + + +def test_a_failed_log_read_is_tried_again(tmp_path, fast): + calls = [] + + def power(): + calls.append(1) + if len(calls) <= 2: + raise subprocess.CalledProcessError(1, ["pmset"]) + return "" + + host = cr.HostLog( + tmp_path, + timezone=TZ, + interval=0.02, + read_load=lambda: (1.0, 2.0, 3.0), + read_pressure=lambda: 1, + read_guard=lambda: "", + read_power=power, + ) + host.refresh(after=time.time()) + assert len(calls) == 3 # two failures, then a read + host.close() + assert (tmp_path / "pmset.log").exists() + + +def test_logs_that_cannot_be_read_are_a_runner_error(tmp_path, fast): + def power(): + raise subprocess.TimeoutExpired(["pmset"], 120) + + host = cr.HostLog( + tmp_path, + timezone=TZ, + interval=0.02, + read_load=lambda: (1.0, 2.0, 3.0), + read_pressure=lambda: 1, + read_guard=lambda: "", + read_power=power, + ) + with pytest.raises(cr.HostEvidenceError): + host.refresh(after=time.time()) + host.close() + assert "TimeoutExpired" in (tmp_path / "host-error.txt").read_text() + assert not (tmp_path / "pmset.log").exists() + + +def test_a_sampler_whose_samples_fail_is_dead_after_its_silence(tmp_path, fast): + readers = Readers() + host = readers.host(tmp_path) + assert host.dead() is None + readers.pressure = None + host.sample() + time.sleep(cr.SAMPLER_SILENCE + 0.2) + assert "samples failing since" in host.dead() + readers.pressure = 1 + host.sample() + assert host.dead() is None # a good sample: alive again + host.close() + + +# ---------------------------------------------------------------- the ceiling + + +def test_the_clock_never_goes_back(monkeypatch): + monkeypatch.setattr(cr, "_clock_last", cr._clock_last) # restored after + base = time.time() + 1000.0 + readings = iter([base, base - 1e-4, base + 2e-4, base - 5.0, base + 3e-4]) + monkeypatch.setattr(time, "time", lambda: next(readings)) + assert [cr.clock() for _ in range(5)] == [ + base, + base, + base + 2e-4, + base + 2e-4, + base + 3e-4, + ] + + +def test_a_backward_wall_clock_does_not_delay_a_due_anchor(monkeypatch): + """Once the ordered clock reaches the due time, a wall-clock step cannot + make the anchor not due again.""" + run = cr.Run.__new__(cr.Run) + run._pushing = threading.Lock() + run._push_error = None + base = time.time() + 1000.0 + run._next_anchor = base + monkeypatch.setattr(cr, "_clock_last", base - 1.0) + readings = iter([base - 1.0, base + 1.0, base - 5.0]) + monkeypatch.setattr(time, "time", lambda: next(readings)) + assert [run.anchor_due() for _ in range(3)] == [False, True, True] + + +def test_the_anchor_interval_and_retry_wait_are_registered_durations(): + """paper/preregistration-draft.md:218: anchors every 15 minutes, and retries + a minute after the failed push ends.""" + assert cr.ANCHOR_SECONDS == 900.0 + assert cr.ANCHOR_RETRY == 60.0 + + +def test_a_wall_clock_that_steps_back_keeps_the_run_procedure(world, monkeypatch): + """Every reading of the wall clock up to 0.2 ms early (steps back of up to + 0.1 ms seen on this host): the run's times still order its attempts, + stops and decisions.""" + import random + + jitter, real = random.Random(7), time.time + monkeypatch.setattr(time, "time", lambda: real() - jitter.uniform(0.0, 2e-4)) + w = world().execute() + assert run_problems(w) == [] + for model in w.models: + assert len(w.attempts(model)) == N_DRAW * len(labels_of(model)) + + +def test_the_ceiling_crosses_at_its_amount_and_stays_crossed(): + ceiling = cr.Ceiling(1.0, 0.25) + ceiling.add(0.5) + assert not ceiling.exhausted() and ceiling.crossed_at is None + ceiling.add(0.25) + assert ceiling.exhausted() and ceiling.crossed_at is not None + first = ceiling.crossed_at + ceiling.add(None) + assert ceiling.crossed_at == first and ceiling.spent_usd == pytest.approx(1.0) + + +def test_the_ceiling_ignores_a_reserve(): + # No conversation stops for a model's spend: only the ceiling stops one. + assert not cr.Ceiling(1.0, 0.0).exhausted(reserve_usd=5.0) + + +# ---------------------------------------------------------------- fake runs + + +def scenario(sid: str) -> Scenario: + i = POOL.index(sid) + return Scenario( + id=sid, + state="CO", + filing_status="single", + adults=[Person(name="head", age=30 + i, employment_income=10_000.0 * (i + 1))], + children=[], + ) + + +class FakePool: + """An engine pool that answers every call and keeps what it was sent.""" + + def __init__(self, lanes, fail: bool = False): + if fail: + raise RuntimeError("tool worker failed to start: a test") + self.messages: list = [] + self.lost = 0 + self.closed = False + + def call(self, message): + self.messages.append(message) + return {"results": {"snap": {"values": {"spm": 1.0}}}}, 0.0 + + def counters(self): + return {"timeouts": 0, "crashes": 0, "lost": self.lost} + + def close(self): + self.closed = True + + +class FakeProvider: + """Conversations a test plants. specs[(model, label, household, n)] holds a + record's `status` and `error`, `turns` (default 1), `cost` per turn, + `sleep` per turn, `calls` (tool arguments, one call each, per turn), + `pressure` (high pressure during the attempt), `stall` (a host-log stall, + seconds), `guard` (a guard pause over the attempt), `resume_after` + (seconds after which the operator resumes), `raise` (the conversation + raises before its first turn), `raise_after` (it raises after its turns) + and `check` (a function of the lanes, called first).""" + + def __init__(self, world, specs=None): + self.world, self.specs = world, specs or {} + self.count: dict = {} + self.lock = threading.Lock() + + def __call__(self, lanes, sid, label, tool_call, spend): + model = lanes.model + with self.lock: + n = self.count[(model, label, sid)] = ( + self.count.get((model, label, sid), 0) + 1 + ) + spec = self.specs.get((model, label, sid, n), {}) + readers = self.world.readers + if spec.get("check"): + spec["check"](lanes) + if spec.get("raise"): + raise RuntimeError("a test raised") + if spec.get("pressure"): + with readers.lock: + readers.pressing += 1 + lanes.run.host.sample() # the planted pressure is actually observed + if spec.get("stall"): + readers.stall = spec["stall"] + start = time.time() + rec = { + "scenario_id": sid, + "model": model, + "arm": cr.arm_string(label), + "variables": list(VARIABLES), + "status": "running", + "turns": [], + "predictions": {v: 0.0 for v in VARIABLES}, + } + for i in range(spec.get("turns", 1)): + if spend.exhausted(): + rec["status"] = "budget_stop" + break + started = time.time() + time.sleep(spec.get("sleep", 0.0)) + completed = time.time() + cost = spec.get("cost", COST) + spend.add(cost) + turn = { + "index": i, + "request_started_at": started, + "request_completed_at": completed, + "total_cost_usd": cost, + "calls": [], + } + for arguments in spec.get("calls", []): + result, latency = tool_call(arguments) + turn["calls"].append({"arguments": arguments, "result": result}) + rec["turns"].append(turn) + if spec.get("raise_after"): + raise RuntimeError("a test raised after spending") + if rec["status"] == "running": + rec["status"] = spec.get("status", "complete") + if spec.get("error"): + rec["error"] = spec["error"] + if spec.get("guard"): + readers.guard += [ + guard_line(math.floor(start) - 1, "paused"), + guard_line(math.ceil(time.time()) + 1, "resumed"), + ] + if spec.get("stall"): + time.sleep(spec["stall"] + 0.02) + if spec.get("pressure"): + with readers.lock: + readers.pressing -= 1 + rec["totals"] = {"cost_usd": sum(t["total_cost_usd"] for t in rec["turns"])} + if spec.get("resume_after") is not None: + folder = lanes.folder + + def resume(): + with lanes.cond: + if ( + not lanes.cond.wait_for( + lambda: lanes.paused or lanes.halted(), timeout=30 + ) + or not lanes.paused + ): + return + time.sleep(spec["resume_after"]) + cr.write_json( + folder / "RESUME.json", + {"time": cr.clock(), "note": "fixed in a test"}, + ) + + threading.Thread(target=resume, daemon=True).start() + return rec + + +class World: + """A fake board, design and run.""" + + def __init__( + self, + tmp: Path, + monkeypatch, + specs=None, + caps=None, + reserve=7 * 3 * COST, + overall_cap=100.0, + spent_before=1.0, + no_output=(), + models=None, + pool=FakePool, + ): + self.tmp = tmp + prereg = tmp / "prereg.md" + prereg.write_text(PREREG) + frozen = cr.sha256_file(prereg) + master = cr.master_seed(frozen) + self.draw_order = cr.draw(master, POOL, n=N_DRAW) + board_path = tmp / "board" + board_path.mkdir() + (board_path / "reference_outputs.csv").write_text( + "scenario_id,variable,value\n" + ) + self.no_output = set(no_output) + scored = [ + (sid, v) for sid in POOL if sid not in self.no_output for v in VARIABLES + ] + self.board = { + "scenarios": {sid: scenario(sid) for sid in POOL}, + "variables": {sid: list(VARIABLES) for sid in POOL}, + "scored": pd.DataFrame(scored, columns=["scenario_id", "variable"]), + } + monkeypatch.setattr(pilot, "load_board", lambda path: self.board) + monkeypatch.setattr(pilot, "board_engine", lambda path=None: ENGINE) + monkeypatch.setitem( + pilot._STATED_ENGINE, "version", pilot._STATED_ENGINE["version"] + ) + self.models = tuple(models or cr.CHEAP + cr.FRONTIER) + budget_models = tuple(dict.fromkeys(cr.CHEAP + cr.FRONTIER + self.models)) + self.design = { + "preregistration": str(prereg), + "frozen_sha256": frozen, + "runs": str(tmp / "runs"), + "stage": "confirm", + "board": str(board_path), + "engine": f"policyengine-us {ENGINE}", + "draw_order": self.draw_order, + "arms": {a: a for a in cr.ARMS}, + "frontier_arms": {a: f"f-{a}" for a in cr.FRONTIER_ARMS}, + "caps": {m: (caps or {}).get(m, 10.0) for m in budget_models}, + "reserves": {m: reserve for m in budget_models}, + "overall_cap": overall_cap, + "spent_before": spent_before, + "workers": 2, + "anchor_command": [sys.executable, str(ANCHOR_SCRIPT), str(tmp)], + } + self.readers = Readers() + self.provider = FakeProvider(self, specs) + self.run = cr.Run( + self.design, + models=self.models, + converse=self.provider, + pool_factory=pool, + completion_for=lambda profile: None, + host_factory=self.readers.host, + out=io.StringIO(), + ) + + def execute(self): + self.run.execute() + return self + + # What the runner wrote. + + def runs(self) -> Path: + return Path(self.design["runs"]) + + def lines(self, model, name="run-log.jsonl") -> list[dict]: + path = self.runs() / model / name + if not path.exists(): + return [] + return [json.loads(x) for x in path.read_text().splitlines() if x.strip()] + + def attempts(self, model) -> list[dict]: + return [x for x in self.lines(model) if "event" not in x] + + def events(self, model, kind=None) -> list[dict]: + return [ + x + for x in self.lines(model) + if x.get("event") and kind in (None, x["event"]) + ] + + def folder(self, model, label) -> Path: + arms = ( + self.design["arms"] if model in cr.CHEAP else self.design["frontier_arms"] + ) + return self.runs() / model / arms[label] / "confirm" / "households" + + +def labels_of(model): + return cr.ARMS if model in cr.CHEAP else cr.FRONTIER_ARMS + + +def host_from_files(folder: Path): + """The host evidence as the report builds it, from the archived files.""" + meta = json.loads((folder / "host.json").read_text()) + start, end = float(meta["start"]), float(meta["end"]) + samples = [ + json.loads(x) for x in (folder / "host-log.jsonl").read_text().splitlines() if x + ] + spans = cr.guard_spans( + (folder / "clamshell-guard.log").read_text(), meta["timezone"], end + ) + spans += cr.power_spans((folder / "pmset.log").read_text(), end) + # A sample with no pressure reading is no sample. + good = [s for s in samples if s.get("pressure") is not None] + times = sorted(float(s["time"]) for s in good) + for a, b in zip([start] + times, times + [end]): + if b - a > cr.HOST_LOG_GAP: + spans.append((a, b, "host log gap")) + pressure = [float(s["time"]) for s in good if int(s["pressure"]) > 1] + + class Host: + def trouble(self, s, e): + for a, b, what in spans: + if a <= e and b >= s: + return what + for t in pressure: + if s - cr.PRESSURE_WINDOW <= t <= e + cr.PRESSURE_WINDOW: + return "memory pressure" + return None + + return Host() + + +def chain_problems(path: Path, seed: str) -> list[str]: + """Whether each line's `prev` is the line before's sha256 (the first's, + `seed`).""" + head = seed + for i, text in enumerate(path.read_text().splitlines() if path.exists() else []): + if json.loads(text).get("prev") != head: + return [f"{path.name} line {i + 1}: its prev is not the line before's hash"] + head = cr.line_sha(text) + return [] + + +def chain_heads(path: Path, seed: str) -> list[str]: + """The chain's head after each count of lines, from none.""" + heads = [seed] + for text in path.read_text().splitlines() if path.exists() else []: + heads.append(cr.line_sha(text)) + return heads + + +def anchor_problems(world: World) -> list[str]: + """The anchors: a chain of their own; each holds every log's head at its + count; the last holds every log whole; the last was pushed.""" + problems: list[str] = [] + runs, frozen = world.runs(), world.design["frozen_sha256"] + path = runs / "anchors.jsonl" + problems += chain_problems(path, cr.chain_seed(frozen, "", "anchors.jsonl")) + anchors = [json.loads(x) for x in path.read_text().splitlines()] + heads = { + (model, name): chain_heads( + runs / model / name, cr.chain_seed(frozen, model, name) + ) + for model in world.models + for name in ("run-log.jsonl", "admission-log.jsonl") + } + host = chain_heads(runs / "host" / "host-log.jsonl", cr.HOST_SEED) + for i, anchor in enumerate(anchors): + for (model, name), chain in heads.items(): + got = anchor["models"][model][name] + if got["lines"] >= len(chain) or chain[got["lines"]] != got["sha256"]: + problems.append(f"anchor {i}: {model}/{name} is not the log's head") + got = anchor["host-log.jsonl"] + if got["lines"] >= len(host) or host[got["lines"]] != got["sha256"]: + problems.append(f"anchor {i}: the host log is not the log's head") + last = anchors[-1] + for (model, name), chain in heads.items(): + if last["models"][model][name]["lines"] != len(chain) - 1: + problems.append(f"the last anchor leaves out lines of {model}/{name}") + if last["host-log.jsonl"]["lines"] != len(host) - 1: + problems.append("the last anchor leaves out host-log lines") + for a, b in zip(anchors, anchors[1:]): + if b["time"] - a["time"] > cr.ANCHOR_SECONDS + ANCHOR_SLACK: + problems.append(f"anchors {a['time']!r} and {b['time']!r} too far apart") + pushes = [ + json.loads(x) for x in (runs / "anchor-pushes.jsonl").read_text().splitlines() + ] + final = cr.line_sha(path.read_text().splitlines()[-1]) + if not any(x["anchor"] == final and x["returncode"] == 0 for x in pushes): + problems.append("the last anchor was not pushed") + copy = world.tmp / "anchored.jsonl" + if not copy.exists() or copy.read_text() != path.read_text(): + problems.append("the anchor command's copy is not the anchors") + return problems + + +def run_problems(world: World) -> list[str]: + """Every rule of the run procedure, recomputed from the runner's files.""" + problems: list[str] = [] + host = host_from_files(world.runs() / "host") + frozen = world.design["frozen_sha256"] + problems += chain_problems(world.runs() / "host" / "host-log.jsonl", cr.HOST_SEED) + problems += anchor_problems(world) + late_total = 0.0 + position = {sid: i for i, sid in enumerate(world.draw_order)} + master = cr.master_seed(world.design["frozen_sha256"]) + all_attempts = [] + ceiling_events = {} + for model in world.models: + labels = labels_of(model) + drawn = cr.orders(master, model, world.draw_order, labels) + lines = world.attempts(model) + events = world.events(model) + for name in ("run-log.jsonl", "admission-log.jsonl"): + problems += chain_problems( + world.runs() / model / name, cr.chain_seed(frozen, model, name) + ) + for e in events: + if e["event"] == "stop" and e.get("cause") not in cr.STOP_CAUSES: + problems.append(f"{model}: a stop with no cause ({e})") + if e["event"] == "ceiling" and e.get("cause") != "ceiling": + problems.append(f"{model}: a ceiling event with another cause") + late_total += sum(e["cost_usd"] for e in events if e["event"] == "late-cost") + causes = {e.get("cause") for e in events if e["event"] == "stop"} + stops = [e["time"] for e in events if e["event"] in ("stop", "ceiling")] + stopped_at = min(stops) if stops else math.inf + ceiling_events[model] = [e["time"] for e in events if e["event"] == "ceiling"] + cost: dict[str, float] = {} + span: dict[str, list[float]] = {} + by_run: dict = {} + cut_short: set[str] = set() # an arm or a rerun the stop kept from running + for x in lines: + by_run.setdefault((x["household"], x["arm"]), []).append(x) + # Records and hashes. + for label in labels: + folder = world.folder(model, label) + finals = sorted(folder.glob("*.json")) if folder.is_dir() else [] + for path in finals: + if (path.stem, label) not in by_run: + problems.append( + f"{model}/{label}/{path.stem}: a record with no line" + ) + for (sid, label), xs in sorted(by_run.items()): + at = f"{model}/{label}/{sid}" + xs.sort(key=lambda x: x["attempt"]) + if [x["attempt"] for x in xs] != list(range(1, len(xs) + 1)): + problems.append(f"{at}: attempts {[x['attempt'] for x in xs]}") + continue + final_path = world.folder(model, label) / f"{sid}.json" + final = json.loads(final_path.read_text()) + entries = final.get("attempts") or [] + if len(entries) != len(xs) - 1: + problems.append(f"{at}: {len(entries)} entries for {len(xs)} attempts") + continue + for k, x in enumerate(xs, start=1): + if k < len(xs): + entry = entries[k - 1] + path = world.folder(model, label) / entry["file"] + rec = json.loads(path.read_text()) + if entry["n"] != k or entry["sha256"] != cr.sha256_file(path): + problems.append(f"{at}#{k}: its entry does not hash its file") + if entry["class"] != x["class"] or entry["status"] != rec["status"]: + problems.append(f"{at}#{k}: its entry is not its line's") + if x["sha256"] != entry["sha256"]: + problems.append(f"{at}#{k}: its line's hash is not its file's") + else: + rec = final + if x["sha256"] != cr.sha256_file(final_path): + problems.append( + f"{at}#{k}: its line's hash is not its record's" + ) + cls, _ = cr.classify(rec, x["start"], x["end"], host) + if x["class"] == "unsettled" and "runner-error" in causes: + cls = "unsettled" # classed when the runner failed: it stands + rule = cr.action(cls, k) + if x["class"] != cls or x["action"] != rule: + problems.append( + f"{at}#{k}: logged {x['class']}/{x['action']}, " + f"recomputed {cls}/{rule}" + ) + if x["status"] != rec["status"] or x["lane"] != 1 + position[sid] % 2: + problems.append(f"{at}#{k}: status or lane") + if k < len(xs) and rule not in ("rerun", "pause-rerun"): + problems.append(f"{at}#{k}: rerun after {cls}") + if k == len(xs) and rule in ("rerun", "pause-rerun"): + cut_short.add(sid) + if not stops: + problems.append( + f"{at}#{k}: a rerun due and never run, with no stop" + ) + times = [ + t[key] + for t in rec.get("turns") or [] + for key in ("request_started_at", "request_completed_at") + ] + if times and ( + min(times) < x["start"] - CLOCK_SLACK + or max(times) > x["end"] + CLOCK_SLACK + ): + problems.append( + f"{at}#{k}: requests {min(times)!r}-{max(times)!r} outside " + f"its start and end {x['start']!r}-{x['end']!r}" + ) + if x["start"] > stopped_at: + problems.append(f"{at}#{k}: started after a stop") + cost[sid] = cost.get(sid, 0.0) + cr.attempt_cost(rec) + s, e = span.get(sid, [math.inf, -math.inf]) + span[sid] = [min(s, x["start"]), max(e, x["end"])] + all_attempts.append((model, sid, label, k, x, rec)) + # The schedule. + for lane in (1, 2): + mine = sorted( + (x for x in lines if x["lane"] == lane), key=lambda x: x["start"] + ) + for a, b in zip(mine, mine[1:]): + if b["start"] < a["end"]: + problems.append(f"{model} lane {lane}: attempts overlap") + blocks: list = [] + for x in mine: + if blocks and blocks[-1][0] == x["household"]: + blocks[-1][1].append(x) + else: + blocks.append((x["household"], [x])) + sids = [s for s, _ in blocks] + if len(set(sids)) != len(sids) or sids != sorted(sids, key=position.get): + problems.append( + f"{model} lane {lane}: households split or out of order" + ) + for i, (sid, block) in enumerate(blocks): + got = [(x["attempt"], x["arm"]) for x in block] + firsts = [a for n, a in got if n == 1] + want = [(1, a) for a in firsts] + for n in range(2, cr.MAX_RERUNS + 2): + again = {x["arm"] for x in block if x["attempt"] == n} + want += [(n, a) for a in drawn[sid] if a in again] + cut = firsts != drawn[sid] + if cut: + cut_short.add(sid) + if got != want or firsts != drawn[sid][: len(firsts)]: + problems.append(f"{model}/{sid}: ran {got}, drawn {drawn[sid]}") + if cut and not (stops and i == len(blocks) - 1): + problems.append(f"{model}/{sid}: cut short without a stop") + # Admission. + decisions = sorted( + world.lines(model, "admission-log.jsonl"), key=lambda x: x["time"] + ) + cap = world.design["caps"][model] + reserve = world.design["reserves"][model] + admitted: dict[str, float] = {} + refused = False + # A household a stop cut short is under way until the stop. + ended = { + h: max(e, stopped_at) if h in cut_short else e for h, (_, e) in span.items() + } + for x in decisions: + sid, t = x["household"], x["time"] + if sid in world.no_output: + problems.append( + f"{model}/{sid}: a household with no scored output decided" + ) + finished = [h for h in admitted if h in ended and ended[h] <= t] + spend = sum(cost[h] for h in finished) + under = sum(1 for h in admitted if h not in finished) + 1 + ok = not refused and spend + under * reserve <= cap + cr.ADMISSION_SLACK + if x["decision"] != ("admit" if ok else "refuse"): + problems.append(f"{model}/{sid}: logged {x['decision']}, rule {ok}") + if abs(x["finished_spend"] - spend) > 1e-9 or x["under_way"] != under: + problems.append( + f"{model}/{sid}: spend {x['finished_spend']} vs {spend}" + ) + if x["lane"] != 1 + position[sid] % 2: + problems.append(f"{model}/{sid}: decided on the other lane") + if x["decision"] == "admit": + admitted[sid] = t + else: + refused = True + for sid, (s, _) in span.items(): + if sid not in admitted or s < admitted[sid]: + problems.append(f"{model}/{sid}: ran without, or before, its admission") + for lane in (1, 2): + expect = [ + s + for s in world.draw_order + if 1 + position[s] % 2 == lane and s not in world.no_output + ] + decided = [x["household"] for x in decisions if x["lane"] == lane] + if decided != expect[: len(decided)]: + problems.append(f"{model} lane {lane}: decisions skip a household") + if len(decided) < len(expect) and not (refused or stops): + problems.append(f"{model} lane {lane}: stopped deciding early") + if not stops and set( + a for a in admitted if 1 + position[a] % 2 == lane + ) - set(span): + problems.append(f"{model} lane {lane}: admitted and never run") + # Pauses. + resumes = sorted(e["time"] for e in events if e["event"] == "resume") + for x in lines: + if x["class"] != "operator": + continue + pauses = [ + e for e in events if e["event"] == "pause" and e["time"] >= x["end"] - 1 + ] + if not pauses: + problems.append( + f"{model}/{x['household']}: an operator failure, no pause" + ) + continue + until = next((t for t in resumes if t >= pauses[0]["time"]), math.inf) + if any(x["end"] < y["start"] < until for y in lines): + problems.append(f"{model}: an attempt started during a pause") + # The ceiling, over every model. + total = world.design["spent_before"] + sum( + cr.attempt_cost(r) for *_, r in all_attempts + ) + ceiling = world.design["overall_cap"] + cr.CEILING_MARGIN + if total >= ceiling and not all(ceiling_events.values()): + problems.append(f"spend {total} reached the ceiling and a model has no event") + for times in ceiling_events.values(): + for t in times: + if any(x["start"] > t for *_, x, _ in all_attempts): + problems.append("an attempt started after the ceiling") + # Conservation: the ceiling counted exactly the records' spend, and the + # spend of abandoned attempts after their deadline. + if abs(world.run.ceiling.spent_usd - total - late_total) > 1e-9: + problems.append( + f"the ceiling counted {world.run.ceiling.spent_usd}, records {total} " + f"and late spend {late_total}" + ) + problems += trigger_problems(world, all_attempts) + return problems + + +def trigger_problems(world: World, all_attempts) -> list[str]: + """Each stop rule's trigger has its stop, and each stop of those causes + its trigger: a harness failure and an abandoned attempt stop the model at + their end, before any other attempt starts; one inconclusive error ending + runs in a sixth household stops it once that household's pass is classed.""" + problems: list[str] = [] + for model in world.models: + events = world.events(model) + mine = [(sid, k, x, rec) for m, sid, _, k, x, rec in all_attempts if m == model] + triggers: list[tuple[str, float]] = [] + joined: dict[str, dict[str, float]] = {} # key -> household -> pass end + for sid, k, x, rec in mine: + if x["class"] == "harness": + triggers.append(("harness", x["end"])) + if str(rec.get("error") or "").startswith("AttemptDeadline"): + triggers.append(("deadline", x["end"])) + status = rec.get("status") + if x["class"] == "inconclusive" and status in ( + "provider_error", + "harness_error", + ): + key = f"{status}: {cr.error_class(rec) or rec.get('error')}" + end = max(y["end"] for s, n, y, _ in mine if s == sid and n == k) + households = joined.setdefault(key, {}) + households[sid] = min(households.get(sid, math.inf), end) + for households in joined.values(): + ends = sorted(households.values()) + if len(ends) > cr.INCONCLUSIVE_STOP: + triggers.append(("inconclusive", ends[cr.INCONCLUSIVE_STOP])) + stops = [e for e in events if e["event"] == "stop"] + for cause, t in triggers: + if not any( + e.get("cause") == cause and t <= e["time"] <= t + TRIGGER_BOUND + for e in stops + ): + problems.append(f"{model}: a {cause} trigger at {t!r} with no stop") + if cause != "inconclusive" and any(x["start"] > t for _, _, x, _ in mine): + problems.append(f"{model}: an attempt started after a {cause} stop") + for e in stops: + if e.get("cause") in ("harness", "deadline", "inconclusive") and not any( + cause == e["cause"] and t <= e["time"] <= t + TRIGGER_BOUND + for cause, t in triggers + ): + problems.append(f"{model}: a {e['cause']} stop with no trigger") + return problems + + +@pytest.fixture +def world(tmp_path, monkeypatch, fast): + """A fake run to plant failures in, then execute.""" + + def make(**kwargs): + return World(tmp_path, monkeypatch, **kwargs) + + return make + + +def test_an_untouched_run_runs_every_household_and_arm(world): + w = world().execute() + assert run_problems(w) == [] + for model in w.models: + labels = labels_of(model) + attempts = w.attempts(model) + assert len(attempts) == N_DRAW * len(labels) + assert {x["class"] for x in attempts} == {"ok"} + assert all( + x["decision"] == "admit" for x in w.lines(model, "admission-log.jsonl") + ) + manifests = list((w.runs() / model).glob("manifest-*.json")) + assert len(manifests) == 1 + m = json.loads(manifests[0].read_text()) + assert m["arms"] == { + label: { + "arm": cr.arm_string(label), + "features": sorted(cr.arm_profile(model, label).tool_features), + } + for label in labels + } + assert m["treatment_commit"] == cr.TREATMENT_COMMIT + assert m["cap_usd"] == 10.0 and m["reserve_usd"] == pytest.approx(0.21) + assert m["board_engine"] == f"policyengine-us {ENGINE}" + assert not (w.runs() / model / "in-flight").exists() or not any( + (w.runs() / model / "in-flight").iterdir() + ) + host = json.loads((w.runs() / "host" / "host.json").read_text()) + assert host["timezone"] == TZ and host["end"] > host["start"] + + +def test_households_alternate_lanes_in_draw_order(world): + w = world(models=("gpt-6-luna",)).execute() + lanes = {x["household"]: x["lane"] for x in w.attempts("gpt-6-luna")} + assert [lanes[s] for s in w.draw_order] == [1, 2] * (N_DRAW // 2) + + +def test_each_household_runs_its_arms_in_its_drawn_order(world): + w = world(models=("claude-haiku-5.5",)).execute() + master = cr.master_seed(w.design["frozen_sha256"]) + drawn = cr.orders(master, "claude-haiku-5.5", w.draw_order, cr.ARMS) + for sid in w.draw_order: + mine = sorted( + (x for x in w.attempts("claude-haiku-5.5") if x["household"] == sid), + key=lambda x: x["start"], + ) + assert [x["arm"] for x in mine] == drawn[sid] + + +def test_each_call_carries_its_arm_s_features(world): + calls = {"situation": "{}", "variables": ["snap"]} + model = "gpt-6-luna" + w = world(models=(model,)) + sid = w.draw_order[0] + w.provider.specs = {(model, label, sid, 1): {"calls": [calls]} for label in cr.ARMS} + w.execute() + messages = w.run.lanes[model].pool.messages + assert len(messages) == len(cr.ARMS) + raw = [m for m in messages if not isinstance(m, tuple)] + framed = [m for m in messages if isinstance(m, tuple)] + assert raw == [calls] # the tool v1 arm: as a featureless pool sends it + want = { + tuple(sorted(cr.arm_profile(model, label).tool_features)) + for label in cr.ARMS + if label != "pe" + } + assert {m[1] for m in framed} == want + assert all(m[0] == pilot.CALL_FRAME and m[2] == calls for m in framed) + # The worker reads each frame's features as the arm's. + for m in framed: + assert pilot.frame_features(m[1]) == frozenset(m[1]) + assert run_problems(w) == [] + + +def test_households_with_no_scored_output_are_never_decided(world): + model = "gemini-4-argon" + master = cr.master_seed(hashlib.sha256(PREREG.encode()).hexdigest()) + skipped = cr.draw(master, POOL, n=N_DRAW)[1] + w = world(models=(model,), no_output=(skipped,)).execute() + assert skipped not in { + x["household"] for x in w.lines(model, "admission-log.jsonl") + } + assert skipped not in {x["household"] for x in w.attempts(model)} + assert run_problems(w) == [] + + +def test_a_provider_error_is_rerun_after_the_household_s_first_pass(world): + model = "claude-haiku-5.5" + w = world(models=(model,)) + sid = w.draw_order[0] + master = cr.master_seed(w.design["frozen_sha256"]) + first = cr.orders(master, model, w.draw_order, cr.ARMS)[sid][0] + error = {"status": "provider_error", "error": "RateLimitError: slow down"} + w.provider.specs = {(model, first, sid, 1): error, (model, first, sid, 2): error} + w.execute() + mine = sorted( + (x for x in w.attempts(model) if x["household"] == sid), + key=lambda x: x["start"], + ) + assert [(x["attempt"], x["arm"]) for x in mine][-2:] == [(2, first), (3, first)] + assert [x["class"] for x in mine if x["arm"] == first] == ["provider"] * 2 + ["ok"] + final = json.loads((w.folder(model, first) / f"{sid}.json").read_text()) + assert [e["n"] for e in final["attempts"]] == [1, 2] + assert final["attempts"][0]["reason"] == "RateLimitError" + assert (w.folder(model, first) / "attempts" / f"{sid}-1.json").exists() + assert run_problems(w) == [] + + +def test_a_third_attempt_stands_whatever_its_class(world): + model = "gpt-6-sol" + w = world(models=(model,)) + sid = w.draw_order[1] + error = {"status": "provider_error", "error": "APIConnectionError: reset"} + w.provider.specs = {(model, "pe3", sid, n): error for n in (1, 2, 3)} + w.execute() + mine = [x for x in w.attempts(model) if x["household"] == sid and x["arm"] == "pe3"] + assert sorted((x["attempt"], x["action"]) for x in mine) == [ + (1, "rerun"), + (2, "rerun"), + (3, "stands"), + ] + assert run_problems(w) == [] + + +def test_host_trouble_during_an_attempt_reruns_it(world): + model = "gemini-3.5-flash-lite" + w = world(models=(model,)) + pressured, stalled = w.draw_order[0], w.draw_order[2] # both lane 1 + w.provider.specs = { + (model, "loo-flat", pressured, 1): {"pressure": True, "sleep": 0.05}, + (model, "pe", stalled, 1): {"stall": cr.HOST_LOG_GAP + 0.3}, + } + w.execute() + + def first(sid, label): + line = next( + x + for x in w.attempts(model) + if (x["household"], x["arm"], x["attempt"]) == (sid, label, 1) + ) + final = json.loads((w.folder(model, label) / f"{sid}.json").read_text()) + return line, final["attempts"][0] + + line, entry = first(pressured, "loo-flat") + assert line["class"] == entry["class"] == "host" and line["action"] == "rerun" + assert "memory pressure 2 at" in entry["reason"] + line, entry = first(stalled, "pe") + assert line["class"] == "host" and "host log gap" in entry["reason"] + assert run_problems(w) == [] + + +def test_a_guard_pause_over_an_attempt_reruns_it(world, monkeypatch): + # Guard lines have whole seconds and the fake brackets by another + # second: keep the lookahead longer than its possible two-second backdate. + monkeypatch.setattr(cr, "PRESSURE_WINDOW", 2.1) + model = "gpt-6-sol" + w = world(models=(model,)) + sid = w.draw_order[0] + w.provider.specs = {(model, "pe3", sid, 1): {"guard": True}} + w.execute() + line = next( + x + for x in w.attempts(model) + if (x["household"], x["arm"], x["attempt"]) == (sid, "pe3", 1) + ) + assert line["class"] == "host" + final = json.loads((w.folder(model, "pe3") / f"{sid}.json").read_text()) + assert final["attempts"][0]["reason"].startswith("guard pause: guard pause ") + archived = (w.runs() / "host" / "clamshell-guard.log").read_text() + assert "paused pids" in archived + assert run_problems(w) == [] + + +def test_an_operator_failure_pauses_the_model_until_resumed(world): + model = "gpt-6-luna" + w = world(models=(model, "claude-haiku-5.5")) + sid = w.draw_order[0] + w.provider.specs = { + (model, "pe3", sid, 1): { + "status": "provider_error", + "error": "AuthenticationError: bad key", + "turns": 0, + "resume_after": 0.4, + } + } + w.execute() + pauses, resumes = w.events(model, "pause"), w.events(model, "resume") + assert len(pauses) == 1 and len(resumes) == 1 + assert resumes[0]["reason"] == "fixed in a test" + started = [x["start"] for x in w.attempts(model)] + assert not [t for t in started if pauses[0]["time"] < t < resumes[0]["time"]] + assert resumes[0]["time"] - pauses[0]["time"] >= 0.35 + rerun = [ + x for x in w.attempts(model) if x["household"] == sid and x["arm"] == "pe3" + ] + assert [x["action"] for x in sorted(rerun, key=lambda x: x["attempt"])] == [ + "pause-rerun", + "stands", + ] + assert not w.events("claude-haiku-5.5", "pause") # another model runs on + assert list((w.runs() / model).glob("resume-*.json")) + assert run_problems(w) == [] + + +def test_a_request_class_on_the_first_request_stops_the_model(world): + model = "claude-opus-5.5" + w = world(models=(model, "gpt-6-sol")) + sid = w.draw_order[2] + w.provider.specs = { + (model, "pe", sid, 1): { + "status": "provider_error", + "error": "BadRequestError: bad tools", + "turns": 0, + } + } + w.execute() + stops = w.events(model, "stop") + assert len(stops) == 1 and "first request" in stops[0]["reason"] + assert stops[0]["cause"] == "harness" + assert not [x for x in w.attempts(model) if x["start"] > stops[0]["time"]] + assert len(w.attempts("gpt-6-sol")) == N_DRAW * 2 # the other model finishes + assert run_problems(w) == [] + + +def test_one_inconclusive_error_in_six_households_stops_the_model(world): + model = "gpt-6-luna" + w = world(models=(model,)) + error = {"status": "provider_error", "error": "ProviderEmpty: no choices"} + w.provider.specs = {(model, "pe", sid, 1): error for sid in w.draw_order} + w.execute() + stops = w.events(model, "stop") + assert len(stops) == 1 + assert ( + stops[0]["reason"] == "provider_error: ProviderEmpty ended runs in 6 households" + ) + assert stops[0]["cause"] == "inconclusive" + assert run_problems(w) == [] + + +def test_five_households_with_one_inconclusive_error_do_not_stop(world): + model = "gpt-6-luna" + w = world(models=(model,)) + error = {"status": "provider_error", "error": "ProviderEmpty: no choices"} + w.provider.specs = {(model, "pe", sid, 1): error for sid in w.draw_order[:5]} + w.execute() + assert not w.events(model, "stop") + assert len(w.attempts(model)) == N_DRAW * len(cr.ARMS) + assert run_problems(w) == [] + + +def test_a_refusal_ends_both_lanes_decisions(world): + model = "claude-haiku-5.5" + # Each household costs 7 arms x $0.01; the reserve is $0.21 per household. + w = world(models=(model,), caps={model: 0.5}).execute() + decisions = w.lines(model, "admission-log.jsonl") + refused = [x for x in decisions if x["decision"] == "refuse"] + after = decisions[decisions.index(refused[0]) :] + assert refused and all(x["decision"] == "refuse" for x in after) + admitted = {x["household"] for x in decisions if x["decision"] == "admit"} + assert {x["household"] for x in w.attempts(model)} == admitted + assert run_problems(w) == [] + + +def test_spend_never_stops_a_conversation_below_the_ceiling(world): + model = "gemini-4-argon" + w = world(models=(model,), caps={model: 0.05}, reserve=0.01) + sid = w.draw_order[0] + w.provider.specs = {(model, "pe", sid, 1): {"turns": 4, "cost": 0.5}} + w.execute() + # $2 on one arm, far past the cap: it ran to the end; later households + # were refused. + ran = [x for x in w.attempts(model) if x["household"] == sid and x["arm"] == "pe"] + assert ran[0]["status"] == "complete" + assert any(x["decision"] == "refuse" for x in w.lines(model, "admission-log.jsonl")) + assert run_problems(w) == [] + + +def test_the_hard_ceiling_stops_every_model(world): + w = world( + models=("claude-haiku-5.5", "gpt-6-sol", "gemini-4-argon"), + overall_cap=0.0, + spent_before=24.0, + ) + sid = w.draw_order[1] + # One long conversation crosses $25 while the others run. + w.provider.specs = { + ("gpt-6-sol", "pe3", sid, 1): {"turns": 3, "cost": 0.5, "sleep": 0.02} + } + w.execute() + events = {m: w.events(m, "ceiling") for m in w.models} + assert all(len(e) == 1 for e in events.values()) + crossed = events["gpt-6-sol"][0]["time"] + assert {e[0]["time"] for e in events.values()} == {crossed} + assert w.run.ceiling.spent_usd >= 25.0 + for m in w.models: + assert not [x for x in w.attempts(m) if x["start"] > crossed] + assert run_problems(w) == [] + + +def test_a_model_that_decides_nothing_still_has_both_logs(world): + """haiku's first attempt crosses the ceiling before gpt-6-sol's lanes, + held back, decide: gpt-6-sol's run log holds only the ceiling event and + its admission log is empty.""" + w = world( + models=("claude-haiku-5.5", "gpt-6-sol"), overall_cap=0.0, spent_before=24.5 + ) + sid = w.draw_order[0] + first = w.run.lanes["claude-haiku-5.5"].orders[sid][0] + w.provider.specs = {("claude-haiku-5.5", first, sid, 1): {"cost": 1.0}} + held = w.run.lanes["gpt-6-sol"] + admit = held.admit + + def late(sid, lane): + time.sleep(0.3) + return admit(sid, lane) + + held.admit = late + w.execute() + admission = w.runs() / "gpt-6-sol" / "admission-log.jsonl" + assert admission.exists() and admission.read_text() == "" + assert [ + x["event"] + for x in w.lines("gpt-6-sol") + if x["event"] not in ("setup-start", "setup-end") + ] == ["ceiling"] + assert run_problems(w) == [] + + +def test_a_conversation_under_way_at_the_ceiling_ends_budget_stop(world): + model = "gpt-6-luna" + w = world(models=(model,), overall_cap=0.0, spent_before=24.9) + sid = w.draw_order[0] + master = cr.master_seed(w.design["frozen_sha256"]) + first = cr.orders(master, model, w.draw_order, cr.ARMS)[sid][0] + w.provider.specs = {(model, first, sid, 1): {"turns": 5, "cost": 0.06}} + w.execute() + line = next( + x for x in w.attempts(model) if x["household"] == sid and x["arm"] == first + ) + assert line["status"] == "budget_stop" and line["class"] == "ceiling" + assert line["action"] == "stopped" + assert run_problems(w) == [] + + +def test_an_attempt_that_raises_is_saved_as_a_harness_error_record(world): + model = "claude-opus-5.5" + w = world(models=(model,)) + sid = w.draw_order[3] + w.provider.specs = {(model, "pe3", sid, 1): {"raise": True}} + w.execute() + replaced = json.loads( + (w.folder(model, "pe3") / "attempts" / f"{sid}-1.json").read_text() + ) + assert replaced["status"] == "harness_error" and replaced["turns"] == [] + assert replaced["error"] == "RuntimeError: a test raised" + assert replaced["tool_features"] == sorted( + cr.arm_profile(model, "pe3").tool_features + ) + line = next( + x + for x in w.attempts(model) + if x["household"] == sid and x["attempt"] == 1 and x["arm"] == "pe3" + ) + assert line["class"] == "none" and line["action"] == "rerun" + assert run_problems(w) == [] + + +def test_a_pool_that_lost_every_worker_is_started_again(world): + model = "gpt-6-sol" + starts = [] + + class Losing(FakePool): + def __init__(self, lanes): + super().__init__(lanes) + starts.append(self) + + def call(self, message): + self.lost = 2 # every worker gone after this call + return super().call(message) + + w = world(models=(model,), pool=Losing) + sid = w.draw_order[0] + w.provider.specs = {(model, "pe", sid, 1): {"calls": [{"situation": "{}"}]}} + w.execute() + assert len(starts) == 2 and starts[0].closed + setup = [e for e in w.events(model) if e.get("phase") == "restart"] + assert [e["event"] for e in setup] == ["setup-start", "setup-end"] + assert setup[0]["start"] == setup[0]["time"] == setup[1]["start"] + assert setup[1]["time"] >= setup[0]["time"] + assert setup[1]["outcome"] == "ready" + assert run_problems(w) == [] + + +def test_a_pool_that_cannot_start_again_stops_the_model(world, monkeypatch): + model = "gpt-6-sol" + made = [] + + def pool(lanes): + made.append(1) + return FakePool(lanes, fail=len(made) > 1) + + w = world(models=(model,), pool=pool) + sid = w.draw_order[0] + w.provider.specs = {(model, "pe", sid, 1): {"calls": [{"situation": "{}"}]}} + original = FakePool.call + + def losing(self, message): + self.lost = 2 + return original(self, message) + + monkeypatch.setattr(FakePool, "call", losing) + w.execute() + stops = w.events(model, "stop") + assert stops and "engine pool" in stops[0]["reason"] + assert stops[0]["cause"] == "pool" + setup = [e for e in w.events(model) if e.get("phase") == "restart"] + assert [e["event"] for e in setup] == ["setup-start", "setup-end"] + assert setup[1]["outcome"] == "failed" + assert run_problems(w) == [] + + +def test_a_household_a_stop_cuts_short_is_under_way_until_the_stop(world): + """Lane 1's first household loses the pool in its first arm, and the + restart waits while lane 2 finishes its household and + decides its next: the household lane 1 cut short has ended its last + attempt, but it is still under way, so its spend is not counted.""" + model = "gpt-6-sol" + made = [] + other_second, restarting, decided_after = ( + threading.Event(), + threading.Event(), + threading.Event(), + ) + + class Losing(FakePool): + def call(self, message): + assert other_second.wait(30) + self.lost = 2 + return super().call(message) + + def pool(lanes): + made.append(1) + if len(made) > 1: + restarting.set() + assert decided_after.wait(30) + raise RuntimeError("tool worker failed to start: a test") + return Losing(lanes) + + w = world(models=(model,), pool=pool) + cut, other, after = w.draw_order[0], w.draw_order[1], w.draw_order[3] + lanes = w.run.lanes[model] + orders, admit = lanes.orders, lanes.admit + + def in_second(lanes): + other_second.set() + assert restarting.wait(30) + + def admitted(sid, lane): + ok = admit(sid, lane) + if sid == after and ok: + decided_after.set() + # Keep this admitted household from racing the failed restart + # for the pool lock before lane 1 records its stop. + with lanes.cond: + assert lanes.cond.wait_for(lambda: lanes.stopped, timeout=30) + return ok + + lanes.admit = admitted + w.provider.specs = { + (model, orders[cut][0], cut, 1): {"calls": [{"situation": "{}"}]}, + (model, orders[other][1], other, 1): {"check": in_second}, + } + w.execute() + stop = w.events(model, "stop")[0]["time"] + decided = {x["household"]: x for x in w.lines(model, "admission-log.jsonl")} + assert decided[after]["time"] < stop # decided while the cut household waited + assert decided[after]["finished_spend"] == pytest.approx(2 * COST) # `other` only + assert decided[after]["under_way"] == 2 # `cut` and `after` + assert [x["arm"] for x in w.attempts(model) if x["household"] == cut] == [ + orders[cut][0] + ] + setup = [e for e in w.events(model) if e.get("phase") == "restart"] + assert [e["event"] for e in setup] == ["setup-start", "setup-end"] + assert setup[0]["start"] == setup[0]["time"] == setup[1]["start"] + assert setup[1]["time"] >= decided[after]["time"] + assert setup[1]["outcome"] == "failed" + assert run_problems(w) == [] + + +def test_an_interrupt_stops_every_model_and_lets_attempts_end(world): + w = world(models=("gpt-6-luna", "gpt-6-sol")) + sid = w.draw_order[0] + first = w.run.lanes["gpt-6-luna"].orders[sid][0] + + def interrupt_inside(lanes): + # The signal arrives during the household's first attempt, which + # finishes only once the main loop has stopped the lanes, so no + # timing on a loaded host lets the household's later arms start first. + w.run.interrupt(2, None) + until = time.time() + 30 + while not lanes.stopped and time.time() < until: + time.sleep(0.01) + + w.provider.specs = {("gpt-6-luna", first, sid, 1): {"check": interrupt_inside}} + w.execute() + for m in w.models: + stops = w.events(m, "stop") + assert len(stops) == 1 and stops[0]["reason"] == "operator stop (signal 2)" + assert stops[0]["cause"] == "interrupt" + assert not [x for x in w.attempts(m) if x["start"] > stops[0]["time"]] + luna = [x for x in w.attempts("gpt-6-luna") if x["household"] == sid] + assert luna and len(luna) < len(cr.ARMS) # cut by the stop + assert run_problems(w) == [] + + +def test_a_failed_explain_trace_is_inconclusive(world): + """The explain feature's trace catches its own errors and returns them + under `explanations`: a MemoryError there is the host's, not a miss.""" + + class Explaining(FakePool): + def call(self, message): + self.messages.append(message) + return { + "results": {"snap": {"values": {"spm": 1.0}}}, + "explanations": {"snap": {"error": "MemoryError: a test"}}, + }, 0.0 + + model = "gpt-6-luna" + w = world(models=(model,), pool=Explaining) + sid = w.draw_order[0] + w.provider.specs = {(model, "pe3", sid, 1): {"calls": [{"situation": "{}"}]}} + w.execute() + line = next( + x for x in w.attempts(model) if x["household"] == sid and x["arm"] == "pe3" + ) + assert line["class"] == "inconclusive" and line["action"] == "stands" + assert run_problems(w) == [] + + +def test_no_household_is_decided_after_the_crossing(world): + """The crossing lands between the lanes' halt check and the decision: the + decision's time is taken under the ceiling's lock, after a second look.""" + w = world(models=("gpt-6-luna",)) + lanes = w.run.lanes["gpt-6-luna"] + halted = lanes.halted + + def crossing(): + result = halted() + if not result: + w.run.ceiling.add(1e6) # another lane's spend, just after the check + return result + + lanes.halted = crossing + decided = lanes.admit(w.draw_order[0], 1) + lines = w.lines("gpt-6-luna", "admission-log.jsonl") + assert decided is False and lines == [] + + +@pytest.mark.parametrize( + "when", ["before the run", "before the run, misdated", "during the pause"] +) +def test_a_resume_written_before_the_pause_is_ignored(world, when, monkeypatch): + """A resume left from before a pause would end that pause unseen: it is + set aside, and the pause holds until a resume written during it. One + found while no pause holds is set aside at once, whatever time it + states; one found during the pause but stamped before it is set aside + too.""" + model = "gpt-6-luna" + w = world(models=(model,)) + sid = w.draw_order[0] + folder = w.runs() / model + folder.mkdir(parents=True) + stale = {"time": time.time(), "note": "stale"} + if when.startswith("before the run"): + if when.endswith("misdated"): + stale["time"] += 3600.0 # a writer whose clock runs ahead + cr.write_json(folder / "RESUME.json", stale) + + lanes, watch = w.run.lanes[model], w.run.watch + planted, fresh = False, False + + def supervised(*args, **kwargs): + nonlocal planted, fresh + with lanes.cond: + if when == "during the pause" and lanes.paused and not planted: + cr.write_json(folder / "RESUME.json", stale) + planted = True + watch(*args, **kwargs) + with lanes.cond: + if ( + lanes.paused + and list(folder.glob("resume-ignored-*.json")) + and not fresh + ): + # The stale note has been read and archived before its + # replacement exists; the next watch sees only the fresh one. + cr.write_json( + folder / "RESUME.json", + {"time": cr.clock(), "note": "fixed in a test"}, + ) + fresh = True + + monkeypatch.setattr(w.run, "watch", supervised) + + w.provider.specs = { + (model, "pe3", sid, 1): { + "status": "provider_error", + "error": "AuthenticationError: bad key", + "turns": 0, + } + } + w.execute() + pauses, resumes = w.events(model, "pause"), w.events(model, "resume") + assert len(pauses) == 1 and len(resumes) == 1 + assert resumes[0]["reason"] == "fixed in a test" + assert resumes[0]["time"] >= pauses[0]["time"] + ignored = list(folder.glob("resume-ignored-*.json")) + assert len(ignored) == 1 and json.loads(ignored[0].read_text()) == stale + assert run_problems(w) == [] + + +def test_the_signal_handler_only_notes_the_signal(world, monkeypatch): + """The handler runs on the main thread between any two of its bytecodes, + perhaps holding a lock it would need: it takes none. A second signal + exits at once.""" + w = world(models=("gpt-6-luna",)) + lanes = w.run.lanes["gpt-6-luna"] + exits = [] + monkeypatch.setattr(os, "_exit", lambda code: exits.append(code)) + with w.run._say_lock, lanes.cond, lanes._log_lock: + w.run.interrupt(2, None) # would deadlock if it took any of these + assert w.run.signalled == 2 and not lanes.stopped + assert w.lines("gpt-6-luna") == [] + w.run.interrupt(15, None) + assert exits == [130] + + +def test_an_attempt_that_raises_after_spending_keeps_its_cost(world): + model = "claude-haiku-5.5" + w = world(models=(model,)) + sid = w.draw_order[0] + first = w.run.lanes[model].orders[sid][0] + w.provider.specs = { + (model, first, sid, 1): {"turns": 2, "cost": 0.03, "raise_after": True} + } + w.execute() + replaced = json.loads( + (w.folder(model, first) / "attempts" / f"{sid}-1.json").read_text() + ) + assert replaced["status"] == "harness_error" and replaced["turns"] == [] + assert replaced["totals"]["cost_usd"] == pytest.approx(0.06) + assert run_problems(w) == [] # the ceiling counted it, and so do the records + + +def test_an_attempt_past_its_deadline_is_abandoned_and_stops_the_model( + world, monkeypatch +): + """The conversation runs on in its own thread; at the deadline its record + is a harness error with the spend so far, the model stops, and the + conversation ends `budget_stop` at its next turn. Its spend after the + deadline is a late-cost event.""" + monkeypatch.setattr(cr, "ATTEMPT_DEADLINE", 0.3) + model = "gpt-6-luna" + w = world(models=(model, "claude-haiku-5.5")) + sid = w.draw_order[0] + first = w.run.lanes[model].orders[sid][0] + w.provider.specs = { + (model, first, sid, 1): {"turns": 4, "cost": 0.01, "sleep": 0.2}, + **{ + ("claude-haiku-5.5", label, s, 1): {"sleep": 0.05} + for label in cr.ARMS + for s in w.draw_order[:2] + }, + } + w.execute() + line = next( + x for x in w.attempts(model) if x["household"] == sid and x["arm"] == first + ) + final = json.loads((w.folder(model, first) / f"{sid}.json").read_text()) + assert final["error"].startswith("AttemptDeadline: past the attempt deadline") + assert final["totals"]["cost_usd"] == pytest.approx(0.01) # turn 1 only + assert line["class"] == "none" # its rerun is cut short by the stop + stops = w.events(model, "stop") + assert len(stops) == 1 and stops[0]["cause"] == "deadline" + late = w.events(model, "late-cost") + assert len(late) == 1 and late[0]["cost_usd"] == pytest.approx(0.01) + assert not [x for x in w.attempts(model) if x["start"] > line["end"]] + assert len(w.attempts("claude-haiku-5.5")) == N_DRAW * len(cr.ARMS) + assert run_problems(w) == [] + + +def test_a_sampler_whose_samples_fail_stops_every_model(world): + models = ("gpt-6-luna", "gpt-6-sol") + w = world(models=models) + w.provider.specs = { + (m, label, sid, 1): {"sleep": 0.1} + for m in models + for label in labels_of(m) + for sid in w.draw_order + } + threading.Timer(0.3, lambda: setattr(w.readers, "pressure", None)).start() + w.execute() + for m in models: + stops = w.events(m, "stop") + assert len(stops) == 1 and stops[0]["cause"] == "sampler" + assert "samples failing since" in stops[0]["reason"] + assert run_problems(w) == [] + + +def failing_settle(lanes, sid, times): + """Lanes.settle, failing its first `times` calls for household `sid`.""" + original, calls = lanes.settle, [] + + def settle(at, done): + if at == sid and len(calls) < times: + calls.append(at) + raise RuntimeError("a test's runner defect") + return original(at, done) + + lanes.settle = settle + return calls + + +@pytest.mark.parametrize("times", [1, 2]) +def test_a_runner_error_stops_every_model_and_writes_what_ended(world, times): + """A runner error in a household's pass: every model stops, and that + household's ended attempts are classed, or `unsettled` if classing fails + again, and written with their lines before the lane ends.""" + models = ("gpt-6-luna", "gpt-6-sol") + w = world(models=models) + sid = w.draw_order[2] + failing_settle(w.run.lanes["gpt-6-luna"], sid, times) + w.execute() + for m in models: + stops = w.events(m, "stop") + assert len(stops) == 1 and stops[0]["cause"] == "runner-error" + mine = [x for x in w.attempts("gpt-6-luna") if x["household"] == sid] + assert len(mine) == len(cr.ARMS) # the pass ended before the error + assert {x["class"] for x in mine} == ({"ok"} if times == 1 else {"unsettled"}) + for label in cr.ARMS: + assert (w.folder("gpt-6-luna", label) / f"{sid}.json").exists() + assert run_problems(w) == [] + + +def test_each_attempt_is_on_disk_before_the_next_starts(world, monkeypatch): + """An ended attempt is written, synced, before its household's next + attempt starts; a replaced one is saved, with its line, before its rerun + starts.""" + model = "claude-haiku-5.5" + w = world(models=(model,)) + sid = w.draw_order[0] + order = w.run.lanes[model].orders[sid] + import fcntl + + if not hasattr(fcntl, "F_GETPATH"): + pytest.skip("no F_GETPATH: the paths synced cannot be told") + synced: list[str] = [] + real = os.fsync + + def fsync(fd): + path = fcntl.fcntl(fd, fcntl.F_GETPATH, bytes(1024)) + synced.append(path.rstrip(b"\0").decode()) + return real(fd) + + monkeypatch.setattr(os, "fsync", fsync) + seen = {} + + def before_second(lanes): + seen["in-flight"] = ( + lanes.folder / "in-flight" / sid / f"{order[0]}-1.json" + ).exists() + + def before_rerun(lanes): + seen["replaced"] = ( + w.folder(model, order[1]) / "attempts" / f"{sid}-1.json" + ).exists() + seen["line"] = any( + x["household"] == sid and x["arm"] == order[1] and x["attempt"] == 1 + for x in w.attempts(model) + ) + + error = {"status": "provider_error", "error": "RateLimitError: slow"} + w.provider.specs = { + (model, order[1], sid, 1): {**error, "check": before_second}, + (model, order[1], sid, 2): {"check": before_rerun}, + } + w.execute() + assert seen == {"in-flight": True, "replaced": True, "line": True} + # Each whole-file write is synced before its rename. + assert any(f"/in-flight/{sid}/.{order[0]}-1.json.tmp" in p for p in synced) + assert any(f"/attempts/.{sid}-1.json.tmp" in p for p in synced) + assert run_problems(w) == [] + + +def test_the_worker_count_is_the_design_s(tmp_path, capsys): + design = tmp_path / "design.json" + design.write_text(json.dumps({"runs": str(tmp_path / "runs"), "workers": 2})) + assert cr.main(["run", str(design), "--workers", "3"]) == 1 + assert "the design runs 2 engine workers" in capsys.readouterr().out + + +def test_the_checker_catches_a_runner_that_ignores_a_harness_failure( + world, monkeypatch +): + """trigger_problems is not vacuous: a runner whose harness failure does + not stop the model fails it.""" + model = "claude-opus-5.5" + w = world(models=(model,)) + sid = w.draw_order[0] + w.provider.specs = { + (model, "pe", sid, 1): { + "status": "provider_error", + "error": "BadRequestError: bad tools", + "turns": 0, + } + } + lanes = w.run.lanes[model] + real = lanes.event + + def no_stop(kind, reason, at=None, cause=None, **extra): + if cause == "harness": + lanes.stopped = False # the fault: the stop is not kept + return + real(kind, reason, at, cause, **extra) + + lanes.event = no_stop + w.execute() + problems = run_problems(w) + assert any("a harness trigger" in p and "with no stop" in p for p in problems) + assert any("an attempt started after a harness stop" in p for p in problems) + + +def test_the_checker_catches_an_edited_log_line(world): + w = world(models=("gpt-6-sol",)).execute() + path = w.runs() / "gpt-6-sol" / "admission-log.jsonl" + lines = path.read_text().splitlines() + edited = json.loads(lines[1]) + edited["finished_spend"] += 1.0 + path.write_text("\n".join([lines[0], json.dumps(edited)] + lines[2:]) + "\n") + problems = run_problems(w) + assert any("its prev is not the line before's hash" in p for p in problems) + # An interior edit need not change a later anchor's head: its successor + # still has its old bytes. A tail edit separately exercises the anchor. + edited = json.loads(lines[-1]) + edited["finished_spend"] += 1.0 + path.write_text("\n".join(lines[:-1] + [json.dumps(edited)]) + "\n") + problems = run_problems(w) + assert any("is not the log's head" in p for p in problems) + + +KINDS = { + "ok": {}, + "provider": {"status": "provider_error", "error": "RateLimitError: slow"}, + "none": {"status": "harness_error", "error": "RuntimeError: lost", "turns": 0}, + "model": {"status": "provider_error", "error": "BadRequestError: long"}, + "inconclusive": {"status": "provider_error", "error": "ProviderEmpty: none"}, + "pressure": {"pressure": True, "sleep": 0.04}, + "incomplete": {"status": "incomplete"}, + "harness": {"status": "provider_error", "error": "BadRequestError: x", "turns": 0}, + "costly": {"turns": 3, "cost": 0.2}, +} + + +@settings( + max_examples=12, + deadline=None, + suppress_health_check=[HealthCheck.function_scoped_fixture, HealthCheck.too_slow], +) +@given( + planted=st.lists( + st.tuples( + st.sampled_from(("claude-haiku-5.5", "gpt-6-sol")), + st.sampled_from(cr.FRONTIER_ARMS), + st.integers(0, N_DRAW - 1), + st.integers(1, 3), + st.sampled_from(sorted(KINDS)), + ), + max_size=10, + ), + cap=st.sampled_from([0.3, 0.6, 10.0]), + spent_before=st.sampled_from([0.0, 24.0]), +) +def test_every_run_keeps_the_run_procedure( + tmp_path_factory, fast, planted, cap, spent_before +): + """Whatever fails, and wherever spend lands, the records follow every rule.""" + tmp = tmp_path_factory.mktemp("run") + mp = pytest.MonkeyPatch() + try: + models = ("claude-haiku-5.5", "gpt-6-sol") + w = World( + tmp, + mp, + models=models, + caps={m: cap for m in models}, + overall_cap=0.0, + spent_before=spent_before, + ) + w.provider.specs = { + (model, label, w.draw_order[i], n): KINDS[kind] + for model, label, i, n, kind in planted + } + w.execute() + assert run_problems(w) == [] + finally: + mp.undo() + + +def test_the_checker_catches_a_planted_fault(world): + """run_problems is not vacuous: an edited log line fails it.""" + w = world(models=("gpt-6-sol",)).execute() + path = w.runs() / "gpt-6-sol" / "run-log.jsonl" + lines = path.read_text().splitlines() + at = next(i for i, line in enumerate(lines) if "event" not in json.loads(line)) + first = json.loads(lines[at]) + first["class"] = "provider" + lines[at] = json.dumps(first) + path.write_text("\n".join(lines) + "\n") + assert any("recomputed" in p for p in run_problems(w)) + + +# ---------------------------------------------------------------- before a run + + +def test_the_preflight_names_a_missing_field(): + assert cr.preflight({}, cr.CHEAP) == [f"the design has no {', '.join(cr.REQUIRED)}"] + + +def complete_preflight_design(w, tmp_path): + """Each calculator preflight starts after synthetic standing no-tools finals.""" + pool = tmp_path / "pool.json" + pool.write_text(json.dumps([{"id": s} for s in POOL])) + design = dict( + w.design, + eligible_pool={"path": str(pool), "sha256": cr.sha256_file(pool)}, + treatment_harness=str(cr.ROOT), + run_commit="0" * 40, + no_tools={ + "runs": str(tmp_path / "no-tools"), + "folder": "none", + "stage": "confirm", + }, + ) + for model in cr.CHEAP: + for sid in design["draw_order"]: + cr.write_json( + Path(design["no_tools"]["runs"]) + / model + / "none/confirm/households" + / f"{sid}.json", + { + "scenario_id": sid, + "status": "complete", + "turns": [{}], + "totals": {"cost_usd": 0.0}, + "attempts": [], + }, + ) + return design + + +def test_the_preflight_refuses_a_changed_draw_and_a_dirty_runner( + world, tmp_path, monkeypatch +): + w = world(models=("gpt-6-luna",)) + design = complete_preflight_design(w, tmp_path) + design["draw_order"] = list(reversed(w.draw_order)) + monkeypatch.setattr(cr, "host_power", lambda: (True, False)) + problems = cr.preflight(design, ("gpt-6-luna",)) + text = "\n".join(problems) + assert "the draw, recomputed" in text + assert "not the run commit, clean" in text + assert "lid open False" in text + design["draw_order"] = w.draw_order + assert "the draw" not in "\n".join(cr.preflight(design, ("gpt-6-luna",))) + assert not any( + p.startswith("no-tools") for p in cr.preflight(design, ("gpt-6-luna",)) + ) + + +def test_the_preflight_refuses_a_runs_folder_with_records(world, tmp_path): + w = world(models=("gpt-6-luna",)).execute() + design = complete_preflight_design(w, tmp_path) + text = "\n".join(cr.preflight(design, ("gpt-6-luna",))) + assert "already holds records" in text and "already holds a host log" in text + + +@pytest.mark.parametrize( + "fault,expected", + [ + ("missing", "missing"), + ("harness", "stop"), + ("ceiling", "stopped"), + ("history", "attempts list"), + ], +) +def test_preflight_refuses_an_unfinished_no_tools_stage( + world, tmp_path, fault, expected +): + w = world(models=(cr.CHEAP[0],)) + design = complete_preflight_design(w, tmp_path) + model, sid = cr.CHEAP[-1], w.draw_order[-1] + path = ( + Path(design["no_tools"]["runs"]) + / model + / "none/confirm/households" + / f"{sid}.json" + ) + payload = json.loads(path.read_text()) + if fault == "missing": + path.unlink() + else: + if fault == "history": + payload.pop("attempts") + else: + payload.update( + status="budget_stop" if fault == "ceiling" else "provider_error", + error="BadRequestError" if fault == "harness" else None, + turns=[], + ) + path.write_text(json.dumps(payload)) + text = "\n".join(cr.preflight(design, (cr.CHEAP[0],))) + assert "no-tools" in text and model in text and sid in text and expected in text + + +@pytest.mark.parametrize("relationship", ["equal", "inside", "contains"]) +def test_preflight_refuses_overlapping_no_tools_and_calculator_roots( + world, tmp_path, relationship +): + w = world(models=(cr.CHEAP[0],)) + design = complete_preflight_design(w, tmp_path) + calculator = Path(design["runs"]) + design["no_tools"]["runs"] = str( + { + "equal": calculator, + "inside": calculator / "no-tools", + "contains": calculator.parent, + }[relationship] + ) + assert any("roots overlap" in p for p in cr.preflight(design, (cr.CHEAP[0],))) + + +def test_resume_writes_the_operator_s_note(tmp_path): + design = tmp_path / "design.json" + design.write_text(json.dumps({"runs": str(tmp_path / "runs")})) + assert cr.main(["resume", str(design), "gpt-6-luna", "--note", "key rotated"]) == 0 + note = json.loads((tmp_path / "runs" / "gpt-6-luna" / "RESUME.json").read_text()) + assert note["note"] == "key rotated" + + +# ---------------------------------------------------------------- the harness + + +def chat_response(calls): + from types import SimpleNamespace + + message = SimpleNamespace( + role="assistant", content=None, tool_calls=calls, function_call=None + ) + usage = SimpleNamespace( + prompt_tokens=1000, + completion_tokens=200, + total_tokens=1200, + reasoning_tokens=0, + prompt_tokens_details=SimpleNamespace(cached_tokens=0), + completion_tokens_details=None, + ) + return SimpleNamespace( + choices=[SimpleNamespace(message=message, finish_reason="tool_calls")], + usage=usage, + model="claude-haiku-5-5", + ) + + +def chat_call(name, arguments, call_id): + from types import SimpleNamespace + + return SimpleNamespace( + id=call_id, + type="function", + function=SimpleNamespace(name=name, arguments=json.dumps(arguments)), + ) + + +def stateless_model(**kwargs): + """A tool-contract model: one calculation, then its answers. It reads the + conversation so far, so the two lanes can share it.""" + if not any(m.get("role") == "tool" for m in kwargs["messages"]): + arguments = {"situation": json.dumps({"people": {}}), "variables": ["snap"]} + return chat_response([chat_call(pilot.TOOL_NAME, arguments, "c1")]) + outputs = {v: {"value": 0, "explanation": "value = 0"} for v in VARIABLES} + return chat_response([chat_call("submit_outputs", {"outputs": outputs}, "s1")]) + + +def stateless_responses_model(**kwargs): + """A Responses tool-contract model: calculate, then submit the answers.""" + from types import SimpleNamespace + + if "previous_response_id" not in kwargs: + name, call_id = pilot.TOOL_NAME, "c1" + arguments = {"situation": json.dumps({"people": {}}), "variables": ["snap"]} + else: + name, call_id = "submit_outputs", "s1" + arguments = { + "outputs": {v: {"value": 0, "explanation": "value = 0"} for v in VARIABLES} + } + return SimpleNamespace( + id=f"resp_{call_id}", + output=[ + SimpleNamespace( + type="function_call", + id=f"fc_{call_id}", + call_id=call_id, + name=name, + arguments=json.dumps(arguments), + status="completed", + ) + ], + output_text=None, + status="completed", + incomplete_details=None, + usage=SimpleNamespace( + input_tokens=1000, + output_tokens=200, + total_tokens=1200, + input_tokens_details=SimpleNamespace(cached_tokens=0), + output_tokens_details=SimpleNamespace(reasoning_tokens=0), + ), + model=kwargs["model"], + ) + + +def stateless_json_model(**kwargs): + """A Gemini JSON-contract model: calculate, then answer in JSON text.""" + if not any(m.get("role") == "tool" for m in kwargs["messages"]): + response = stateless_model(**kwargs) + response.model = kwargs["model"] + return response + response = chat_response([]) + response.model = kwargs["model"] + response.choices[0].finish_reason = "stop" + response.choices[0].message.content = json.dumps( + {v: {"value": 0, "explanation": "value = 0"} for v in VARIABLES} + ) + return response + + +@pytest.mark.parametrize( + "model, completion", + [ + ("claude-haiku-5.5", stateless_model), + ("gpt-6-luna", stateless_responses_model), + ("gemini-3.1-pro-preview", stateless_json_model), + ], +) +def test_the_harness_conversation_runs_under_the_runner(world, model, completion): + """Each API and answer contract completes real harness conversations in + both runner lanes, with the registered feature frame for every arm. + + The confirmatory roster's Geminis use tools. The older board profile + covers the harness's Gemini JSON path in a fake design, without changing + the production roster or any model's answer contract.""" + w = world(models=(model,)) + w.run.converse = cr.converse_with_harness + w.run.completion_for = lambda profile: completion + w.execute() + labels = labels_of(model) + attempts = w.attempts(model) + assert len(attempts) == N_DRAW * len(labels) + assert {x["status"] for x in attempts} == {"complete"} + messages = w.run.lanes[model].pool.messages + assert len(messages) == N_DRAW * len(labels) # one calculation per attempt + frames = [m for m in messages if isinstance(m, tuple)] + assert len(frames) == N_DRAW * (len(labels) - 1) # every arm but pe + sid = w.draw_order[0] + label = "loo-names" if "loo-names" in labels else "pe3" + rec = json.loads((w.folder(model, label) / f"{sid}.json").read_text()) + profile = cr.arm_profile(model, label) + assert rec["arm"] == cr.arm_string(label) and rec["attempts"] == [] + assert rec["tool_features"] == sorted(profile.tool_features) + assert rec["predictions"] == {v: 0.0 for v in VARIABLES} + assert run_problems(w) == [] + + +@pytest.mark.parametrize( + "model, completion, api, contract, label", + [ + (model, completion, api, contract, label) + for model, completion, api, contract in [ + ("gpt-6-luna", stateless_responses_model, "responses", "tool"), + ("gemini-3.1-pro-preview", stateless_json_model, "chat", "json"), + ] + for label in labels_of(model) + ], +) +def test_the_runner_sends_the_treatment_conversation( + world, label, model, completion, api, contract +): + """Compare every provider request and calculation against the unchanged + treatment harness at 6b00a6f0, including the tool-result continuation. + + Gemini 3.1's board profile exercises JSON; both confirmatory Geminis use + the tool contract. No contract or model card is replaced for this test.""" + w = world(models=(model,)) + lanes, sid = w.run.lanes[model], w.draw_order[0] + requests, calculations = [], [] + + def provider(**kwargs): + """Keep each request before the conversation can extend its messages.""" + requests.append(copy.deepcopy(kwargs)) + return completion(**kwargs) + + def tool(arguments): + """Keep exactly what the conversation sends to the calculator.""" + calculations.append(arguments) + return {"results": {"snap": {"values": {"spm": 1.0}}}}, 0.0 + + lanes.completion = provider + record = cr.converse_with_harness( + lanes, sid, label, tool, cr.AttemptSpend(w.run.ceiling) + ) + sent, called = requests[:], calculations[:] + requests.clear() + calculations.clear() + profile = pilot.model_profile( + model, arm=cr.arm_string(label), prompt_version="v2-pilot" + ) + treatment = pilot.run_household( + w.board["scenarios"][sid], + w.board["variables"][sid], + tool, + provider, + pilot.Spend(100.0), + profile=profile, + ) + assert record["api"] == treatment["api"] == api + assert record["contract"] == treatment["contract"] == contract + assert record["status"] == treatment["status"] == "complete" + assert record["predictions"] == treatment["predictions"] == { + v: 0.0 for v in VARIABLES + } + assert len(sent) == len(requests) == 2 + assert sent == requests and called == calculations and len(called) == 1 + assert record["messages"] == treatment["messages"] + first, second = sent + if api == "responses": + assert "messages" not in first and "previous_response_id" not in first + assert first["tool_choice"] == "required" + assert [t["name"] for t in first["tools"]] == [ + pilot.TOOL_NAME, + "submit_outputs", + ] + assert "max_output_tokens" in first + assert second["previous_response_id"] == "resp_c1" + assert second["input"] == [ + { + "type": "function_call_output", + "call_id": "c1", + "output": json.dumps({"results": {"snap": {"values": {"spm": 1.0}}}}), + } + ] + else: + assert "input" not in first and first["tool_choice"] == "auto" + assert [t["function"]["name"] for t in first["tools"]] == [pilot.TOOL_NAME] + assert second["messages"][-1]["role"] == "tool" + assert second["messages"][-1]["tool_call_id"] == "c1" + + +def test_the_ceiling_ends_a_harness_conversation_at_its_next_turn(world): + model = "claude-haiku-5.5" + w = world(models=(model,), overall_cap=0.0, spent_before=25.0 - 1e-9) + w.run.converse = cr.converse_with_harness + w.run.completion_for = lambda profile: stateless_model + w.execute() + # The first turns cross the ceiling; each conversation under way ends + # budget_stop before its next request, and no attempt starts after. + attempts = w.attempts(model) + assert attempts and {x["status"] for x in attempts} == {"budget_stop"} + assert len(attempts) <= 2 # one per lane at most + assert len(w.events(model, "ceiling")) == 1 + assert run_problems(w) == [] + + +def test_a_reader_that_keeps_raising_starts_the_sampler_silence( + tmp_path, fast, monkeypatch +): + readers = Readers() + host = readers.host(tmp_path) + host._stop.set() + host._thread.join() + now, reads = [time.time()], [] + + def pressure(): + reads.append(now[0]) + raise RuntimeError("pressure reader failed") + + class Ticks: + def wait(self, timeout): + now[0] += cr.SAMPLER_SILENCE + 1.0 + return len(reads) == 3 + + # Run the real sampling loop across three failures with a controlled + # clock; no scheduling or sleep decides whether its silence has elapsed. + with monkeypatch.context() as patch: + patch.setattr(cr.time, "time", lambda: now[0]) + patch.setattr(host, "_stop", Ticks()) + patch.setattr(host, "_read_pressure", pressure) + patch.setattr(host._thread, "is_alive", lambda: True) + host._loop() + assert len(reads) == 3 + assert host.failing_since == reads[0] + assert "samples failing since" in host.dead() + assert "RuntimeError: pressure reader failed" in host.dead() + patch.setattr(host, "_read_pressure", lambda: 1) + host.sample() + assert host.failing_since is None and host.failure is None + assert host.dead() is None + host.close() + + +def test_a_second_lane_s_authentication_failure_invalidates_a_resume( + world, monkeypatch +): + model = "gpt-6-luna" + w = world(models=(model,)) + lanes = w.run.lanes[model] + first, second = w.draw_order[:2] + lanes.spent.update({first: 0.0, second: 0.0}) + now = [time.time()] + + def tick(): + now[0] += 1.0 + return now[0] + + monkeypatch.setattr(cr, "clock", tick) + auth = record("provider_error", "AuthenticationError: bad key", turns=0) + lanes.end_attempt(first, "pe3", 1, now[0], auth, False) + note = {"time": lanes.paused_at, "note": "first key fixed"} + cr.write_json(lanes.folder / "RESUME.json", note) + resume = lanes.resume + + def second_failure(*args, **kwargs): + # The other lane finishes after watch reads the note and immediately + # before resume validates it. The second pause requires its own note. + lanes.end_attempt(second, "pe3", 1, now[0], auth, False) + return resume(*args, **kwargs) + + monkeypatch.setattr(lanes, "resume", second_failure) + w.run.watch(anchor=False) + assert lanes.paused and lanes.paused_at > note["time"] + assert len(w.events(model, "pause")) == 2 + assert w.events(model, "resume") == [] + assert list(lanes.folder.glob("resume-ignored-*.json")) + monkeypatch.setattr(lanes, "resume", resume) + cr.write_json( + lanes.folder / "RESUME.json", + {"time": lanes.paused_at, "note": "both keys fixed"}, + ) + w.run.watch(anchor=False) + assert not lanes.paused + assert [event["reason"] for event in w.events(model, "resume")] == [ + "both keys fixed" + ] + + +def test_an_interrupt_during_setup_starts_no_pool_or_lane(world, monkeypatch): + started = [] + w = world( + models=("gpt-6-luna", "gpt-6-sol"), + pool=lambda lanes: started.append((lanes.model, "pool")), + ) + + def completion(profile): + if w.run.signalled is None: + w.run.interrupt(2, None) + + w.run.completion_for = completion + for model, lanes in w.run.lanes.items(): + monkeypatch.setattr( + lanes, "lane", lambda lane, m=model: started.append((m, lane)) + ) + w.execute() + assert started == [] and w.provider.count == {} + for model in w.models: + assert [e["cause"] for e in w.events(model, "stop")] == ["interrupt"] + setup = [e for e in w.events(model) if e.get("phase") == "startup"] + assert [e["event"] for e in setup] == ["setup-start", "setup-end"] + assert setup[0]["start"] == setup[0]["time"] == setup[1]["start"] + stop = w.events(model, "stop")[0]["time"] + assert setup[0]["time"] <= stop <= setup[1]["time"] + assert setup[1]["outcome"] == "stopped" + assert run_problems(w) == [] + + +def test_a_slow_pool_start_is_polled_and_anchored_before_it_finishes( + world, monkeypatch +): + model = "gpt-6-sol" + entered, release, finished = threading.Event(), threading.Event(), threading.Event() + polls, anchors = [], [] + + def pool(lanes): + entered.set() + # Readiness depends on supervision, never on which sleep wins. + assert release.wait(10), "startup was not supervised" + finished.set() + return FakePool(lanes) + + w = world(models=(model,), pool=pool) + watch, anchor = w.run.watch, w.run.anchor + + def supervised(*args, **kwargs): + watch(*args, **kwargs) + if entered.is_set() and not finished.is_set(): + polls.append(cr.clock()) + if len(polls) == 3: + release.set() + + def anchored(*args, **kwargs): + if entered.is_set() and not finished.is_set(): + anchors.append(cr.clock()) + return anchor(*args, **kwargs) + + monkeypatch.setattr(w.run, "watch", supervised) + monkeypatch.setattr(w.run, "anchor", anchored) + w.execute() + assert len(polls) >= 3 and anchors + setup = [e for e in w.events(model) if e.get("phase") == "startup"] + assert setup[0]["time"] <= min(polls + anchors) + assert max(polls + anchors) <= setup[1]["time"] + assert setup[1]["outcome"] == "ready" + assert all(a["start"] >= setup[1]["time"] for a in w.attempts(model)) + assert run_problems(w) == [] + + +def test_an_interrupt_during_pool_start_is_recorded_before_readiness( + world, monkeypatch +): + model = "gpt-6-sol" + stopped = threading.Event() + started = [] + + def pool(lanes): + w.run.interrupt(2, None) + assert stopped.wait(10), "the setup interrupt was not processed" + return FakePool(lanes) + + w = world(models=(model,), pool=pool) + watch = w.run.watch + + def supervised(*args, **kwargs): + watch(*args, **kwargs) + if w.run.lanes[model].stopped: + stopped.set() + + monkeypatch.setattr(w.run, "watch", supervised) + monkeypatch.setattr(w.run.lanes[model], "lane", started.append) + w.execute() + assert stopped.is_set() and started == [] + assert [e["cause"] for e in w.events(model, "stop")] == ["interrupt"] + assert w.events(model, "setup-end")[0]["outcome"] == "stopped" + assert w.run.lanes[model].pool.closed + assert run_problems(w) == [] + + +def test_an_interrupt_between_lane_launches_prevents_the_next_lane(world, monkeypatch): + model = "gpt-6-sol" + w = world(models=(model,)) + signalled = threading.Event() + started = [] + start = threading.Thread.start + + def lane(number): + started.append(number) + w.run.interrupt(2, None) + signalled.set() + + def start_and_signal(thread): + start(thread) + if thread.name == f"{model}-1": + assert signalled.wait(10) + + monkeypatch.setattr(w.run.lanes[model], "lane", lane) + monkeypatch.setattr(threading.Thread, "start", start_and_signal) + w.execute() + assert started == [1] + assert [e["cause"] for e in w.events(model, "stop")] == ["interrupt"] + assert run_problems(w) == [] + + +def test_stop_all_notifies_every_model_before_a_failed_event_write(world, monkeypatch): + w = world(models=("gpt-6-luna", "gpt-6-sol")) + notified = [] + for model, lanes in w.run.lanes.items(): + notify = lanes.cond.notify_all + + def observed(model=model, notify=notify): + notified.append(model) + notify() + + monkeypatch.setattr(lanes.cond, "notify_all", observed) + first = w.run.lanes[w.models[0]] + + def broken(line, name="run-log.jsonl"): + assert all(lanes.stopped for lanes in w.run.lanes.values()) + raise OSError("the first model's event log is unavailable") + + monkeypatch.setattr(first, "write_line", broken) + w.run.stop_all("disk failure", "runner-error") + assert notified == list(w.models) + assert all(lanes.stopped for lanes in w.run.lanes.values()) + assert w.events(w.models[1], "stop")[0]["cause"] == "runner-error" + + +@pytest.mark.parametrize( + "kind,error", [("pause", "AuthenticationError"), ("stop", "BadRequestError")] +) +def test_end_attempt_retains_the_record_before_a_failed_event_write( + world, monkeypatch, kind, error +): + model = "gpt-6-luna" + w = world(models=(model, "gpt-6-sol")) + sid = w.draw_order[0] + lanes = w.run.lanes[model] + label = lanes.orders[sid][0] + w.provider.specs = { + (model, label, sid, 1): { + "status": "provider_error", + "error": f"{error}: a test", + "turns": 0 if kind == "stop" else 1, + } + } + write = lanes.write_line + failed = [] + + def broken(line, name="run-log.jsonl"): + if line.get("event") == kind and not failed: + failed.append(line) + raise OSError("end_attempt's event write failed") + write(line, name) + + monkeypatch.setattr(lanes, "write_line", broken) + w.execute() + assert len(failed) == 1 + record = json.loads((w.folder(model, label) / f"{sid}.json").read_text()) + assert record["error"] == f"{error}: a test" + assert record["totals"]["cost_usd"] == pytest.approx(0 if kind == "stop" else COST) + lines = w.lines(model) + saved = next( + i + for i, x in enumerate(lines) + if x.get("household") == sid and x.get("arm") == label + ) + stopped = next(i for i, x in enumerate(lines) if x.get("cause") == "runner-error") + assert saved < stopped + assert all(lanes.stopped for lanes in w.run.lanes.values()) + assert ( + lanes.folder / "in-flight" / sid + ).exists() is False # event failed before disk write + + +def test_a_final_record_write_failure_still_recovers_the_other_arms(world, monkeypatch): + model = "gpt-6-luna" + w = world(models=(model,)) + sid = w.draw_order[0] + w.run.no_output.update(w.draw_order[1:]) + first = w.run.lanes[model].orders[sid][0] + target = w.folder(model, first) / f"{sid}.json" + write = cr.write_json + + def broken(path, payload, indent=1): + if Path(path) == target: + raise OSError("one final record cannot be written") + return write(path, payload, indent) + + monkeypatch.setattr(cr, "write_json", broken) + w.execute() + assert len(w.attempts(model)) == len(cr.ARMS) - 1 + assert all( + (w.folder(model, a) / f"{sid}.json").exists() for a in cr.ARMS if a != first + ) + assert (w.run.lanes[model].folder / "in-flight" / sid / f"{first}-1.json").exists() + assert w.lines(model)[-1]["cause"] == "runner-error" + + +def blocked_cleanup_request(w, monkeypatch): + """One real request, released by the test after the abandoned join.""" + monkeypatch.setattr(cr, "ATTEMPT_DEADLINE", 0.02) + monkeypatch.setattr(cr, "LATE_JOIN", 0.0) + monkeypatch.setattr(cr, "CEILING_MARGIN", 0.0) + w.design.update(overall_cap=0.10, spent_before=0.0) + w.run.no_output.update(w.draw_order[1:]) + w.run.ceiling = cr.Ceiling(0.10, 0.0) + release, returned = threading.Event(), threading.Event() + + def converse(lanes, sid, label, tool_call, spend): + assert release.wait(30) + spend.add(0.20) + returned.set() + return {"status": "budget_stop", "turns": [], "totals": {"cost_usd": 0.20}} + + w.run.converse = converse + return release, returned + + +def test_cleanup_counts_a_request_returning_during_host_close(world, monkeypatch): + model = "gpt-6-luna" + w = world(models=(model,)) + release, returned = blocked_cleanup_request(w, monkeypatch) + host_factory = w.run.host_factory + + def host(folder): + evidence = host_factory(folder) + close = evidence.close + + def finish(): + release.set() + assert returned.wait(10) + for lanes in w.run.lanes.values(): + for item in list(lanes.abandoned): + item["thread"].join(timeout=10) + assert not item["thread"].is_alive() + close() + + evidence.close = finish + return evidence + + w.run.host_factory = host + try: + w.execute() + finally: + release.set() + assert returned.is_set() + assert w.run.ceiling.spent_usd == pytest.approx(0.20) + assert w.run.ceiling.closed + assert [e["cost_usd"] for e in w.events(model, "late-cost")] == [ + pytest.approx(0.20) + ] + assert len(w.events(model, "ceiling")) == 1 + assert w.events(model, "late-unresolved") == [] + assert anchor_problems(w) == [] + assert run_problems(w) == [] + + +@pytest.mark.parametrize("returns_at_close", [False, True]) +def test_cleanup_records_an_unresolved_request_before_closing_the_ledger( + world, monkeypatch, returns_at_close +): + model = "gpt-6-luna" + w = world(models=(model,)) + release, returned = blocked_cleanup_request(w, monkeypatch) + if returns_at_close: + close = w.run.ceiling.close + + def finish(pending=None): + unresolved = close(pending) + release.set() + assert returned.wait(10) + return unresolved + + monkeypatch.setattr(w.run.ceiling, "close", finish) + try: + w.execute() + unresolved = w.events(model, "late-unresolved") + assert len(unresolved) == 1 + assert unresolved[0]["outcome"] == "unresolved-at-ledger-close" + assert unresolved[0]["counted_usd"] == 0.0 + assert w.events(model, "stop")[-1]["cause"] == "runner-error" + assert w.run.ceiling.closed + assert anchor_problems(w) == [] + before = (w.runs() / model / "run-log.jsonl").read_bytes() + finally: + release.set() + assert returned.wait(10) + assert w.run.ceiling.spent_usd == 0.0 + assert w.run.ceiling.unrecorded_usd == pytest.approx(0.20) + assert (w.runs() / model / "run-log.jsonl").read_bytes() == before + + +@pytest.mark.parametrize("during", ["host-close", "final-push"]) +def test_a_first_interrupt_during_cleanup_is_recorded_and_anchored( + world, monkeypatch, during +): + model = "gpt-6-sol" + w = world(models=(model,)) + w.run.no_output.update(w.draw_order) + if during == "host-close": + host_factory = w.run.host_factory + + def host(folder): + evidence = host_factory(folder) + close = evidence.close + + def finish(): + w.run.interrupt(2, None) + close() + + evidence.close = finish + return evidence + + w.run.host_factory = host + else: + anchor = w.run.anchor + signalled = [] + + def push(wait=False): + anchor(wait=wait) + if wait and not signalled: + signalled.append(True) + w.run.interrupt(2, None) + + monkeypatch.setattr(w.run, "anchor", push) + w.execute() + assert [e["cause"] for e in w.events(model, "stop")] == ["interrupt"] + assert w.run._interrupted + assert anchor_problems(w) == [] + + +def test_a_replacement_log_failure_keeps_a_valid_final_history(world, monkeypatch): + model = "gpt-6-luna" + w = world(models=(model,)) + sid = w.draw_order[0] + w.run.no_output.update(w.draw_order[1:]) + lanes = w.run.lanes[model] + label = lanes.orders[sid][0] + w.provider.specs = { + (model, label, sid, 1): { + "status": "provider_error", + "error": "RateLimitError: a test", + } + } + write, failed = lanes.write_line, [] + + def broken(line, name="run-log.jsonl"): + if line.get("arm") == label and line.get("attempt") == 1 and not failed: + failed.append(line) + raise OSError("the replaced attempt's log write failed") + write(line, name) + + monkeypatch.setattr(lanes, "write_line", broken) + w.execute() + rec = json.loads((w.folder(model, label) / f"{sid}.json").read_text()) + assert rec["attempts"] == [] + assert w.provider.count[(model, label, sid)] == 1 + logged = [x for x in w.attempts(model) if x["arm"] == label] + assert len(logged) == 1 + assert all( + logged[0][key] == value for key, value in failed[0].items() if key != "sha256" + ) + assert logged[0]["sha256"] == cr.sha256_file(w.folder(model, label) / f"{sid}.json") + assert run_problems(w) == [] + + +def test_a_supervision_error_drains_active_lanes_before_final_anchor( + world, monkeypatch +): + model = "gpt-6-sol" + w = world(models=(model,)) + w.run.no_output.update(w.draw_order[1:]) + started, returned = threading.Event(), threading.Event() + converse, watch = w.run.converse, w.run.watch + failed = [] + + def request(*args): + started.set() + assert w.run._failed.wait(10) + rec = converse(*args) + returned.set() + return rec + + def broken_watch(anchor=True): + if started.is_set() and not failed: + failed.append(True) + raise OSError("supervision failed while a request was active") + watch(anchor=anchor) + + w.run.converse = request + monkeypatch.setattr(w.run, "watch", broken_watch) + with pytest.raises(OSError, match="supervision failed"): + w.execute() + assert returned.is_set() + assert len(w.attempts(model)) == 1 + assert w.lines(model)[-1]["cause"] == "runner-error" + assert w.run.ceiling.spent_usd == pytest.approx(1.0 + COST) + assert anchor_problems(w) == [] + assert run_problems(w) == [] + + +def final_push_world(world, monkeypatch, fail_all=False, models=("gpt-6-luna",)): + """A run with no periodic pushes, whose first final push fails.""" + w = world(models=models) + w.run.no_output.update(w.draw_order) + monkeypatch.setattr(w.run, "anchor_due", lambda: False) + monkeypatch.setattr(cr, "ANCHOR_RETRY", 0.013) + script = w.tmp / "retrying-anchor.py" + script.write_text( + "import shutil, sys\n" + "from pathlib import Path\n" + "folder = Path(sys.argv[1])\n" + "counter = folder / 'push-count'\n" + "n = int(counter.read_text()) + 1 if counter.exists() else 1\n" + "counter.write_text(str(n))\n" + "shutil.copyfile(sys.argv[3], folder / f'pushed-{n}.jsonl')\n" + "raise SystemExit(1 if n == 1 or sys.argv[2] == '1' else 0)\n" + ) + w.design["anchor_command"] = [ + sys.executable, + str(script), + str(w.tmp), + str(int(fail_all)), + ] + return w + + +@pytest.mark.parametrize("fail_all", [False, True], ids=["then-success", "all-fail"]) +def test_the_final_push_is_retried_until_success_or_three_tries( + world, monkeypatch, fail_all +): + """Final retries stop at the first success, or after three failures.""" + w = final_push_world(world, monkeypatch, fail_all=fail_all) + w.execute() + anchors = [ + json.loads(x) for x in (w.runs() / "anchors.jsonl").read_text().splitlines() + ] + pushes = [ + json.loads(x) + for x in (w.runs() / "anchor-pushes.jsonl").read_text().splitlines() + ] + expected = 3 if fail_all else 2 + assert cr.FINAL_PUSH_TRIES == 3 + assert len(pushes) == len(anchors) == expected + assert [row["outcome"] for row in pushes] == ( + ["failed"] * 3 if fail_all else ["failed", "success"] + ) + final = (w.runs() / "anchors.jsonl").read_bytes() + assert (w.tmp / f"pushed-{expected}.jsonl").read_bytes() == final + assert pushes[-1]["anchor"] == cr.line_sha(final.decode().splitlines()[-1]) + assert pushes[-1]["anchor_time"] == anchors[-1]["time"] + assert all(a["models"] == anchors[0]["models"] for a in anchors) + assert all(a["host-log.jsonl"] == anchors[0]["host-log.jsonl"] for a in anchors) + assert all(a["time"] < b["time"] for a, b in zip(anchors, anchors[1:])) + + +def test_each_final_push_retry_waits_from_the_previous_try_s_end(world, monkeypatch): + """Each final retry starts at least ANCHOR_RETRY after the prior try ends, + even when the failed command itself takes time.""" + from types import SimpleNamespace + + w = world(models=("gpt-6-luna",)) + now = [1000.0] + durations = iter([7.0, 11.0, 5.0]) + monkeypatch.setattr(cr, "clock", lambda: now[0]) + + def sleep(seconds): + """Advance the controlled clock by the requested wait.""" + now[0] += seconds + + def failed_command(*args, **kwargs): + """A failed anchor command with a controlled, nonzero duration.""" + + def communicate(timeout): + """Finish the command after its planted duration.""" + now[0] += next(durations) + return "", "controlled push failure" + + return SimpleNamespace(returncode=1, communicate=communicate) + + monkeypatch.setattr(time, "sleep", sleep) + monkeypatch.setattr(subprocess, "Popen", failed_command) + w.run.finish() + pushes = [ + json.loads(x) + for x in (w.runs() / "anchor-pushes.jsonl").read_text().splitlines() + ] + assert len(pushes) == cr.FINAL_PUSH_TRIES == 3 + assert [p["outcome"] for p in pushes] == ["failed"] * 3 + assert [p["ended"] - p["started"] for p in pushes] == [7.0, 11.0, 5.0] + assert all( + b["started"] >= a["ended"] + cr.ANCHOR_RETRY + for a, b in zip(pushes, pushes[1:]) + ) + + +def test_a_first_signal_during_final_push_retries_is_logged_and_anchored( + world, monkeypatch +): + """A first signal during the retry wait is covered by the last push.""" + w = final_push_world(world, monkeypatch, models=("gpt-6-luna", "gpt-6-sol")) + sleep, delivered = time.sleep, [] + + def during_retry(seconds): + if seconds == cr.ANCHOR_RETRY and not delivered: + delivered.append(True) + w.run.interrupt(signal.SIGTERM, None) + sleep(seconds) + + monkeypatch.setattr(time, "sleep", during_retry) + w.execute() + assert delivered and w.run._interrupted + anchors = [ + json.loads(x) for x in (w.runs() / "anchors.jsonl").read_text().splitlines() + ] + pushes = [ + json.loads(x) + for x in (w.runs() / "anchor-pushes.jsonl").read_text().splitlines() + ] + assert [row["outcome"] for row in pushes] == ["failed", "success", "success"] + for model in w.models: + assert [row["cause"] for row in w.events(model, "stop")] == ["interrupt"] + assert anchors[-1]["models"][model]["run-log.jsonl"] == ( + w.run.lanes[model].heads()["run-log.jsonl"] + ) + assert anchors[-2]["models"][model]["run-log.jsonl"]["lines"] == ( + len(w.lines(model)) - 1 + ) + assert (w.tmp / "pushed-3.jsonl").read_bytes() == ( + w.runs() / "anchors.jsonl" + ).read_bytes() + + +def test_a_second_signal_during_final_push_retries_exits_at_once(world, monkeypatch): + """The retry wait leaves the second signal's immediate exit intact.""" + w = final_push_world(world, monkeypatch) + sleep, delivered = time.sleep, [] + + def exit_now(code): + raise SystemExit(code) + + def during_retry(seconds): + if seconds == cr.ANCHOR_RETRY and not delivered: + delivered.append(True) + w.run.interrupt(signal.SIGINT, None) + w.run.interrupt(signal.SIGTERM, None) + sleep(seconds) + + monkeypatch.setattr(os, "_exit", exit_now) + monkeypatch.setattr(time, "sleep", during_retry) + with pytest.raises(SystemExit) as stopped: + w.execute() + assert stopped.value.code == 130 and delivered + assert len((w.runs() / "anchor-pushes.jsonl").read_text().splitlines()) == 1 + assert all(not w.events(model, "stop") for model in w.models) + + +def test_a_signal_at_the_final_ignore_hook_is_logged_and_anchored(world, monkeypatch): + """A signal between the last ordinary check and SIG_IGN is not lost.""" + w = world(models=("gpt-6-luna", "gpt-6-sol")) + w.run.no_output.update(w.draw_order) + monkeypatch.setattr(w.run, "anchor_due", lambda: False) + ignore = w.run._ignore_signals + ignored, delivered = [], [] + monkeypatch.setattr( + signal, "signal", lambda signum, handler: ignored.append((signum, handler)) + ) + + def at_end(): + if not delivered: + delivered.append(True) + w.run.interrupt(signal.SIGTERM, None) + ignore() + + monkeypatch.setattr(w.run, "_ignore_signals", at_end) + w.execute() + assert delivered and w.run._interrupted + assert (signal.SIGINT, signal.SIG_IGN) in ignored + assert (signal.SIGTERM, signal.SIG_IGN) in ignored + for model in w.models: + stops = w.events(model, "stop") + assert len(stops) == 1 and stops[0]["cause"] == "interrupt" + assert stops[0]["reason"] == f"operator stop (signal {signal.SIGTERM})" + assert anchor_problems(w) == [] + + +def test_a_final_push_log_failure_is_stopped_and_locally_anchored(world, monkeypatch): + model = "gpt-6-sol" + w = world(models=(model,)) + w.run.no_output.update(w.draw_order) + push = w.run._push_anchor + + def broken(head, anchor_time): + if w.run.host.end is not None: + with w.run._pushing: + w.run._push_error = OSError("the final push outcome cannot be written") + else: + push(head, anchor_time) + + monkeypatch.setattr(w.run, "_push_anchor", broken) + with pytest.raises(OSError, match="push outcome could not be recorded"): + w.execute() + assert w.events(model, "stop")[-1]["cause"] == "runner-error" + last = json.loads((w.runs() / "anchors.jsonl").read_text().splitlines()[-1]) + assert last["models"][model]["run-log.jsonl"]["lines"] == len(w.lines(model)) + assert last["host-log.jsonl"] == w.run.host.heads()