cli: `readme2demo report` never shows per-stage duration — the timestamps are already in manifest.json

[alphacrack]

User story

As an operator tuning a readme2demo run, I want readme2demo report to show how long each stage took, so that I can see where a 19-minute run actually went without hand-diffing ISO timestamps out of manifest.json.

What

StageRecord already persists started_at and finished_at on every stage transition. Nothing reads them back for the operator — report shows status, cost, and notes, but never elapsed time. This is a pure presentation slice: no new instrumentation is needed.

In scope:

1. One pure duration helper, in manifest.py, next to the fields it reads — e.g. a plain @property on StageRecord (see the pydantic trap in Notes) or a module-level stage_duration(rec) -> Optional[float]. Returns seconds as a float, or None when the duration is not knowable.
2. Human output (summarize): a duration column in the stage list.
3. --json output: a duration_seconds key per stage entry (null when unknown). Numeric — consumers should not parse "1m 25s".
4. --markdown output (summarize_markdown): a Duration column in the GFM stages table.
5. Update the report section of docs/usage.md (around line 48) if the documented output shape changes.

Explicitly out of scope — please do not expand into these:

• Any new timing instrumentation. No time.monotonic() calls, no new manifest fields, no changes to the four transition methods. If you find yourself editing stage_start/stage_complete, the scope has drifted.
• Sub-stage or per-command timings. Per-step video offsets are distill: emit step_timestamps.json — per-step [start, end] video offsets computed from the tape's timing model #172; per-command agent timings live in command_log.json and are a different issue.
• badge.json. tutorial.render_badge reads verify.finished_at (tutorial.py:284-296) and must keep deriving its verdict from manifest.verified alone. Leave it untouched.
• Published artifacts. Durations must not reach tutorial.md, step_by_step.md, provenance footers, or howto.jsonld.
• Cost accounting. manifest: stage_fail never records cost_usd — failed runs under-report spend #103 (stage_fail never records cost_usd) touches the same table; don't fix it here.

Grounding implication: none. This is read-only presentation over run metadata the orchestrator already wrote. It does not touch distill.py, normalize.py, tutorial.py, engines/, prompts/, or templates/, and no timing value can become a command or an output in a published artifact. The out-of-scope fences above exist to keep it that way.

Why

Two of the three heavyweight stages are invisible in the report. Measured from the two published example manifests (examples/toolhive/manifest.json, examples/readme2demo/manifest.json), by subtracting started_at from finished_at:

Stage	toolhive	readme2demo
ingest	16.3s	11.4s
agent	314.1s	87.5s
normalize	0.0s	0.0s
distill	29.5s	60.5s
verify	201.4s	12.2s
tutorial	18.2s	40.9s
render	565.9s	83.0s
total	~1145s	~296s

render is the slowest stage in both, and on toolhive it is roughly half the wall clock on its own (VHS recording the tape in real time). agent and verify are next. Today an operator asking "why did that take 19 minutes?" gets a report that says render completed and nothing else, and has to open manifest.json and do the arithmetic by hand — data the pipeline already collected and then throws away at the presentation layer.

This also makes the CI surface more useful: report --markdown feeds $GITHUB_STEP_SUMMARY for the README-breaker Action (#62), where per-stage duration is exactly the signal that tells a maintainer whether a slow job is the agent thinking or VHS recording.

Pointers

All line numbers verified by reading the files at 64a3cbd.

The timestamps already exist — src/readme2demo/manifest.py:32-38:

class StageRecord(BaseModel):
    status: StageStatus = "pending"
    started_at: Optional[str] = None
    finished_at: Optional[str] = None

Both are Optional[str], holding ISO-8601 strings from utcnow() (manifest.py:28-29), which is datetime.now(timezone.utc).isoformat() — offset-aware, +00:00 suffix, parseable by datetime.fromisoformat on Python 3.10.

Who writes them:

• stage_start (manifest.py:93-98) sets started_at.
• stage_complete (manifest.py:100-109), stage_fail (manifest.py:111-117), and stage_skip (manifest.py:119-125) each set finished_at.
• Note stage_skip sets finished_at without started_at — a stage skipped by --skip-video or the dry-run path (orchestrator.py:347-349) never started, so it has a finish stamp and no start. Duration is None there, not zero.

The three renderers that need the new column:

orchestrator.py:355-376, summarize() — the human report. Current stage loop:

    for name, rec in manifest.stages.items():
        extra = f" — {rec.error}" if rec.error else ""
        meta = ""
        if rec.meta:
            meta = " " + json.dumps(rec.meta, default=str)
        lines.append(f"  {name:<10} {rec.status:<10}{meta}{extra}")

orchestrator.py:389-424, summarize_markdown() — pure, no filesystem, docstring at 390-399 spells out the purity contract. The table is built at 412-419:

        "| Stage | Status | Cost (USD) | Notes |",
        "|---|---|---|---|",
    ]
    for name, rec in manifest.stages.items():
        note = rec.error or rec.meta.get("reason", "")

cli.py:537-547, the --json payload:

        output_data = {
            "stages": [
                {"name": name, "status": rec.status}
                for name, rec in manifest.stages.items()
            ],

The report command itself is cli.py:510-551 (rewritten by #158 for exit codes and #159 for --markdown, which closed issue #140). Exit-code logic is _report_exit_code at cli.py:494-507 — do not touch it; 0/1/2 is a documented CI contract (docs/usage.md:51-58).

Precedent for reading these fields back: tutorial.py:277-305 already parses verify.finished_at for the badge date. That is the only existing reader.

Existing tests to extend: tests/test_orchestrator.py:227-330 (the summarize_markdown block, with the make_report_manifest helper at 232 — note its stage dicts carry no timestamps, so it exercises the unknown-duration path for free) and tests/test_cli.py:494-650 (report exit codes, JSON payload, markdown shape).

Acceptance criteria

• A pure duration helper lives in manifest.py with a type hint and docstring, returning Optional[float] seconds.
• Returns None — not 0 — when started_at is missing, when finished_at is missing, or when either string fails to parse.
• Negative durations (clock skew / hand-edited manifest) are treated as unknown, i.e. None.
• report (human) shows a duration per stage; unknown renders as a visible placeholder (— or -), never a blank or 0.0s.
• report --json gains a numeric duration_seconds per stage entry, null when unknown. Existing keys (name, status, verified, cost, commit) are unchanged and keep their current names.
• report --markdown gains a Duration column; the header row and the |---| separator stay column-count consistent.
• manifest.json on disk is byte-identical in shape — no new serialized field (verify by round-tripping a fixture through model_validate → model_dump_json).
• A sub-second stage (normalize runs in ~0.0s in both examples) renders without claiming zero work — e.g. 0.0s or <1s, your call, just be deliberate.
• Every new behavior has a test with a """Regression: ...""" docstring, per repo convention; specifically covering skipped-stage (finish, no start), still-running (start, no finish), and unparseable-timestamp cases.
• _report_exit_code and the 0/1/2 contract are untouched.
• docs/usage.md report section updated if the documented shape changed.
• python -m pytest tests/ -q green; ruff check clean.

Notes for contributors

Prerequisites: none beyond a Python env. This is pure Python — no Docker, no API key, no LLM call, no network. pip install -e ".[dev]" && python -m pytest tests/ -q runs the whole suite in about 1.5 seconds, so the edit-test loop is instant. You never need to execute a real pipeline run; the two committed example manifests (examples/toolhive/manifest.json, examples/readme2demo/manifest.json) are real data you can load directly in a test or a REPL.

The pydantic v2 trap, worth reading before you start. StageRecord is a pydantic model, and Manifest.save() writes self.model_dump_json(indent=2) (manifest.py:84-89). If you expose the duration as @computed_field, pydantic will serialize it into every manifest.json write — changing the on-disk schema of a crash-safe state file for a cosmetic report feature. Use a plain @property (ignored by model_dump) or a module-level function. The acceptance criterion about byte-identical shape exists to catch exactly this.

Two honest subtleties, so you can describe the column accurately rather than guess:

1. Duration is last-attempt; cost is cumulative. On resume, a failed stage is re-run: stage_start overwrites started_at (manifest.py:96), while stage_complete accumulates cost with rec.cost_usd += cost_usd (manifest.py:104). So on a resumed run the duration column reflects the final attempt only, while the cost column is the sum across attempts. Don't try to fix that asymmetry here — just don't label the column something like "total time" that would be a lie.

2. Stage order comes from the manifest, not STAGES. All three renderers iterate manifest.stages.items(). examples/toolhive/manifest.json predates the tutorial-before-render reordering and stores render before tutorial, so it prints in its own historical order. That's correct and intentional — but it means if you add any "slowest stage" logic, sort by duration, never by position.

Related but distinct, so you don't need to coordinate: #103 (stage_fail never records cost_usd) touches the same table but a different column; #172 (step_timestamps.json) is about offsets inside the demo video, not pipeline wall clock; #38 (report crashes on a missing/corrupt manifest) is about the load path before any rendering happens.