interactive-story/backend/tools/m11_long_run.py

"""M11 M01-M04: a real 100-turn campaign, against a real narrator, over HTTP.

    python -m tools.m11_long_run --turns 100 --out <dir>

Run from `backend/`. Reads `AIDND_TEST_ENDPOINT`, `AIDND_TEST_MODEL` and
optionally `AIDND_TEST_EMBED_MODEL`.

## Why this is a script that spawns servers rather than a test

M01's pass condition is not "100 requests succeeded". It is **100+ accepted turns
with no continuity, state, history, authority, lineage or recovery corruption**,
across genuine application restarts, with a fact planted at the beginning
recoverable at the end through memory rather than through the transcript.

Three of those words decide the shape of this harness:

*Accepted* — a turn counts when the application committed it, so every turn is
checked for a committed action and a state document, not for an HTTP 200.

*Restarts* — M02 says a new test client, a reconnected browser and a reopened
session do **not** count. So the storyteller runs as a real `uvicorn` process,
started with the command `DEVELOPMENT.md` documents, and is killed and restarted
at planned points. Everything that survives crosses as bytes on disk.

*Recoverable* — the planted clue has to be pushed out of the recent-history
window and then retrieved, so the run measures the window at intervals and the
recall check at the end asks the application what it would actually send.

## What it records

A JSON line per turn (`timeline.jsonl`) with the context measurements M03 wants,
a `measurements.json` of the sampled checkpoints, the recall evidence for M04,
and the final bundle. Everything is written as it happens, so a run that dies at
turn 80 still leaves 80 turns of evidence rather than nothing.
"""

from __future__ import annotations

import argparse
import json
import os
import socket
import subprocess
import sys
import time
import urllib.error
import urllib.request
from datetime import datetime
from pathlib import Path

HERE = Path(__file__).resolve().parent
BACKEND = HERE.parent

ENDPOINT = os.environ.get("AIDND_TEST_ENDPOINT", "")
MODEL = os.environ.get("AIDND_TEST_MODEL", "")
EMBED_MODEL = os.environ.get("AIDND_TEST_EMBED_MODEL", "")

#: The planted clue. Distinctive enough that its presence anywhere is
#: unambiguous, and phrased as something a story would actually establish.
CLUE = "the silver key opens the crypt beneath the Old Abbey"
CLUE_SENTINEL = "SILVER-KEY-CRYPT-OLD-ABBEY"

CANON = [
    "The dead do not return. No rite, relic or bargain has ever returned anyone.",
    "The abbey crypt has been sealed since the founding.",
    "Aldric is the protagonist and the one the reader plays.",
]

CANON_MD = """# Westhaven

## The Old Abbey

The abbey above Westhaven has stood since the founding. Its crypt is sealed.

## What cannot happen here

The dead do not return. No rite, relic or bargain in Westhaven has ever
returned anyone from death, and none ever will.
"""

REFERENCE_MD = """# Roads and weather of the Fen

The fen road floods between the autumn rains and the first hard frost. Traders
take the ridge track instead, which adds a day.
"""

INSPIRATION_MD = """# Tone notes

Rain on slate. Lamplight through smoke. People who say less than they mean.
"""

#: The beats the campaign plays through, cycled. Written so the story keeps
#: moving and keeps giving the state extractor something to do, rather than a
#: hundred repetitions of one sentence.
BEATS = [
    "I ask Mara what she has heard about the abbey.",
    "I walk down to the waterfront and watch the boats.",
    "I ask the ferryman about the fen road.",
    "I look through my pack for anything useful.",
    "I go back to the tavern and sit by the fire.",
    "I ask Mara whether Edrin has been seen.",
    "I take the ridge track north out of town.",
    "I stop at the shrine on the ridge and look back at Westhaven.",
    "I talk to the trader waiting out the rain.",
    "I check the sky and decide whether to press on.",
]


def free_port() -> int:
    with socket.socket() as s:
        s.bind(("127.0.0.1", 0))
        return s.getsockname()[1]


class Storyteller:
    """The real application, started the way `DEVELOPMENT.md` says to start it."""

    def __init__(self, db_path: Path, log: Path):
        self.db_path = db_path
        self.port = free_port()
        self.log_path = log
        self.proc = None
        self.starts = 0

    def start(self) -> None:
        self.starts += 1
        handle = open(self.log_path, "ab")
        self.proc = subprocess.Popen(
            [str(BACKEND / ".venv/bin/uvicorn"), "app.main:app",
             "--host", "127.0.0.1", "--port", str(self.port)],
            cwd=str(BACKEND), stdout=handle, stderr=subprocess.STDOUT,
            env={**os.environ, "AIDND_DB_PATH": str(self.db_path),
                 "AIDND_DATABASE_URL": "", "DATABASE_URL": ""},
        )
        deadline = time.monotonic() + 90
        while time.monotonic() < deadline:
            if self.proc.poll() is not None:
                raise SystemExit(f"server exited early; see {self.log_path}")
            try:
                self.call("GET", "/settings")
                return
            except (urllib.error.URLError, ConnectionError, OSError):
                time.sleep(0.1)
        raise SystemExit(f"server never became ready; see {self.log_path}")

    def stop(self) -> None:
        if self.proc and self.proc.poll() is None:
            self.proc.terminate()
            try:
                self.proc.wait(timeout=20)
            except subprocess.TimeoutExpired:
                self.proc.kill()
                self.proc.wait(timeout=20)

    def listening(self) -> bool:
        try:
            self.call("GET", "/settings")
            return True
        except Exception:
            return False

    def restart(self) -> None:
        """A genuine OS process boundary, proved gone before it is replaced."""
        self.stop()
        assert not self.listening(), "the old process is still answering"
        self.port = free_port()
        self.start()

    def call(self, method: str, path: str, payload=None, timeout=600):
        data = json.dumps(payload).encode() if payload is not None else None
        request = urllib.request.Request(
            f"http://127.0.0.1:{self.port}/api{path}", data=data, method=method,
            headers={"Content-Type": "application/json"} if data else {},
        )
        with urllib.request.urlopen(request, timeout=timeout) as response:
            body = response.read().decode()
        return json.loads(body) if body else None

    def stream(self, path: str, payload, timeout=900) -> list[dict]:
        """A turn. The reply is SSE, and a failed turn is an event, not a status.

        `app/sse.py`: "A failed turn is still an HTTP 200 response, because the
        error is reported inside the stream the client is already reading." A
        harness that read the status code would call every failure a success —
        which is precisely the class of harness defect M8's review warned about.
        """
        request = urllib.request.Request(
            f"http://127.0.0.1:{self.port}/api{path}",
            data=json.dumps(payload).encode(), method="POST",
            headers={"Content-Type": "application/json"},
        )
        events: list[dict] = []
        with urllib.request.urlopen(request, timeout=timeout) as response:
            for raw in response:
                line = raw.decode(errors="replace").strip()
                if line.startswith("data:"):
                    try:
                        events.append(json.loads(line[5:].strip()))
                    except json.JSONDecodeError:
                        pass
        return events


class Run:
    """One long campaign, and everything measured about it."""

    def __init__(self, server: Storyteller, out: Path):
        self.server = server
        self.out = out
        self.timeline = (out / "timeline.jsonl").open("a")
        self.adv = 0
        self.accepted = 0
        self.events: list[dict] = []

    # ------------------------------------------------------------ recording

    def note(self, kind: str, **fields) -> None:
        entry = {"at": datetime.now().isoformat(timespec="seconds"),
                 "kind": kind, "accepted_turns": self.accepted, **fields}
        self.events.append(entry)
        self.timeline.write(json.dumps(entry, default=str) + "\n")
        self.timeline.flush()

    # ------------------------------------------------------------- campaign

    def setup(self) -> None:
        settings = self.server.call("PUT", "/settings", {
            "endpoint_url": ENDPOINT, "model": MODEL,
            "embedding_model": EMBED_MODEL, "context_token_budget": 16384,
            "max_output_tokens": 500, "model_timeout_seconds": 600,
            "memory_top_k": 4,
        })
        self.note("settings", model=settings["model"],
                  budget=settings["context_token_budget"])

        created = self.server.call("POST", "/adventures", {
            "title": "Continuity Test (M11 long run)",
            "opening": (
                "Rain over Westhaven. Aldric sits in the Crooked Lantern with a "
                "silver key in his pocket and no-one to give it to."
            ),
            "canon_rules": CANON,
            "persona_name": "Aldric",
            "narration_length": "brief",
        })
        self.adv = created["id"]
        self.note("campaign", id=self.adv)

        for name, body, kind in (("canon.md", CANON_MD, "canon"),
                                 ("reference.md", REFERENCE_MD, "reference"),
                                 ("inspiration.md", INSPIRATION_MD, "inspiration")):
            self.upload(name, body, kind)

        # The cast and the opening scene, as accepted state rather than prose.
        self.correct([
            {"type": "create_entity", "entity": "aldric",
             "entity_type": "character", "name": "Aldric"},
            {"type": "create_entity", "entity": "mara",
             "entity_type": "character", "name": "Mara"},
            {"type": "create_entity", "entity": "edrin",
             "entity_type": "character", "name": "Edrin"},
            {"type": "create_entity", "entity": "tavern",
             "entity_type": "location", "name": "The Crooked Lantern"},
            {"type": "create_entity", "entity": "abbey",
             "entity_type": "location", "name": "The Old Abbey"},
            {"type": "create_entity", "entity": "silver_key",
             "entity_type": "item", "name": "the silver key"},
            {"type": "set_possession", "item": "silver_key", "owner": "aldric"},
            {"type": "set_scene",
             "summary": "Aldric and Mara in the Crooked Lantern, rain outside.",
             "location": "tavern", "present": ["aldric", "mara"]},
        ], note="the opening cast")

    def upload(self, name: str, body: str, classification: str) -> None:
        """Multipart by hand: the harness speaks HTTP, not the test client."""
        boundary = "----m11longrun"
        parts = (
            f"--{boundary}\r\nContent-Disposition: form-data; name=\"classification\""
            f"\r\n\r\n{classification}\r\n"
            f"--{boundary}\r\nContent-Disposition: form-data; name=\"file\"; "
            f"filename=\"{name}\"\r\nContent-Type: text/markdown\r\n\r\n{body}\r\n"
            f"--{boundary}--\r\n"
        ).encode()
        request = urllib.request.Request(
            f"http://127.0.0.1:{self.server.port}/api/adventures/{self.adv}/knowledge",
            data=parts, method="POST",
            headers={"Content-Type": f"multipart/form-data; boundary={boundary}"},
        )
        with urllib.request.urlopen(request, timeout=120) as response:
            body_out = json.loads(response.read().decode())
        self.note("knowledge", file=name, classification=classification,
                  id=body_out["id"])

    def correct(self, events, note="") -> None:
        self.server.call("POST", f"/adventures/{self.adv}/state/corrections",
                         {"events": events, "note": note})
        self.note("state_correction", events=len(events), note=note)

    # ----------------------------------------------------------------- play

    def turn(self, text: str, *, kind="do") -> dict:
        started = time.monotonic()
        before = self.count_actions()
        try:
            events = self.server.stream(f"/adventures/{self.adv}/actions",
                                        {"type": kind, "text": text})
        except urllib.error.HTTPError as exc:
            self.note("turn_failed", text=text, status=exc.code,
                      detail=exc.read().decode()[:300])
            return {"accepted": False}
        errors = [e for e in events if e.get("type") == "error"]
        if errors:
            self.note("turn_error", text=text, detail=errors[0].get("detail", "")[:300])
            return {"accepted": False, "error": errors[0].get("detail", "")}
        after = self.count_actions()
        if after <= before:
            self.note("turn_not_accepted", text=text)
            return {"accepted": False}
        self.accepted += 1
        seconds = time.monotonic() - started
        sample = self.measure()
        self.note("turn", text=text, seconds=round(seconds, 1), **sample)
        return {"accepted": True, "seconds": seconds, **sample}

    def count_actions(self) -> int:
        return self.server.call("GET", f"/adventures/{self.adv}/actions?limit=1")["total"]

    def measure(self) -> dict:
        """M03's numbers, read from the prompt the app would send right now."""
        report = self.server.call("GET", f"/adventures/{self.adv}/context")
        tokens = report["tokens"]
        sections = {s["label"]: s["tokens"] for s in report["sections"]}
        window = report.get("window") or {}
        return {
            "total_actions": report["history"]["total"],
            "history_included": report["history"]["included"],
            "prompt_tokens": tokens["total"],
            "budget": tokens["budget"],
            "configured_budget": tokens.get("configured_budget"),
            "output_reserve": tokens["output_reserve"],
            "protected": tokens["protected"],
            "available_for_history": tokens["available_for_history"],
            "summary_tokens": sections.get("story_summary", 0),
            "memory_tokens": sections.get("memories", 0),
            "knowledge_tokens": sum(
                v for k, v in sections.items() if k.startswith("knowledge")),
            "state_tokens": sections.get("narrative_state", 0),
            "canon_tokens": sections.get("campaign_canon", 0),
            "window_verified": window.get("verified"),
            "window_tokens": window.get("tokens"),
            # Whether the *planted clue* is still visible anywhere in the
            # assembled prompt. Named for what it measures: an earlier version
            # called this `canon_present`, which it never was — the campaign
            # canon's presence is `canon_tokens`, which is non-zero on every
            # turn. This one going to zero is M04's precondition: the clue has
            # left the recent-history window and can only come back through
            # memory, summary or state.
            "clue_in_prompt": CLUE_SENTINEL in json.dumps(report["sections"]),
        }

    def state(self) -> dict:
        return self.server.call("GET", f"/adventures/{self.adv}/state")

    def head(self) -> tuple:
        page = self.server.call("GET", f"/adventures/{self.adv}/actions?limit=1")
        return page["total"], page["can_undo"], page["can_redo"]


def main() -> int:
    parser = argparse.ArgumentParser(description=__doc__)
    parser.add_argument("--turns", type=int, default=100)
    parser.add_argument("--out", required=True)
    args = parser.parse_args()

    if not (ENDPOINT and MODEL):
        print("set AIDND_TEST_ENDPOINT and AIDND_TEST_MODEL")
        return 2

    out = Path(args.out)
    out.mkdir(parents=True, exist_ok=True)
    db_path = out / "campaign.db"
    server = Storyteller(db_path, out / "server.log")
    server.start()
    run = Run(server, out)
    started = datetime.now()

    try:
        run.setup()

        # ---- The planted clue, at the very beginning. ----
        run.turn(f"I tell Mara quietly that {CLUE} — {CLUE_SENTINEL}.")
        run.correct([
            {"type": "add_fact", "subject": "aldric", "predicate": "knows",
             "object": "abbey", "detail": f"{CLUE} ({CLUE_SENTINEL})",
             "fact_id": "silver-key-opens-crypt"},
        ], note="the planted clue, as accepted state")
        run.note("clue_planted", sentinel=CLUE_SENTINEL)

        # ---- The long middle. ----
        plan = _schedule(args.turns)
        beat = 0
        while run.accepted < args.turns:
            step = plan.get(run.accepted + 1)
            if step:
                try:
                    _do_step(run, server, step)
                except Exception as exc:  # noqa: BLE001
                    # A step that fails is a finding, not a reason to lose the
                    # other ninety turns. It is recorded loudly and the campaign
                    # goes on, because an abandoned run proves nothing at all.
                    run.note("step_failed", step=step,
                             error=f"{type(exc).__name__}: {exc}"[:300])
            run.turn(BEATS[beat % len(BEATS)])
            beat += 1

        # ---- M04: the recall check, with controls. ----
        run.note("recall_begin")
        recall = _recall(run)
        (out / "recall.json").write_text(json.dumps(recall, indent=2))

        # ---- Export the whole thing, for the recovery evidence. ----
        bundle = server.call("GET", f"/adventures/{run.adv}/export")
        (out / "bundle.json").write_text(json.dumps(bundle))
        run.note("exported", bytes=len((out / "bundle.json").read_bytes()))

        summary = {
            "accepted_turns": run.accepted,
            "restarts": server.starts - 1,
            "elapsed_seconds": round((datetime.now() - started).total_seconds()),
            "recall": recall,
            "final_state": run.state()["document"],
            "final_measurement": run.measure(),
            "db_bytes": db_path.stat().st_size,
        }
        (out / "summary.json").write_text(json.dumps(summary, indent=2, default=str))
        print(json.dumps({k: v for k, v in summary.items()
                          if k not in ("final_state",)}, indent=2, default=str)[:2000])
        return 0
    finally:
        server.stop()
        run.timeline.close()


def _schedule(turns: int) -> dict:
    """Where each required history operation happens. Spread, not clustered."""
    unit = max(1, turns // 13)
    return {
        unit * 1: "save_point_1",
        unit * 2: "restart",
        unit * 3: "undo_redo",
        unit * 4: "retry",
        unit * 5: "save_point_2",
        unit * 6: "restart_with_retained_history",
        unit * 7: "retry",
        unit * 8: "undo_diverge",
        unit * 9: "take_selection",
        unit * 10: "failed_call",
        unit * 11: "restore_save_point",
        unit * 12: "restart",
    }


def _do_step(run: Run, server: Storyteller, step: str) -> None:
    adv = run.adv
    if step == "save_point_1":
        point = server.call("POST", f"/adventures/{adv}/checkpoints",
                            {"name": "Before the ridge", "note": "planted clue is behind us"})
        run.note("save_point", id=point["id"], name=point["name"])

    elif step == "save_point_2":
        point = server.call("POST", f"/adventures/{adv}/checkpoints",
                            {"name": "On the ridge", "note": ""})
        run.note("save_point", id=point["id"], name=point["name"])

    elif step in ("restart", "restart_with_retained_history"):
        if step == "restart_with_retained_history":
            server.call("POST", f"/adventures/{adv}/undo")
            run.note("undo", why="leave retained history across the restart")
        before = _snapshot(run)
        server.restart()
        after = _snapshot(run)
        run.note("restart", number=server.starts - 1,
                 identical=before == after,
                 before=before, after=after)

    elif step == "undo_redo":
        total_before, _, _ = run.head()
        server.call("POST", f"/adventures/{adv}/undo")
        after_undo = run.head()
        server.call("POST", f"/adventures/{adv}/redo")
        after_redo = run.head()
        run.note("undo_redo", before=total_before, after_undo=after_undo[0],
                 after_redo=after_redo[0], restored=after_redo[0] == total_before)

    elif step == "retry":
        # Retry regenerates a turn, so it streams like one. The first version of
        # this harness called it as JSON and died on the SSE body — found by the
        # shakeout run rather than fifty turns into the release campaign, which
        # is what the shakeout was for.
        events = server.stream(f"/adventures/{adv}/retry", {})
        errors = [e for e in events if e.get("type") == "error"]
        page = server.call("GET", f"/adventures/{adv}/actions?limit=3")
        takes = max((a.get("take_count") or 1) for a in page["actions"])
        run.note("retry", ok=not errors, takes_on_newest_turn=takes,
                 detail=(errors[0].get("detail", "")[:120] if errors else ""))

    elif step == "take_selection":
        # Retry first so there is more than one take to choose between, then
        # step back to the earlier one — D07's "select prior retry take".
        server.stream(f"/adventures/{adv}/retry", {})
        page = server.call("GET", f"/adventures/{adv}/actions?limit=5")
        multi = [a for a in page["actions"] if (a.get("take_count") or 1) > 1]
        if multi:
            target = multi[-1]
            takes = server.call(
                "GET", f"/adventures/{adv}/actions/{target['id']}/variants")
            chosen = server.call(
                "POST", f"/adventures/{adv}/actions/{target['id']}/variant",
                {"index": 0})
            run.note("take_selected", action=target["id"], of=len(takes),
                     chose_index=0, now_live=chosen["id"])
        else:
            run.note("take_selection_skipped", reason="no multi-take turn found")

    elif step == "undo_diverge":
        server.call("POST", f"/adventures/{adv}/undo")
        server.call("POST", f"/adventures/{adv}/undo")
        run.turn("I turn back towards the town instead.")
        _, _, can_redo = run.head()
        run.note("diverged", redo_available_after_new_writing=can_redo)

    elif step == "restore_save_point":
        points = server.call("GET", f"/adventures/{adv}/checkpoints")
        if points:
            target = points[0]
            before = run.head()
            page = server.call(
                "POST", f"/adventures/{adv}/checkpoints/{target['id']}/restore")
            run.note("save_point_restored", id=target["id"], name=target["name"],
                     total_before=before[0], total_after=page["total"],
                     can_redo=page["can_redo"])
        else:
            run.note("restore_skipped", reason="no save point exists yet")

    elif step == "failed_call":
        # A real failure: point the model at a name the server does not serve,
        # take a turn, and put it back. Nothing is mocked.
        settings = server.call("GET", "/settings")
        before_total, _, _ = run.head()
        before_state = run.state()["document"]
        server.call("PUT", "/settings", {"model": "no-such-model-m11"})
        try:
            events = server.stream(
                f"/adventures/{adv}/actions",
                {"type": "do", "text": "I look for a way across the water."},
                timeout=180)
            errors = [e for e in events if e.get("type") == "error"]
            outcome = (f"reported: {errors[0].get('detail', '')[:120]}"
                       if errors else "NO ERROR REPORTED")
        except urllib.error.HTTPError as exc:
            outcome = f"HTTP {exc.code}"
        except Exception as exc:  # noqa: BLE001 - recorded, not swallowed
            outcome = type(exc).__name__
        server.call("PUT", "/settings", {"model": settings["model"]})
        after_total, _, _ = run.head()
        run.note("failed_call", outcome=outcome,
                 actions_before=before_total, actions_after=after_total,
                 state_unchanged=before_state == run.state()["document"])
        # And prove play resumes.
        run.turn("I ask the ferryman again, more politely.")


def _snapshot(run: Run) -> dict:
    """What must be identical across a restart (M02's list)."""
    adv = run.adv
    page = run.server.call("GET", f"/adventures/{adv}/actions?limit=3")
    state = run.state()["document"]
    points = run.server.call("GET", f"/adventures/{adv}/checkpoints")
    knowledge = run.server.call("GET", f"/adventures/{adv}/knowledge")
    settings = run.server.call("GET", "/settings")
    return {
        "total": page["total"],
        "can_undo": page["can_undo"],
        "can_redo": page["can_redo"],
        "newest": [a["text"][:60] for a in page["actions"]],
        "scene": (state.get("scene") or {}).get("summary"),
        "entities": sorted(state.get("entities") or {}),
        "facts": sorted(f.get("id") for f in state.get("facts") or []),
        "save_points": sorted(p["name"] for p in points),
        "knowledge": sorted(k["original_filename"] for k in knowledge),
        "model": settings["model"],
        "budget": settings["context_token_budget"],
    }


def _recall(run: Run) -> dict:
    """M04: can the planted clue still be found, and not from the transcript?"""
    adv, server = run.adv, run.server

    # 1. Is the clue outside the recent-history window? (Precondition, not result.)
    report = server.call("GET", f"/adventures/{adv}/context")
    history_text = " ".join(
        s["text"] for s in report["sections"] if s["label"] == "story_history")
    in_history = CLUE_SENTINEL in history_text

    # 2. Ask about the subject, and see what the application assembles.
    run.turn("I think back to what I told Mara about the key, that first night.")
    after = server.call("GET", f"/adventures/{adv}/context")
    sections = {s["label"]: s["text"] for s in after["sections"]}
    whole_prompt = "\n".join(sections.values())

    # 3. Where did it come from? State, summary, memory, retrieval — or nowhere.
    document = run.state()["document"]
    fact_present = any(
        CLUE_SENTINEL in json.dumps(f) for f in document.get("facts") or [])
    return {
        "clue_in_recent_history_window": in_history,
        "clue_in_prompt": CLUE_SENTINEL in whole_prompt,
        "in_state_section": CLUE_SENTINEL in sections.get("narrative_state", ""),
        "in_summary_section": CLUE_SENTINEL in sections.get("story_summary", ""),
        "in_memories_section": CLUE_SENTINEL in sections.get("memories", ""),
        "in_knowledge_sections": any(
            CLUE_SENTINEL in text for label, text in sections.items()
            if label.startswith("knowledge")),
        "fact_still_in_state": fact_present,
        "history_included": after["history"]["included"],
        "history_total": after["history"]["total"],
        "memories_used": [
            m.get("text", "")[:120] for m in (after.get("memories") or {}).get("used", [])
        ],
        "prompt_tokens": after["tokens"]["total"],
    }


if __name__ == "__main__":
    raise SystemExit(main())