diff --git a/CHANGES b/CHANGES index 3abb8a1..bf716b1 100644 --- a/CHANGES +++ b/CHANGES @@ -1,5 +1,9 @@ # Changelog +## v1.6.1 — 2026-08-21 +- REPL: show time to task completion when each model finishes, persist timings in the session, and include last/total duration in `/report` +- `agent-tester run` reports: add a fastest-first time-to-completion ranking among successful agents + ## v1.6.0 — 2026-08-21 - Add `type: cursor` REPL provider (Cursor CLI) so Auto / Router works in `agent-tester repl` alongside other models; `/reset` clears the CLI chat session; document `models.cursor-auto` config diff --git a/README.md b/README.md index 091a0b7..19d0729 100644 --- a/README.md +++ b/README.md @@ -367,7 +367,7 @@ The REPL fans out each prompt to all configured models in parallel and maintains | `/status` | Show which models are running or idle | | `/stop [@model …]` | Cancel a running model. Without a tag, stops all busy models. | | `/interrupt [@model …] ` | Cancel and immediately re-dispatch with ``. Without a tag, targets all busy models. | -| `/report` | Show each model's git commits, diff stats, and token usage. Report data is persisted in the session file (`~/.config/agenttester/sessions/.yaml`). | +| `/report` | Show each model's git commits, diff stats, token usage, and time to completion. Report data is persisted in the session file (`~/.config/agenttester/sessions/.yaml`). | | `/evaluate [m1,m2,…]` | Cross-evaluate: each model reviews the others' work. Evaluation documents are saved to `.agenttester/evaluations//`. Eval results are also persisted in the session file. | | `/iterate ` | After `/evaluate`, inject peer evaluations as context and send an iteration prompt. Requires `y` confirmation. | diff --git a/pyproject.toml b/pyproject.toml index 1c3a493..a519f07 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -4,7 +4,7 @@ build-backend = "hatchling.build" [project] name = "agenttester" -version = "1.6.0" +version = "1.6.1" description = "Run a prompt against multiple coding agents in parallel and compare results" readme = "README.md" requires-python = ">=3.10" diff --git a/src/agenttester/repl.py b/src/agenttester/repl.py index a3d7e7a..8b6db22 100644 --- a/src/agenttester/repl.py +++ b/src/agenttester/repl.py @@ -46,6 +46,18 @@ _CTRL_C_TIMEOUT = 2.0 _BRANCH_SLUG_MAX_LEN = 60 + +def _format_duration(seconds: float) -> str: + """Human-readable duration for task completion display.""" + if seconds < 60: + return f"{seconds:.1f}s" + minutes, secs = divmod(seconds, 60) + if minutes < 60: + return f"{int(minutes)}m {secs:.0f}s" + hours, minutes = divmod(int(minutes), 60) + return f"{hours}h {minutes}m" + + _SLASH_COMMANDS = [ ("/reset", "clear conversation history"), ("/status", "show running/idle models"), @@ -327,12 +339,25 @@ async def _run_one( model: Model, prompt: str, on_event: Callable[[str, str], None] | None = None, -) -> tuple[str, str]: +) -> tuple[str, str, float]: + """Run one model query. Returns ``(name, reply, duration_seconds)``.""" + start = time.monotonic() try: r = await _query_async(model, prompt, on_event=on_event) except Exception as exc: r = str(exc) - return name, r + return name, r, time.monotonic() - start + + +def _print_model_done(console: Console, name: str, reply: str, duration: float) -> None: + """Print the per-model completion line including time to task completion.""" + elapsed = _format_duration(duration) + if reply.startswith("[error]"): + console.print(f" [red]✗ {name}[/red]: {reply[:100]} [dim]({elapsed})[/dim]") + else: + console.print( + f" [green]✓[/green] [bold]{name}[/bold]: done [dim]({elapsed})[/dim]" + ) def _clean_name(raw: str) -> str: @@ -460,6 +485,7 @@ async def _run_report( console: Console, reports_store: dict[str, dict[str, str]], token_usage: dict[str, dict[str, dict[str, int]]] | None = None, + query_timings: dict[str, dict[str, float | int]] | None = None, ) -> None: """Collect each model's work and display a summary. Populates *reports_store*.""" @@ -478,6 +504,22 @@ async def _fetch(name: str, model: Model) -> tuple[str, dict[str, str]]: console.print( "[yellow]No models have committed or uncommitted work yet.[/yellow]\n" ) + # Still show timings even when there is no git work yet. + if query_timings: + console.print("[bold]Time to completion[/bold]") + for name in models: + timing = query_timings.get(name) + if not timing: + continue + last = float(timing.get("last", 0)) + total = float(timing.get("total", 0)) + count = int(timing.get("count", 0)) + console.print( + f" [bold]{name}[/bold]: last {_format_duration(last)}" + f" · total {_format_duration(total)} ({count} quer" + f"{'y' if count == 1 else 'ies'})" + ) + console.print() return console.print(f"\n[bold]Work report — {len(models_with_work)} model(s)[/bold]\n") @@ -488,6 +530,16 @@ async def _fetch(name: str, model: Model) -> tuple[str, dict[str, str]]: console.print(f" [dim]{line}[/dim]") if report["stat"]: console.print(f" {report['stat']}") + if query_timings and name in query_timings: + timing = query_timings[name] + last = float(timing.get("last", 0)) + total = float(timing.get("total", 0)) + count = int(timing.get("count", 0)) + console.print( + f" [dim]time: last {_format_duration(last)}" + f" · total {_format_duration(total)} ({count} quer" + f"{'y' if count == 1 else 'ies'})[/dim]" + ) if token_usage and name in token_usage: for phase, counts in token_usage[name].items(): in_t = counts.get("input", 0) @@ -1003,7 +1055,7 @@ async def _iterate_run( _in_before = _m.input_tokens _out_before = _m.output_tokens try: - _, reply = await _run_one( + _, reply, duration = await _run_one( _nm, _m, _p, @@ -1021,19 +1073,15 @@ async def _iterate_run( session.add_tokens( _nm, "queries", delta_in, delta_out ) + session.add_timing(_nm, duration) if _m.event_logger is not None: _m.event_logger.log("response", reply) _m.event_logger.log( - "status", "waiting for next instructions" - ) - if reply.startswith("[error]"): - console.print( - f" [red]✗ {_nm}[/red]: {reply[:100]}" - ) - else: - console.print( - f" [green]✓[/green] [bold]{_nm}[/bold]: done" + "status", + f"waiting for next instructions" + f" (completed in {_format_duration(duration)})", ) + _print_model_done(console, _nm, reply, duration) _had_user_input = True _it2 = asyncio.create_task(_iterate_run()) @@ -1130,7 +1178,11 @@ async def _iterate_run( async def _report_task() -> None: await _run_report( - models, console, _reports, token_usage=session.token_usage + models, + console, + _reports, + token_usage=session.token_usage, + query_timings=session.query_timings, ) session.reports = dict(_reports) session.save() @@ -1331,7 +1383,7 @@ async def _background_run( _in_before = _m.input_tokens _out_before = _m.output_tokens try: - _, reply = await _run_one( + _, reply, duration = await _run_one( _nm, _m, _prompt, @@ -1347,13 +1399,15 @@ async def _background_run( delta_out = _m.output_tokens - _out_before if delta_in or delta_out: session.add_tokens(_nm, "queries", delta_in, delta_out) + session.add_timing(_nm, duration) if _m.event_logger is not None: _m.event_logger.log("response", reply) - _m.event_logger.log("status", "waiting for next instructions") - if reply.startswith("[error]"): - console.print(f" [red]✗ {_nm}[/red]: {reply[:100]}") - else: - console.print(f" [green]✓[/green] [bold]{_nm}[/bold]: done") + _m.event_logger.log( + "status", + f"waiting for next instructions" + f" (completed in {_format_duration(duration)})", + ) + _print_model_done(console, _nm, reply, duration) _had_user_input = True _bt = asyncio.create_task(_background_run()) diff --git a/src/agenttester/report.py b/src/agenttester/report.py index 939328e..76e6451 100644 --- a/src/agenttester/report.py +++ b/src/agenttester/report.py @@ -51,6 +51,20 @@ def generate_report( f"| -{stats.deletions} |" ) + # Rank by time to task completion (fastest first among successful agents) + finished = sorted( + (r for r in results if r.exit_code == 0 and not r.error), + key=lambda r: r.duration, + ) + if len(finished) >= 2: + lines.extend( + [ + "", + "**Time to completion** (fastest first): " + + ", ".join(f"{r.agent_name} ({r.duration:.1f}s)" for r in finished), + ] + ) + lines.append("") # Per-agent details diff --git a/src/agenttester/session.py b/src/agenttester/session.py index b1d93ac..cf68f0b 100644 --- a/src/agenttester/session.py +++ b/src/agenttester/session.py @@ -42,6 +42,8 @@ class ReplSession: reports: dict[str, dict[str, str]] = field(default_factory=dict) eval_results: dict[str, dict[str, str]] = field(default_factory=dict) token_usage: dict[str, dict[str, dict[str, int]]] = field(default_factory=dict) + # model -> {total: float seconds, last: float, count: int} + query_timings: dict[str, dict[str, float | int]] = field(default_factory=dict) @classmethod def create(cls, name: str) -> ReplSession: @@ -69,6 +71,7 @@ def load(cls, name: str, sessions_dir: Path | None = None) -> ReplSession: reports=data.get("reports", {}), eval_results=data.get("eval_results", {}), token_usage=data.get("token_usage", {}), + query_timings=data.get("query_timings", {}), ) @classmethod @@ -94,6 +97,15 @@ def add_tokens( phase_usage["input"] += in_tok phase_usage["output"] += out_tok + def add_timing(self, model_name: str, seconds: float) -> None: + """Record a query duration for *model_name* (last + cumulative).""" + timing = self.query_timings.setdefault( + model_name, {"total": 0.0, "last": 0.0, "count": 0} + ) + timing["last"] = float(seconds) + timing["total"] = float(timing.get("total", 0.0)) + float(seconds) + timing["count"] = int(timing.get("count", 0)) + 1 + def save( self, sessions_dir: Path | None = None, max_sessions: int | None = None ) -> None: @@ -110,6 +122,7 @@ def save( "reports": self.reports, "eval_results": self.eval_results, "token_usage": self.token_usage, + "query_timings": self.query_timings, }, default_flow_style=False, allow_unicode=True, diff --git a/tests/test_repl.py b/tests/test_repl.py index d99ddba..6621e3f 100644 --- a/tests/test_repl.py +++ b/tests/test_repl.py @@ -337,17 +337,31 @@ async def test_returns_name_and_result(self) -> None: provider = MagicMock() provider.async_call = AsyncMock(return_value="ok") model = Model(name="llama3", model_id="llama", provider=provider) - name, result = await _run_one("llama3", model, "hello") + name, result, duration = await _run_one("llama3", model, "hello") assert name == "llama3" assert result == "ok" + assert duration >= 0 async def test_returns_error_string_on_exception(self) -> None: provider = MagicMock() provider.async_call = AsyncMock(side_effect=OSError("unreachable")) model = Model(name="llama3", model_id="llama", provider=provider) - name, result = await _run_one("llama3", model, "hello") + name, result, duration = await _run_one("llama3", model, "hello") assert name == "llama3" assert "[error]" in result + assert duration >= 0 + + +class TestFormatDuration: + def test_seconds(self) -> None: + from agenttester.repl import _format_duration + + assert _format_duration(12.34) == "12.3s" + + def test_minutes(self) -> None: + from agenttester.repl import _format_duration + + assert _format_duration(125) == "2m 5s" # --------------------------------------------------------------------------- diff --git a/tests/test_report.py b/tests/test_report.py index 125e7d0..e0fc1be 100644 --- a/tests/test_report.py +++ b/tests/test_report.py @@ -53,6 +53,19 @@ def test_contains_summary_table(self) -> None: assert "✅" in report assert "❌" in report + def test_time_to_completion_ranking(self) -> None: + results = [ + AgentResult("slow", 0, 30.0, "", "", None), + AgentResult("fast", 0, 5.0, "", "", None), + AgentResult("failed", 1, 1.0, "", "", "boom"), + ] + report = generate_report("r-time", "b" * 40, "test", results, _mock_git()) + assert "**Time to completion**" in report + # Fastest successful agent listed first + ranking = report.split("**Time to completion**")[1].split("\n")[0] + assert ranking.index("fast") < ranking.index("slow") + assert "failed" not in ranking + def test_per_agent_sections(self) -> None: results = [ AgentResult("agent1", 0, 3.0, "", "", None), diff --git a/tests/test_session.py b/tests/test_session.py index 684b093..e06f094 100644 --- a/tests/test_session.py +++ b/tests/test_session.py @@ -136,3 +136,21 @@ def test_deletes_file(self, tmp_path: Path) -> None: def test_delete_missing_is_noop(self, tmp_path: Path) -> None: s = ReplSession.create("ghost") s.delete(tmp_path) # should not raise + + +class TestQueryTimings: + def test_add_timing_accumulates(self) -> None: + s = ReplSession.create("t") + s.add_timing("m1", 1.5) + s.add_timing("m1", 2.5) + assert s.query_timings["m1"]["last"] == 2.5 + assert s.query_timings["m1"]["total"] == 4.0 + assert s.query_timings["m1"]["count"] == 2 + + def test_timings_roundtrip(self, tmp_path: Path) -> None: + s = ReplSession.create("timed") + s.add_timing("cursor-auto", 12.3) + s.save(tmp_path) + loaded = ReplSession.load("timed", tmp_path) + assert loaded.query_timings["cursor-auto"]["last"] == 12.3 + assert loaded.query_timings["cursor-auto"]["count"] == 1