diff --git a/docs/cli.md b/docs/cli.md index 9e118c2..9df01d4 100644 --- a/docs/cli.md +++ b/docs/cli.md @@ -34,7 +34,8 @@ Exit code conventions: - `0` success (or a replayed failure reproduced intentionally). - `1` the run behaved differently, or the operation could not complete safely. - `2` invalid, unreadable, or unresolvable input, or (for `run`) a check that - could not execute. + could not execute, or (for `minimize`) a replay that never reached the + failure the trace records. - `3` `validate --verify-integrity` on a legacy bundle without integrity metadata. @@ -320,11 +321,17 @@ Exit codes: - `0` minimization succeeded and produced a valid minimal trace. - `1` minimization failed (no failure detected, or minimization error). -- `2` invalid input, unreadable trace, or unresolvable entrypoint. +- `2` invalid input, unreadable trace, or unresolvable entrypoint, or a replay + that never reached the failure the trace records. Common errors: - `Failed to detect original failure signature: trace replay completed successfully; no failure to minimize` - the trace does not fail when replayed. +- `Cannot minimize: the replay failed before reaching any recorded call ...` - the + recording fails after at least one dependency call and the replay consumed + none of them, so what it raised is not the recording's failure. Either the + fixture could not be built, or the change moved the failure earlier than the + recording. No bundle is written; exception type cannot decide between the two. - `cannot resolve entrypoint ...` - the entrypoint specification is invalid or the module cannot be imported. - `Minimized trace does not reproduce the original failure` - rare internal error during delta debugging. diff --git a/src/stepfork/cli/minimize.py b/src/stepfork/cli/minimize.py index d03a106..f1d628f 100644 --- a/src/stepfork/cli/minimize.py +++ b/src/stepfork/cli/minimize.py @@ -13,6 +13,7 @@ from stepfork.minimize.delta_debug import create_minimized_trace from stepfork.minimize.engine import MinimizationEngine, generate_report from stepfork.minimize.models import MinimizationReport +from stepfork.minimize.signature import ReplayNeverReachedRecordedCall from stepfork.trace.models import Trace console = Console() @@ -149,6 +150,13 @@ def minimize_command( except KeyboardInterrupt: console.print("\n[yellow]Minimization interrupted by user[/yellow]") raise typer.Exit(1) from None + except ReplayNeverReachedRecordedCall as exc: + # The run could not reach the failure it was asked to minimize, so it + # says nothing about the trace. Exit 2 separates that from a failed + # minimization (exit 1) and from invalid input, which prints its own + # message. See issue #22. + console.print(f"\n[yellow]✗ Cannot minimize:[/yellow] {exc}") + raise typer.Exit(2) from None except Exception as exc: console.print( f"\n[red]Minimization failed:[/red] {exc}", diff --git a/src/stepfork/minimize/engine.py b/src/stepfork/minimize/engine.py index bd4722e..8b96dfc 100644 --- a/src/stepfork/minimize/engine.py +++ b/src/stepfork/minimize/engine.py @@ -20,6 +20,7 @@ MinimizationResult, ) from stepfork.minimize.signature import ( + ReplayNeverReachedRecordedCall, detect_failure_signature, format_signature, ) @@ -110,6 +111,10 @@ def minimize(self) -> MinimizationResult: timeout_seconds=self.timeout_seconds, ) self.total_replay_attempts += 1 + except ReplayNeverReachedRecordedCall: + # A refusal, not a failed minimization: the caller must be able to + # tell them apart by exit status, so it travels untouched. + raise except Exception as exc: return MinimizationResult( success=False, diff --git a/src/stepfork/minimize/signature.py b/src/stepfork/minimize/signature.py index 73318a0..a551535 100644 --- a/src/stepfork/minimize/signature.py +++ b/src/stepfork/minimize/signature.py @@ -22,13 +22,24 @@ ReplaySession, ) from stepfork.trace.canonical import canonical_json_bytes -from stepfork.trace.models import JsonValue, Trace +from stepfork.trace.models import EventType, JsonValue, Trace class FailureDetectionError(Exception): """Raised when failure signature cannot be determined.""" +class ReplayNeverReachedRecordedCall(FailureDetectionError): + """Raised when the replay failed without consuming any recorded call. + + The recording says the failure happened after at least one dependency call, + so a replay that consumed none of them never reached the place the trace + fails. The failure it raised instead is not the recording's failure, and a + bundle minimized from it would be derived from something that did not + happen. See issue #22. + """ + + def detect_failure_signature( trace: Trace, entrypoint: str, @@ -67,15 +78,16 @@ def detect_failure_signature( except Exception as exc: raise FailureDetectionError(f"cannot create replay session: {exc}") from exc - # Attempt replay and capture the failure + # Attempt replay and capture the failure. The session's divergence and + # consumed-call count are read *after* the attempt in every outcome: an + # exception can leave state worth reporting, and the success path is not + # the only one that carries a divergence. exception: BaseException | None = None actual_output: Any = None - divergence_error: ReplayError | None = None try: - with session as replay: + with session: actual_output = entrypoint_fn() - divergence_error = replay.divergence except ReplayPolicyError as exc: # The replay harness refused execution (forbidden/manual/derived mode, # unauthorized live tool). The agent never ran its check, so this is @@ -95,6 +107,9 @@ def detect_failure_signature( # Application exception during replay exception = exc + divergence_error: ReplayError | None = session.divergence + consumed = len(session.calls) - session.pending + # A policy refusal the agent swallowed internally still poisons the # outcome; refuse instead of recording it as a divergence signature. if isinstance(divergence_error, ReplayPolicyError): @@ -102,6 +117,28 @@ def detect_failure_signature( f"replay policy refused the attempt: {divergence_error}" ) from divergence_error + # The recording fails after at least ``calls_before`` dependency calls. A + # replay that consumed none of them never reached that place, so whatever + # it raised is not the recording's failure -- and minimizing from it writes + # a bundle derived from something that did not happen. Exception type + # cannot decide this: a setup error and a change that moves the failure + # earlier are the same observation. See issue #22. + calls_before = _calls_before_recorded_failure(trace) + if ( + exception is not None + and consumed == 0 + and calls_before >= 1 + and divergence_error is None + ): + raise ReplayNeverReachedRecordedCall( + "the replay failed before reaching any recorded call " + f"({_describe_attempt(exception, actual_output)}), and the trace " + f"records its failure after {calls_before} dependency call(s): " + "this run never reached the recorded failure. Either the fixture " + "could not be built, or the change moved the failure earlier than " + "the recording. No bundle written." + ) + # Determine the failure signature based on what happened if exception is not None: return _signature_from_exception(exception, divergence_error) @@ -120,6 +157,34 @@ def detect_failure_signature( ) +def _calls_before_recorded_failure(trace: Trace) -> int: + """Count dependency calls that precede the trace's own error event. + + A recording that fails during a dependency call still has that call's + ``tool_call``/``llm_request`` event before its ``error`` event, so this + counts the calls a faithful replay has to reach before it can fail the + way the recording did. A trace with no error event returns 0: it records + no failure, so nothing here can be compared against it. + """ + calls = 0 + for event in trace.events: + if event.type is EventType.ERROR: + return calls + if event.type in (EventType.LLM_REQUEST, EventType.TOOL_CALL): + calls += 1 + return 0 + + +def _describe_attempt( + exception: BaseException | None, + actual_output: Any, +) -> str: + """Name what the attempt did, for a refusal message a reader can act on.""" + if exception is None: + return f"the entrypoint returned {actual_output!r}" + return f"{type(exception).__name__}: {exception}" + + def _signature_from_exception( exception: BaseException, divergence: ReplayError | None, diff --git a/tests/unit/test_minimize_unreached_call.py b/tests/unit/test_minimize_unreached_call.py new file mode 100644 index 0000000..0ff79e1 --- /dev/null +++ b/tests/unit/test_minimize_unreached_call.py @@ -0,0 +1,211 @@ +"""Tests for refusing a signature produced before any recorded call. + +A trace records where it failed. When the recording fails after a dependency +call, a replay that consumes no recorded call never reached that place, so the +exception it raised is not the recording's failure -- and a bundle minimized +from it would be derived from something that did not happen. Exception type +cannot decide this: a setup error and a change that moves the failure earlier +look the same from inside the replay. See issue #22. +""" + +from __future__ import annotations + +import importlib +from pathlib import Path + +import pytest +from typer.testing import CliRunner, Result + +from stepfork import llm_request, record, trace_tool +from stepfork.cli.main import app +from stepfork.minimize.signature import ( + FailureDetectionError, + ReplayNeverReachedRecordedCall, + detect_failure_signature, +) +from stepfork.trace.models import Trace + +runner = CliRunner() + + +@trace_tool(name="lookup_customer") +def lookup_customer(customer_id: str) -> dict[str, str]: + """A dependency the recording calls once, before it fails.""" + return {"id": customer_id, "tier": "gold"} + + +def _plan() -> dict[str, str]: + plan: dict[str, str] = llm_request( + provider="fake", + model="m", + input={"messages": [{"role": "user", "content": "refund?"}]}, + call=lambda: {"content": "look up then refund", "model": "m"}, + ) + return plan + + +def _failing_agent() -> dict[str, str]: + _plan() + who = lookup_customer("cust-42") + if who["tier"] == "gold": + raise ValueError("refund path broken for gold tier") + return {"ok": "true"} + + +@pytest.fixture() +def failing_trace(tmp_path: Path) -> Path: + """A trace with two dependency calls before its recorded failure.""" + path = tmp_path / "two-call.sftrace" + # Let the failure escape the recording block so the trace records it. + try: + with record("two-call-agent", output=str(path)) as session: + session.set_output(_failing_agent()) + except ValueError: + pass + return path + + +# --- entrypoints exercised by the tests ------------------------------------- + + +def imports_a_missing_dependency() -> None: + # Dynamic on purpose: a literal import of a module that does not exist is + # an error mypy would report for this file. + importlib.import_module("definitely_not_installed_module") + + +def setup_error_with_the_recorded_type() -> None: + raise ValueError("config file missing") + + +def fails_after_consuming_every_recorded_call() -> None: + _plan() + lookup_customer("cust-42") + raise TypeError("refund path now fails differently") + + +def returns_without_failing() -> dict[str, str]: + return {"ok": "true"} + + +def _run_cli(trace: Path, entrypoint: str, out: Path) -> Result: + return runner.invoke( + app, + [ + "minimize", + str(trace), + "--entrypoint", + f"test_minimize_unreached_call:{entrypoint}", + "-o", + str(out), + ], + ) + + +# --- the refusal ------------------------------------------------------------ + + +def test_setup_error_is_refused(failing_trace: Path) -> None: + """An import error is not the recording's failure.""" + with pytest.raises(ReplayNeverReachedRecordedCall) as caught: + detect_failure_signature( + Trace.load(failing_trace), + "test_minimize_unreached_call:imports_a_missing_dependency", + ) + message = str(caught.value) + assert "ModuleNotFoundError" in message + assert "after 2 dependency call(s)" in message + + +def test_setup_error_of_the_recorded_type_is_refused(failing_trace: Path) -> None: + """The recorded exception type does not make an unreached run faithful.""" + with pytest.raises(ReplayNeverReachedRecordedCall): + detect_failure_signature( + Trace.load(failing_trace), + "test_minimize_unreached_call:setup_error_with_the_recorded_type", + ) + + +def test_a_refusal_is_a_detection_failure(failing_trace: Path) -> None: + """Callers that already catch FailureDetectionError keep working.""" + with pytest.raises(FailureDetectionError): + detect_failure_signature( + Trace.load(failing_trace), + "test_minimize_unreached_call:imports_a_missing_dependency", + ) + + +def test_cli_exits_two_and_writes_no_bundle( + failing_trace: Path, + tmp_path: Path, +) -> None: + """The refusal is separable from a failed minimization by exit status.""" + out = tmp_path / "never.sftrace" + result = _run_cli(failing_trace, "imports_a_missing_dependency", out) + assert result.exit_code == 2 + assert "before reaching any recorded call" in result.stdout + assert not out.exists() + + +# --- what must keep working ------------------------------------------------- + + +def test_failure_after_consuming_the_recorded_calls_still_minimizes( + failing_trace: Path, + tmp_path: Path, +) -> None: + """Same calls, different exception type: a real regression, not a refusal.""" + signature = detect_failure_signature( + Trace.load(failing_trace), + "test_minimize_unreached_call:fails_after_consuming_every_recorded_call", + ) + assert signature.exception_type == "TypeError" + + +def test_cli_minimizes_a_failure_reached_through_the_recorded_calls( + failing_trace: Path, + tmp_path: Path, +) -> None: + out = tmp_path / "reached.sftrace" + result = _run_cli( + failing_trace, + "fails_after_consuming_every_recorded_call", + out, + ) + assert result.exit_code == 0 + assert out.exists() + + +def test_no_failure_at_all_keeps_its_own_exit_status( + failing_trace: Path, + tmp_path: Path, +) -> None: + """A clean replay is "no failure to minimize" (exit 1), not a refusal.""" + out = tmp_path / "clean.sftrace" + result = _run_cli(failing_trace, "returns_without_failing", out) + assert result.exit_code == 1 + assert "no failure to minimize" in result.stdout + assert not out.exists() + + +def test_a_trace_whose_failure_precedes_its_calls_is_not_refused( + tmp_path: Path, +) -> None: + """With no recorded call before the error there is nothing to fail to reach.""" + path = tmp_path / "early.sftrace" + + @trace_tool(name="unused_tool") + def unused_tool(value: int) -> int: + return value + + with record("early-failure-agent", output=str(path)) as session: + session.set_output({"never": "reached"}) + session.record_error("StartupError", "the agent could not start") + + with pytest.raises(FailureDetectionError) as caught: + detect_failure_signature( + Trace.load(path), + "test_minimize_unreached_call:returns_without_failing", + ) + assert not isinstance(caught.value, ReplayNeverReachedRecordedCall) + assert "no failure to minimize" in str(caught.value)