Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions docs/usage.md
Original file line number Diff line number Diff line change
Expand Up @@ -57,6 +57,10 @@ directly instead of parsing output:
| `1` | Completed but **UNVERIFIED** — no stage failed, but the replay did not pass. |
| `2` | A stage failed. |

`report` also shows how long each stage took (from the timestamps already in
`manifest.json`): a duration column in the human and `--markdown` tables, and
a numeric `duration_seconds` per stage in `--json` (`null` when unknown).

```bash
readme2demo report runs/tool-20260702-... --json && echo "verified" || echo "gate failed"
```
Expand Down
6 changes: 5 additions & 1 deletion src/readme2demo/cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -537,7 +537,11 @@ def report(
if json_output:
output_data = {
"stages": [
{"name": name, "status": rec.status}
{
"name": name,
"status": rec.status,
"duration_seconds": rec.duration_seconds,
}
for name, rec in manifest.stages.items()
],
"verified": manifest.verified,
Expand Down
25 changes: 25 additions & 0 deletions src/readme2demo/manifest.py
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,31 @@ class StageRecord(BaseModel):
cost_usd: float = 0.0
meta: dict = Field(default_factory=dict)

@property
def duration_seconds(self) -> Optional[float]:
"""Elapsed wall-clock time for this stage's last attempt, in seconds.

Returns ``None`` (not ``0``) whenever the duration isn't knowable:
missing ``started_at``/``finished_at``, unparseable timestamps, or a
negative span (clock skew / a hand-edited manifest). A plain
``@property`` on purpose -- pydantic only serializes ``@computed_field``s,
so this never changes the on-disk shape of ``manifest.json``.
"""
if self.started_at is None or self.finished_at is None:
return None

try:
started = datetime.fromisoformat(self.started_at)
finished = datetime.fromisoformat(self.finished_at)
except ValueError:
return None

elapsed = (finished - started).total_seconds()
if elapsed < 0:
return None

return elapsed


class Manifest(BaseModel):
run_id: str
Expand Down
23 changes: 19 additions & 4 deletions src/readme2demo/orchestrator.py
Original file line number Diff line number Diff line change
Expand Up @@ -360,6 +360,19 @@ def run(self) -> Manifest:
return self.manifest


def _format_duration(seconds: Optional[float]) -> str:
"""Render a stage duration for human/markdown output.

``None`` (unknown duration) renders as a visible placeholder, never a
blank or ``0.0s`` -- those would look like data instead of "we don't
know". A genuinely sub-second stage still shows a real number (``0.0s``),
so it isn't mistaken for "unknown" either.
"""
if seconds is None:
return "—"
return f"{seconds:.1f}s"


def summarize(manifest: Manifest) -> str:
"""Human-readable run report for ``readme2demo report``."""
repo_line = (
Expand All @@ -380,7 +393,8 @@ def summarize(manifest: Manifest) -> str:
meta = ""
if rec.meta:
meta = " " + json.dumps(rec.meta, default=str)
lines.append(f" {name:<10} {rec.status:<10}{meta}{extra}")
duration = _format_duration(rec.duration_seconds)
lines.append(f" {name:<10} {rec.status:<10} {duration:<8}{meta}{extra}")
return "\n".join(lines)


Expand Down Expand Up @@ -417,14 +431,15 @@ def summarize_markdown(manifest: Manifest, artifacts: list[str]) -> str:
f"{badge} — {repo_part} — engine `{manifest.engine}` — "
f"total cost ${manifest.total_cost_usd:.4f}",
"",
"| Stage | Status | Cost (USD) | Notes |",
"|---|---|---|---|",
"| Stage | Status | Cost (USD) | Duration | Notes |",
"|---|---|---|---|---|",
]
for name, rec in manifest.stages.items():
# Failed stages carry `error`; skipped stages carry meta["reason"].
note = rec.error or rec.meta.get("reason", "")
duration = _format_duration(rec.duration_seconds)
lines.append(
f"| {name} | {rec.status} | {rec.cost_usd:.4f} | {_md_cell(note)} |"
f"| {name} | {rec.status} | {rec.cost_usd:.4f} | {duration} | {_md_cell(note)} |"
)
if artifacts:
lines += ["", "**Artifacts**", ""]
Expand Down
42 changes: 38 additions & 4 deletions tests/test_cli.py
Original file line number Diff line number Diff line change
Expand Up @@ -470,8 +470,42 @@ def test_regression_report_json_with_recorded_stages(tmp_path):
assert parsed["verified"] is True
assert parsed["cost"] == 1.5
assert parsed["commit"] == "abcdef123456"
assert {"name": "ingest", "status": "completed"} in parsed["stages"]
assert {"name": "agent", "status": "failed"} in parsed["stages"]
assert {
"name": "ingest",
"status": "completed",
"duration_seconds": None,
} in parsed["stages"]
assert {
"name": "agent",
"status": "failed",
"duration_seconds": None,
} in parsed["stages"]


def test_report_json_includes_known_duration(tmp_path):
"""Regression (#200): a stage with real timestamps reports a numeric
duration_seconds; consumers must not have to parse a string like
"1m 25s" out of it."""
import json

manifest_data = {
"run_id": "duration-test-run",
"verified": True,
"stages": {
"ingest": {
"status": "completed",
"started_at": "2026-07-10T16:20:12+00:00",
"finished_at": "2026-07-10T16:20:22.5+00:00",
},
},
}
(tmp_path / "manifest.json").write_text(json.dumps(manifest_data))

result = runner.invoke(app, ["report", str(tmp_path), "--json"])

parsed = json.loads(result.output)
stage = next(s for s in parsed["stages"] if s["name"] == "ingest")
assert stage["duration_seconds"] == pytest.approx(10.5)


# -- report exit codes (#85) --------------------------------------------------
Expand Down Expand Up @@ -594,8 +628,8 @@ def test_report_markdown_emits_gfm_summary_with_present_artifacts(tmp_path):
out = result.output
assert "## readme2demo — glow-20260710-162012-33fc72" in out
assert "**Verified: yes**" in out
assert "| Stage | Status | Cost (USD) | Notes |" in out
assert "| ingest | completed | 0.0021 | |" in out
assert "| Stage | Status | Cost (USD) | Duration | Notes |" in out
assert "| ingest | completed | 0.0021 | — | |" in out
assert "- tutorial.md" in out
assert "- demo.mp4" in out
assert "- demo.gif" not in out # not on disk → not claimed
Expand Down
132 changes: 123 additions & 9 deletions tests/test_orchestrator.py
Original file line number Diff line number Diff line change
Expand Up @@ -4,13 +4,14 @@
"""

from pathlib import Path
import json

import pytest

from readme2demo import ingest as ingest_mod
from readme2demo.config import Config
from readme2demo.manifest import STAGES, Manifest
from readme2demo.orchestrator import Orchestrator, PipelineError, summarize_markdown
from readme2demo.manifest import STAGES, Manifest, StageRecord
from readme2demo.orchestrator import Orchestrator, PipelineError, summarize, summarize_markdown
from readme2demo.types import Plan, SuccessCriteria


Expand Down Expand Up @@ -100,6 +101,82 @@ def test_manifest_skip_counts_as_done(tmp_path: Path):
assert m.next_stage() == "tutorial"


# -- StageRecord.duration_seconds (#200) ----------------------------------------
# A plain @property (not @computed_field) on purpose: pydantic only serializes
# computed fields, so this must never change manifest.json's on-disk shape.


def test_duration_seconds_completed_stage():
"""Regression: a completed stage reports elapsed wall-clock seconds."""
rec = StageRecord(
status="completed",
started_at="2026-07-01T10:00:00+00:00",
finished_at="2026-07-01T10:00:12.500000+00:00",
)
assert rec.duration_seconds == pytest.approx(12.5)


def test_duration_seconds_still_running_is_none():
"""Regression: a stage with started_at but no finished_at (still running,
or the process died mid-stage) is an unknown duration, not zero."""
rec = StageRecord(status="running", started_at="2026-07-01T10:00:00+00:00")
assert rec.duration_seconds is None


def test_duration_seconds_skipped_without_start_is_none():
"""Regression: stage_skip sets finished_at without started_at when a stage
(e.g. via --skip-video) never actually started. Duration is unknown, not
a negative or zero number."""
rec = StageRecord(status="skipped", finished_at="2026-07-01T10:00:00+00:00")
assert rec.duration_seconds is None


def test_duration_seconds_pending_stage_is_none():
rec = StageRecord()
assert rec.duration_seconds is None


def test_duration_seconds_unparseable_timestamp_is_none():
"""Regression: a hand-edited or corrupt manifest shouldn't raise — an
unparseable timestamp is an unknown duration."""
rec = StageRecord(status="completed", started_at="not-a-date", finished_at="also-not-a-date")
assert rec.duration_seconds is None


def test_duration_seconds_negative_span_is_none():
"""Regression: clock skew or a hand-edited manifest where finished_at
precedes started_at must not report a negative duration."""
rec = StageRecord(
status="completed",
started_at="2026-07-01T10:00:10+00:00",
finished_at="2026-07-01T10:00:00+00:00",
)
assert rec.duration_seconds is None


def test_duration_seconds_zero_length_stage_is_not_none():
"""A genuinely sub-second stage (e.g. `normalize`) is real elapsed time,
not "unknown" — must not be conflated with the None cases above."""
rec = StageRecord(
status="completed",
started_at="2026-07-01T10:00:00+00:00",
finished_at="2026-07-01T10:00:00+00:00",
)
assert rec.duration_seconds == 0.0


def test_duration_seconds_not_serialized_to_manifest_json(tmp_path: Path):
"""Regression: exposing duration via @computed_field would serialize it
into every manifest.json write, changing the on-disk schema of a
crash-safe state file for a cosmetic report feature. Must stay a plain
property."""
m = Manifest.create(tmp_path / "r5", "https://github.com/x/y", "claude-code", "img")
m.stage_start("ingest")
m.stage_complete("ingest")
raw = json.loads((tmp_path / "r5" / "manifest.json").read_text())
assert "duration_seconds" not in raw["stages"]["ingest"]


# -- orchestrator control flow ---------------------------------------------------


Expand Down Expand Up @@ -324,10 +401,10 @@ def test_summarize_markdown_verified_run_full_shape():
assert "engine `claude-code`" in badge
assert "total cost $0.1234" in badge
# Stages table: header + one row per recorded stage, with per-stage cost.
assert "| Stage | Status | Cost (USD) | Notes |" in lines
assert "| ingest | completed | 0.0021 | |" in lines
assert "| agent | completed | 0.0980 | |" in lines
assert "| verify | completed | 0.0000 | |" in lines
assert "| Stage | Status | Cost (USD) | Duration | Notes |" in lines
assert "| ingest | completed | 0.0021 | — | |" in lines
assert "| agent | completed | 0.0980 | — | |" in lines
assert "| verify | completed | 0.0000 | — | |" in lines
# Artifact list renders exactly what the caller passed.
assert "**Artifacts**" in lines
assert "- tutorial.md" in lines
Expand Down Expand Up @@ -355,15 +432,15 @@ def test_summarize_markdown_failed_stage_error_in_notes():
stages={"agent": {"status": "failed", "error": "exit 127: no engine"}},
)
md = summarize_markdown(m, [])
assert "| agent | failed | 0.0000 | exit 127: no engine |" in md.splitlines()
assert "| agent | failed | 0.0000 | — | exit 127: no engine |" in md.splitlines()


def test_summarize_markdown_skip_reason_in_notes():
m = make_report_manifest(
stages={"render": {"status": "skipped", "meta": {"reason": "dry-run stop"}}},
)
md = summarize_markdown(m, [])
assert "| render | skipped | 0.0000 | dry-run stop |" in md.splitlines()
assert "| render | skipped | 0.0000 | — | dry-run stop |" in md.splitlines()


def test_summarize_markdown_escapes_table_breaking_error_text():
Expand All @@ -384,9 +461,46 @@ def test_summarize_markdown_escapes_table_breaking_error_text():
assert len(rows) == 1 # newlines collapsed — still one table row
assert "\\|" in rows[0] # pipe escaped, cell not split
assert "[openai]" in rows[0] # brackets survive verbatim
assert rows[0].count(" | ") == 3 # exactly 4 cells
assert rows[0].count(" | ") == 4 # exactly 5 cells


def test_summarize_markdown_no_artifacts_omits_section():
md = summarize_markdown(make_report_manifest(verified=False, stages={}), [])
assert "**Artifacts**" not in md


def test_summarize_markdown_known_duration_rendered():
"""Regression: a stage with real timestamps shows a real Duration cell,
not the "—" unknown placeholder."""
m = make_report_manifest(
stages={
"ingest": {
"status": "completed",
"cost_usd": 0.0021,
"started_at": "2026-07-10T16:20:12+00:00",
"finished_at": "2026-07-10T16:20:23.700000+00:00",
},
},
)
md = summarize_markdown(m, [])
assert "| ingest | completed | 0.0021 | 11.7s | |" in md.splitlines()


def test_summarize_human_report_shows_duration_column():
m = make_report_manifest(
stages={
"ingest": {
"status": "completed",
"started_at": "2026-07-10T16:20:12+00:00",
"finished_at": "2026-07-10T16:20:24+00:00",
},
"agent": {"status": "pending"},
},
)
text = summarize(m)
lines = text.splitlines()
ingest_line = next(ln for ln in lines if ln.strip().startswith("ingest"))
agent_line = next(ln for ln in lines if ln.strip().startswith("agent"))
assert "12.0s" in ingest_line
# A pending stage (no timestamps at all) is unknown, shown as "—".
assert "—" in agent_line
Loading