From f4d1ada8a499906906192b3f0812f8562fb74c8a Mon Sep 17 00:00:00 2001 From: Karim Elmaaroufi Date: Wed, 9 Sep 2026 17:41:02 -0700 Subject: [PATCH 1/3] feat(trace): decorator-based JSONL timing spans MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add `helix.trace.traced(span)`: a signature-preserving decorator that appends a `start`/`end` record pair (span id, wall/monotonic clocks, duration, thread id, outcome, error class, cheap identity attrs) to a JSONL sink opened once by `trace.enable(path)`. When tracing is off the wrapper is a single global check. The `finally` classifies any BaseException, writes the end record, and re-raises untouched; a failing sink is reported once via `logger.error("Trace unavailable: ...")` and never masks the exception in flight. Decorate the five functions whose whole body is the span we want: `run_evaluator` (evaluate), `_run_full_val_eval` (validate), `_run_proposal_worker` (proposal), `invoke_claude_code` (agent), `generate_seed` (seed) — plus `run_evolution` (run) so the last line of a complete trace is always the run's end record. No function is split and no signature changes. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_015HBBoDVQK7baNMQBhgRkh4 --- src/helix/evolution.py | 5 +- src/helix/executor.py | 3 +- src/helix/mutator.py | 3 + src/helix/trace.py | 154 ++++++++++++++++++++++++++++++++++++++++- 4 files changed, 162 insertions(+), 3 deletions(-) diff --git a/src/helix/evolution.py b/src/helix/evolution.py index 147db9ae..7361c3de 100644 --- a/src/helix/evolution.py +++ b/src/helix/evolution.py @@ -88,7 +88,7 @@ save_eval_cache, save_state, ) -from helix.trace import TRACE, EventType +from helix.trace import TRACE, EventType, traced from helix.worktree import ( create_seed_worktree, create_empty_seed_worktree, @@ -1049,6 +1049,7 @@ def _evaluator( return merged, num_actual_evals +@traced("validate") def _run_full_val_eval( candidate: Candidate, state: EvolutionState, @@ -1446,6 +1447,7 @@ def _plan_proposals( # upstream's ``ReflectiveMutationProposer.propose``, though upstream # batches these stages across all sampled tasks per iteration instead # of running one call per proposal slot. +@traced("proposal") def _run_proposal_worker( pre_ctx: ProposalContext, *, @@ -1695,6 +1697,7 @@ def _dispatch_proposals( return worker_results +@traced("run") def run_evolution( config: HelixConfig, project_root: Path, diff --git a/src/helix/executor.py b/src/helix/executor.py index e4a378f9..6a1ef156 100644 --- a/src/helix/executor.py +++ b/src/helix/executor.py @@ -23,7 +23,7 @@ current_evaluator_sidecar_runtime, run_sandboxed_commands, ) -from helix.trace import TRACE, EventType +from helix.trace import TRACE, EventType, traced logger = logging.getLogger(__name__) @@ -182,6 +182,7 @@ def _collect_asi( return asi +@traced("evaluate") def run_evaluator( candidate: Candidate, config: HelixConfig, diff --git a/src/helix/mutator.py b/src/helix/mutator.py index 4f53c202..63fed38f 100644 --- a/src/helix/mutator.py +++ b/src/helix/mutator.py @@ -22,6 +22,7 @@ ) from helix.executor import _scrub_environment from helix.sandbox import resolve_sandbox_image, run_sandboxed_command +from helix.trace import traced from helix.worktree import clone_candidate, snapshot_candidate, remove_worktree # noqa: F401 logger = logging.getLogger(__name__) @@ -291,6 +292,7 @@ def build_seed_generation_prompt( ) +@traced("seed") def generate_seed( worktree_path: str, prompt: str, @@ -1547,6 +1549,7 @@ def _write_backend_artifacts( ) +@traced("agent") def invoke_claude_code( worktree_path: str, prompt: str, diff --git a/src/helix/trace.py b/src/helix/trace.py index 612c0541..f8fb0803 100644 --- a/src/helix/trace.py +++ b/src/helix/trace.py @@ -1,5 +1,9 @@ """HELIX TraceBus — lightweight runtime event stream for differential testing. +The second half of this module (``traced`` / ``enable``) is the JSONL timing +trace behind ``helix evolve --trace PATH``; it shares nothing with the bus +except this file. + Zero overhead when disabled: ``TRACE.emit(...)`` short-circuits on a single attribute check (``self.enabled``) before building any event payload. @@ -13,11 +17,20 @@ """ from __future__ import annotations +import functools import inspect +import itertools +import json +import logging +import os +import threading +import time from contextlib import contextmanager from dataclasses import dataclass from enum import Enum -from typing import Any, Iterator +from typing import Any, Callable, Iterator, ParamSpec, TextIO, TypeVar + +logger = logging.getLogger(__name__) class EventType(str, Enum): @@ -99,3 +112,142 @@ def record(self) -> Iterator[list[Event]]: TRACE = TraceBus() + + +# --------------------------------------------------------------------------- +# JSONL timing spans — ``helix evolve --trace PATH`` / ``HELIX_TRACE=PATH`` +# --------------------------------------------------------------------------- +# +# One JSON object per line, appended and flushed per record. A span is one +# whole decorated function call: a ``start`` record on entry, an ``end`` +# record on exit carrying ``duration_seconds`` and ``outcome``. The last +# line of a complete trace is the ``end`` record of the ``run`` span; a +# file whose last line is anything else was cut short. + +P = ParamSpec("P") +R = TypeVar("R") +AttrsFn = Callable[[tuple[Any, ...], dict[str, Any]], dict[str, Any]] + +_enabled = False +_sink: TextIO | None = None +_sink_lock = threading.Lock() +_span_ids = itertools.count(1) +_sink_failed = False + +# Cheap identity attrs per span, keyed by span name. Each receives the +# decorated call's ``(args, kwargs)``; anything it raises is dropped. +_ATTRS: dict[str, AttrsFn] = { + "evaluate": lambda a, k: { + "candidate_id": a[0].id, + "split": k.get("split", a[2] if len(a) > 2 else "val"), + "evaluation_phase": k.get("evaluation_phase"), + }, + "validate": lambda a, k: {"candidate_id": a[0].id}, + "proposal": lambda a, k: {"candidate_id": a[0][3], "generation": k.get("gen")}, + "agent": lambda a, k: {"prompt_artifact": k.get("prompt_artifact_name")}, +} + + +def enable(path: str | os.PathLike[str] | None = None) -> bool: + """Open *path* (or ``$HELIX_TRACE``) for appending and turn spans on. + + Returns whether tracing is now enabled. Raises ``OSError`` when the + file cannot be opened, so the caller can fail loudly up front rather + than run untraced by accident. + """ + global _enabled, _sink, _sink_failed + target = path if path is not None else os.environ.get("HELIX_TRACE") + if not target: + return False + with _sink_lock: + if _sink is not None: + _sink.close() + _sink = open(target, "a", encoding="utf-8") + _sink_failed = False + _enabled = True + return True + + +def disable() -> None: + """Turn spans off and close the sink (tests; not needed at process exit).""" + global _enabled, _sink + with _sink_lock: + _enabled = False + if _sink is not None: + _sink.close() + _sink = None + + +def _write(record: dict[str, Any]) -> None: + """Append one record; a failing sink is reported once and never raises.""" + global _sink_failed + try: + line = json.dumps(record, default=str) + with _sink_lock: + if _sink is not None: + _sink.write(line + "\n") + _sink.flush() + except Exception as exc: + if not _sink_failed: + _sink_failed = True + logger.error("Trace unavailable: %s: %s", type(exc).__name__, exc) + + +def traced( + span: str, attrs: AttrsFn | None = None +) -> Callable[[Callable[P, R]], Callable[P, R]]: + """Record a ``start``/``end`` span around every call of the decorated function. + + Signature-preserving passthrough (``functools.wraps``); when tracing is + disabled the only cost is one global check. An exception raised by the + wrapped function is classified (``outcome="error"``, ``error_type``) + and re-raised untouched — ``KeyboardInterrupt`` included — and a broken + sink can never mask it. + """ + extract = attrs if attrs is not None else _ATTRS.get(span) + + def decorate(fn: Callable[P, R]) -> Callable[P, R]: + @functools.wraps(fn) + def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: + if not _enabled: + return fn(*args, **kwargs) + span_id = next(_span_ids) + extracted: dict[str, Any] = {} + if extract is not None: + try: + extracted = extract(args, kwargs) + except Exception: + pass + started = time.monotonic() + record: dict[str, Any] = { + "event": "start", + "span": span, + "span_id": span_id, + "wall_time": time.time(), + "monotonic": started, + "thread_id": threading.get_ident(), + "attrs": extracted, + } + _write(record) + outcome, error_type = "ok", None + try: + return fn(*args, **kwargs) + except BaseException as exc: + outcome, error_type = "error", type(exc).__name__ + raise + finally: + now = time.monotonic() + record.update( + event="end", + wall_time=time.time(), + monotonic=now, + duration_seconds=now - started, + outcome=outcome, + ) + if error_type is not None: + record["error_type"] = error_type + _write(record) + + return wrapper + + return decorate From c34d3d3c3c10cd0c02397aa3e4696096c1112807 Mon Sep 17 00:00:00 2001 From: Karim Elmaaroufi Date: Wed, 9 Sep 2026 17:41:02 -0700 Subject: [PATCH 2/3] feat(cli): `--trace PATH` on evolve/resume, trace docs Parse the path, call `trace.enable()` once before `run_evolution`, and exit 2 with a clear message when the file cannot be opened. `HELIX_TRACE=PATH` is honoured as the environment fallback. Document the event schema, the spans, how a truncated trace is recognised, and a jq line for per-generation wall time. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_015HBBoDVQK7baNMQBhgRkh4 --- CHANGELOG.md | 7 +++++++ README.md | 37 +++++++++++++++++++++++++++++++++++++ src/helix/cli.py | 27 ++++++++++++++++++++++++++- 3 files changed, 70 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b0c031fc..eb79685d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,13 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Added +- `helix evolve --trace PATH` / `helix resume --trace PATH` (or `HELIX_TRACE=PATH`) + append a JSON Lines timing trace of the run: `start`/`end` records for + every `run`, `proposal`, `evaluate`, `validate`, `agent`, and `seed` span, + with `duration_seconds`, `outcome`, and candidate identity. A trace whose + last line is not the `run` span's `end` record was cut short. + ### Changed - **BREAKING**: Removed the `evaluator.score_parser` configuration field. The built-in `helix_result` parser is now implicit; configurations that still provide the diff --git a/README.md b/README.md index 8f0af146..be4fca29 100644 --- a/README.md +++ b/README.md @@ -803,6 +803,43 @@ stderr as fallback debug context. --backend BACKEND Override the mutation backend [claude|codex|cursor|gemini|opencode] --model TEXT Override the backend model (backend-specific naming) --effort LEVEL Reasoning effort: low | medium | high | xhigh | max +--trace PATH Append a JSONL timing trace of the run to PATH (off by default) +``` + +#### Tracing a run + +`--trace PATH` (on `helix evolve` and `helix resume`, or `HELIX_TRACE=PATH` in +the environment) appends a JSON Lines timing trace: one object per line, +flushed as it is written, so a killed run leaves every record it completed. +Each traced operation is a *span* with a `start` and an `end` record: + +```json +{"event": "start", "span": "evaluate", "span_id": 7, "wall_time": 1757400000.1, "monotonic": 1234.5, "thread_id": 6199, "attrs": {"candidate_id": "g1-s2", "split": "train", "evaluation_phase": null}} +{"event": "end", "span": "evaluate", "span_id": 7, "wall_time": 1757400012.3, "monotonic": 1246.7, "thread_id": 6199, "attrs": {...}, "duration_seconds": 12.2, "outcome": "ok"} +``` + +`wall_time` is Unix epoch seconds (for lining up with external logs); +`monotonic` never jumps backwards, and `duration_seconds` is the difference +between a span's two `monotonic` values. `outcome` is `"ok"` or `"error"`; +on error `error_type` names the exception class (never its message, so a +trace is safe to attach to an issue). Match `start` to `end` on `span_id` +— proposals run concurrently, so records from different threads interleave. + +| span | one call of | measures | +| --- | --- | --- | +| `run` | `run_evolution` | the whole run; its `end` is always the last line | +| `proposal` | `_run_proposal_worker` | one proposal slot: parent eval, mutation, child eval | +| `evaluate` | `run_evaluator` | one evaluator invocation (`attrs.split`) | +| `validate` | `_run_full_val_eval` | one sequential full-validation stage | +| `agent` | `invoke_claude_code` | one agent-backend call — inside a `proposal` it is a mutation, inside a `seed` it is seed generation, otherwise a merge | +| `seed` | `generate_seed` | seedless-mode seed generation | + +A trace is complete only if its last line is `{"event": "end", "span": "run", ...}`; +anything else means the process died mid-run and later spans are missing. +Per-generation wall time, from the `proposal` spans' `attrs.generation`: + +```console +$ jq -s 'map(select(.event=="end" and .span=="proposal")) | group_by(.attrs.generation) | map({gen: .[0].attrs.generation, seconds: (map(.duration_seconds) | add)})' .helix/trace.jsonl ``` --- diff --git a/src/helix/cli.py b/src/helix/cli.py index 539a28bf..72578036 100644 --- a/src/helix/cli.py +++ b/src/helix/cli.py @@ -30,10 +30,28 @@ from helix.lineage import load_lineage from helix.population import EvalResult, FrontierType, ParetoFrontier, Candidate from helix.state import load_state, save_state +from helix.trace import enable as enable_trace from helix.worktree import remove_worktree logger = logging.getLogger(__name__) +_trace_option = click.option( + "--trace", + "trace_path", + default=None, + type=click.Path(dir_okay=False, path_type=Path), + help="Append a JSONL timing trace of the run to this path (or set HELIX_TRACE).", +) + + +def _enable_trace(trace_path: Path | None) -> None: + """Start the span trace before evolution; an unopenable path fails loudly.""" + try: + enable_trace(trace_path) + except OSError as exc: + print_error(f"Cannot open trace file: {exc}") + raise SystemExit(2) + # --------------------------------------------------------------------------- # Helpers @@ -603,6 +621,7 @@ def sandbox_logout( "that does not support it)." ), ) +@_trace_option def evolve( config_path: str, project_dir: Path | None, @@ -613,6 +632,7 @@ def evolve( backend: str | None, model: str | None, effort: str | None, + trace_path: Path | None, ) -> None: from helix.evolution import run_evolution @@ -675,6 +695,7 @@ def evolve( base_dir = _helix_dir(project_root) setup_file_logging(base_dir) + _enable_trace(trace_path) try: run_evolution(config, project_root, base_dir) except ResumeIncompatibleError as exc: @@ -1171,7 +1192,10 @@ def attempts_cmd( type=click.Path(exists=True, file_okay=False, path_type=Path), help="Project root directory (defaults to current working directory).", ) -def resume(config_path: str, project_dir: Path | None) -> None: +@_trace_option +def resume( + config_path: str, project_dir: Path | None, trace_path: Path | None +) -> None: """Resume from the last completed generation of an evolution run. In-flight proposal batches are reconciled rather than resumed slot-by-slot. @@ -1222,6 +1246,7 @@ def resume(config_path: str, project_dir: Path | None) -> None: raise SystemExit(1) print_info(f"Resuming from generation {state.generation if state else 0}…") + _enable_trace(trace_path) try: run_evolution(config, project_root, base_dir) except ResumeIncompatibleError as exc: From 86552b4dec5b50367a5aa5ad66346754f11d80c9 Mon Sep 17 00:00:00 2001 From: Karim Elmaaroufi Date: Wed, 9 Sep 2026 17:41:02 -0700 Subject: [PATCH 3/3] test(trace): decorator, CLI flag, and end-to-end span coverage Decorator: args/kwargs/return passthrough, start/end pairing, error outcome with class name only, a broken sink never masking a KeyboardInterrupt in flight, one well-formed line per record under a thread pool, disabled-mode no-op, explicit and registry attrs extraction. `enable`: env fallback, unopenable path, per-record flush. CLI: `--trace` on evolve and resume enables the sink before evolution. End to end: a real `run_evolution` through the evaluator/mutator override hooks emits run, validate, proposal, evaluate, and agent spans and ends with the run's end record. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_015HBBoDVQK7baNMQBhgRkh4 --- tests/unit/test_trace.py | 401 +++++++++++++++++++++++++++++++++++++++ 1 file changed, 401 insertions(+) create mode 100644 tests/unit/test_trace.py diff --git a/tests/unit/test_trace.py b/tests/unit/test_trace.py new file mode 100644 index 00000000..ff8e202e --- /dev/null +++ b/tests/unit/test_trace.py @@ -0,0 +1,401 @@ +"""Tests for the JSONL timing trace (``helix.trace.traced`` / ``enable``).""" +from __future__ import annotations + +import json +import logging +import threading +from concurrent.futures import ThreadPoolExecutor +from pathlib import Path +from typing import Any + +import pytest +from click.testing import CliRunner + +from helix import executor, mutator, trace +from helix.cli import cli +from helix.config import ( + DatasetConfig, + EvaluatorConfig, + EvolutionConfig, + HelixConfig, + WorktreeConfig, +) +from helix.display import UsageStats +from helix.evolution import run_evolution +from helix.population import Candidate, EvalResult +from helix.trace import traced + + +def _read(path: Path) -> list[dict[str, Any]]: + return [json.loads(line) for line in path.read_text().splitlines()] + + +@pytest.fixture +def trace_file(tmp_path: Path) -> Any: + path = tmp_path / "trace.jsonl" + trace.enable(path) + try: + yield path + finally: + trace.disable() + + +@pytest.fixture(autouse=True) +def _trace_off_after_test() -> Any: + yield + trace.disable() + + +class _BrokenSink: + """A sink whose every write fails — stands in for a full or closed disk.""" + + def write(self, _data: str) -> int: + raise OSError("disk full") + + def flush(self) -> None: + raise OSError("disk full") + + def close(self) -> None: + pass + + +# --------------------------------------------------------------------------- +# Decorator unit tests +# --------------------------------------------------------------------------- + + +class TestTracedDecorator: + def test_passes_args_kwargs_and_return_through(self, trace_file: Path) -> None: + @traced("t") + def add(a: int, b: int, *, scale: int = 1) -> int: + return (a + b) * scale + + assert add(1, 2, scale=10) == 30 + assert add.__name__ == "add" + assert add.__wrapped__(1, 2) == 3 # type: ignore[attr-defined] + + def test_start_and_end_records_pair_up(self, trace_file: Path) -> None: + @traced("t") + def work() -> None: + pass + + work() + start, end = _read(trace_file) + assert (start["event"], end["event"]) == ("start", "end") + assert start["span"] == end["span"] == "t" + assert start["span_id"] == end["span_id"] + assert start["thread_id"] == end["thread_id"] == threading.get_ident() + assert end["outcome"] == "ok" and "error_type" not in end + assert end["duration_seconds"] >= 0 + assert end["monotonic"] >= start["monotonic"] + assert end["duration_seconds"] == pytest.approx( + end["monotonic"] - start["monotonic"] + ) + assert isinstance(start["wall_time"], float) + + def test_error_outcome_records_class_name_and_propagates( + self, trace_file: Path + ) -> None: + @traced("t") + def boom() -> None: + raise ValueError("secret message") + + with pytest.raises(ValueError, match="secret message"): + boom() + _start, end = _read(trace_file) + assert end["outcome"] == "error" + assert end["error_type"] == "ValueError" + assert "secret message" not in trace_file.read_text() + + def test_writer_failure_never_masks_the_exception_in_flight( + self, trace_file: Path, caplog: pytest.LogCaptureFixture + ) -> None: + @traced("t") + def interrupted() -> None: + raise KeyboardInterrupt + + trace._sink = _BrokenSink() # type: ignore[assignment] + with caplog.at_level(logging.ERROR, logger="helix.trace"): + with pytest.raises(KeyboardInterrupt): + interrupted() + with pytest.raises(KeyboardInterrupt): + interrupted() + unavailable = [r for r in caplog.records if "Trace unavailable" in r.message] + assert len(unavailable) == 1 + + def test_writer_failure_on_a_successful_call_returns_normally( + self, trace_file: Path, caplog: pytest.LogCaptureFixture + ) -> None: + @traced("t") + def fine() -> str: + return "ok" + + trace._sink = _BrokenSink() # type: ignore[assignment] + with caplog.at_level(logging.ERROR, logger="helix.trace"): + assert fine() == "ok" + assert any("Trace unavailable" in r.message for r in caplog.records) + + def test_thread_pool_writes_one_well_formed_record_per_line( + self, trace_file: Path + ) -> None: + @traced("t") + def work(i: int) -> int: + return i + + with ThreadPoolExecutor(max_workers=8) as pool: + assert sorted(pool.map(work, range(200))) == list(range(200)) + records = _read(trace_file) + assert len(records) == 400 + by_id: dict[int, list[str]] = {} + for r in records: + by_id.setdefault(r["span_id"], []).append(r["event"]) + assert len(by_id) == 200 + assert all(sorted(v) == ["end", "start"] for v in by_id.values()) + assert len({r["thread_id"] for r in records}) > 1 + + def test_disabled_mode_is_a_passthrough_that_writes_nothing( + self, tmp_path: Path + ) -> None: + calls: list[int] = [] + + @traced("t", attrs=lambda a, k: calls.append(1) or {}) + def work(x: int) -> int: + return x * 2 + + assert not trace._enabled + assert work(21) == 42 + assert calls == [] # attrs extraction is skipped entirely + assert not list(tmp_path.iterdir()) + + def test_explicit_attrs_callable_receives_args_and_kwargs( + self, trace_file: Path + ) -> None: + @traced("t", attrs=lambda a, k: {"first": a[0], "flag": k.get("flag")}) + def work(x: str, *, flag: bool = False) -> None: + pass + + work("a", flag=True) + start, end = _read(trace_file) + assert start["attrs"] == {"first": "a", "flag": True} + assert end["attrs"] == start["attrs"] + + def test_attrs_extraction_failure_is_dropped_not_raised( + self, trace_file: Path + ) -> None: + @traced("t", attrs=lambda a, k: {"x": a[5]}) + def work() -> str: + return "ran" + + assert work() == "ran" + assert _read(trace_file)[0]["attrs"] == {} + + def test_registry_attrs_for_the_five_spans(self) -> None: + cand = Candidate( + id="g1-s1", + worktree_path="/tmp/x", + branch_name="b", + generation=1, + parent_id=None, + parent_ids=[], + operation="mutate", + ) + pre_ctx = (cand, None, ["i1"], "g2-s3") + assert trace._ATTRS["proposal"]((pre_ctx,), {"gen": 2}) == { + "candidate_id": "g2-s3", + "generation": 2, + } + assert trace._ATTRS["evaluate"]( + (cand, None), {"split": "train", "evaluation_phase": "staged"} + ) == {"candidate_id": "g1-s1", "split": "train", "evaluation_phase": "staged"} + assert trace._ATTRS["evaluate"]((cand, None), {})["split"] == "val" + assert trace._ATTRS["validate"]((cand,), {}) == {"candidate_id": "g1-s1"} + assert trace._ATTRS["agent"]((), {"prompt_artifact_name": ".p.md"}) == { + "prompt_artifact": ".p.md" + } + + +class TestEnable: + def test_env_var_is_the_fallback_path( + self, tmp_path: Path, monkeypatch: pytest.MonkeyPatch + ) -> None: + path = tmp_path / "env.jsonl" + monkeypatch.setenv("HELIX_TRACE", str(path)) + assert trace.enable() is True + + @traced("t") + def work() -> None: + pass + + work() + assert len(_read(path)) == 2 + + def test_nothing_to_enable_stays_disabled( + self, monkeypatch: pytest.MonkeyPatch + ) -> None: + monkeypatch.delenv("HELIX_TRACE", raising=False) + assert trace.enable() is False + assert not trace._enabled + + def test_unopenable_path_raises(self, tmp_path: Path) -> None: + with pytest.raises(OSError): + trace.enable(tmp_path / "missing-dir" / "trace.jsonl") + + def test_records_are_appended_and_flushed_immediately( + self, trace_file: Path + ) -> None: + @traced("t") + def work() -> None: + assert len(_read(trace_file)) == 1 # start is on disk mid-call + + work() + assert len(_read(trace_file)) == 2 + + +# --------------------------------------------------------------------------- +# CLI +# --------------------------------------------------------------------------- + + +_TOML = 'objective = "improve"\n\n[evaluator]\ncommand = "pytest -q"\n' + + +class TestCliFlag: + @pytest.mark.parametrize("command", ["evolve", "resume"]) + def test_trace_option_enables_the_sink_before_evolution( + self, tmp_path: Path, mocker: Any, command: str + ) -> None: + (tmp_path / "helix.toml").write_text(_TOML) + seen: list[bool] = [] + mocker.patch( + "helix.evolution.run_evolution", + side_effect=lambda *a, **k: seen.append(trace._enabled), + ) + path = tmp_path / "out" / "trace.jsonl" + path.parent.mkdir() + result = CliRunner().invoke( + cli, [command, "--dir", str(tmp_path), "--trace", str(path)] + ) + assert result.exit_code == 0, result.output + assert seen == [True] + assert path.exists() + + def test_unopenable_trace_path_exits_2(self, tmp_path: Path, mocker: Any) -> None: + (tmp_path / "helix.toml").write_text(_TOML) + run = mocker.patch("helix.evolution.run_evolution") + result = CliRunner().invoke( + cli, + ["evolve", "--dir", str(tmp_path), "--trace", str(tmp_path / "no" / "t")], + ) + assert result.exit_code == 2 + assert "Cannot open trace file" in result.output + run.assert_not_called() + + +# --------------------------------------------------------------------------- +# End to end through run_evolution +# --------------------------------------------------------------------------- + + +def _candidate(cid: str, root: Path, generation: int = 0) -> Candidate: + wt = root / cid + wt.mkdir(parents=True, exist_ok=True) + return Candidate( + id=cid, + worktree_path=str(wt), + branch_name=f"helix/{cid}", + generation=generation, + parent_id=None, + parent_ids=[], + operation="seed", + ) + + +def _eval(cand: Candidate, split: str, ids: list[str] | None) -> EvalResult: + scores = {i: 0.5 for i in (ids or ["i1", "i2"])} + return EvalResult( + candidate_id=cand.id, + scores={}, + asi={}, + instance_scores=scores, + objective_scores=[{"quality": s} for s in scores.values()], + ) + + +class TestEndToEnd: + def test_a_real_run_emits_every_span_and_ends_with_the_run_end( + self, tmp_path: Path, mocker: Any + ) -> None: + trace_path = tmp_path / "trace.jsonl" + worktrees = tmp_path / "wt" + seed = _candidate("g0-s0", worktrees) + + # Real ``run_evaluator`` / ``mutate`` / ``invoke_claude_code`` run + # through the differential-testing hooks; only git and persistence + # are stubbed. + mocker.patch.object(executor, "_EVALUATOR_OVERRIDE", _eval) + mocker.patch.object( + mutator, + "_MUTATOR_OVERRIDE", + lambda wt, prompt, cfg: ({"result": "ok"}, UsageStats()), + ) + mocker.patch( + "helix.mutator.clone_candidate", + side_effect=lambda parent, new_id, base: _candidate(new_id, worktrees, 1), + ) + mocker.patch("helix.mutator.snapshot_candidate", return_value="abc123") + mocker.patch("helix.mutator.remove_worktree") + mocker.patch("helix.evaluator_manifest.snapshot_candidate") + for name in ( + "remove_worktree", + "save_state", + "init_base_dir", + "_save_evaluation", + "record_entry", + "snapshot_candidate", + "HelixLiveDisplay", + ): + mocker.patch(f"helix.evolution.{name}") + mocker.patch("helix.evolution.create_seed_worktree", return_value=seed) + mocker.patch("helix.evolution.load_state", return_value=None) + mocker.patch("helix.evolution._load_evaluation", return_value=None) + mocker.patch("helix.evolution.load_lineage", return_value={}) + + config = HelixConfig( + objective="Improve the code", + evaluator=EvaluatorConfig(command="pytest -q"), + dataset=DatasetConfig(), + evolution=EvolutionConfig( + max_generations=1, + max_evaluations=1000, + perfect_score_threshold=None, + merge_enabled=False, + frontier_type="instance", + ), + worktree=WorktreeConfig(), + ) + + trace.enable(trace_path) + run_evolution(config, tmp_path, tmp_path / ".helix") + trace.disable() + + records = _read(trace_path) + assert records[0]["span"] == "run" and records[0]["event"] == "start" + assert records[-1]["span"] == "run" and records[-1]["event"] == "end" + assert records[-1]["outcome"] == "ok" + + ends = [r for r in records if r["event"] == "end"] + spans = {r["span"] for r in ends} + assert {"run", "seed", "validate", "proposal", "evaluate", "agent"} - spans == { + "seed" # non-seedless run: no seed generation + } + assert all(r["outcome"] == "ok" for r in ends) + + starts = {r["span_id"] for r in records if r["event"] == "start"} + assert starts == {r["span_id"] for r in ends} + + proposal = next(r for r in ends if r["span"] == "proposal") + assert proposal["attrs"]["candidate_id"].startswith("g1-") + agent = next(r for r in ends if r["span"] == "agent") + assert agent["attrs"]["prompt_artifact"] == mutator.MUTATION_PROMPT_ARTIFACT_NAME + evaluate = next(r for r in ends if r["span"] == "evaluate") + assert evaluate["attrs"]["split"] in {"train", "val"}