From 57b44db8292ff6a5365402ac1c2ad9a423b6a183 Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Tue, 29 Sep 2026 20:35:18 +0800 Subject: [PATCH 1/9] fix(*): let exec measure the files its command wrote A file an exec command wrote reached the desk diff as a bare row: the loop listed the working directory on either side of the call, so it knew a file changed but never what it changed from, and such a row opened in the file viewer instead of the diff pane. The exec tool now does the measuring itself, around the command it runs, and hands the result back on ToolResult.written beside the removals it already reported: - command_writes lists the directory before and after the command and, where the checkpoint's shadow repo covers it, stages the tree first so a rewritten or removed file is shown against what it held. The repo reaches the tool through a protocol (ShadowTree) the loop hands in; tools do not import the loop shell. - Every command stages the tree afresh inside its own call, into a per-process index of its own, and waits up to 120s. Past that the command is not run and the call fails, rather than running unmeasured. The tool's registry ceiling rises to 780s to cover the wait plus the 600s command cap. - A created file carries its text only where the shadow repo would store it (git check-ignore against its rules), so a .env or a key a command writes never enters a diff or the stored session. - ExecTool.warm starts the first staging as a session opens (session.create / session.resume), or at the first turn of a session opened by its first message, so it overlaps the model's first reply. - The loop loses its exec-only listing branch and forwards result.written as file_written; the registry keeps removed and written on a result it rewrites as an error. file_written entries gain optional added / removed / diff, and ui-web draws them with hunks so they open in the diff pane. Co-authored-by: Claude (claude-opus-5-5) --- CONTEXT.md | 10 +- raven/agent/loop/_shared.py | 69 +- raven/agent/loop/checkpoint.py | 378 ++++++++++- raven/agent/loop/turn_path.py | 75 +-- raven/agent/loop/wiring.py | 2 + raven/agent/tools/command_writes.py | 202 ++++++ raven/agent/tools/registry.py | 8 + raven/agent/tools/removals.py | 8 +- raven/agent/tools/shell.py | 62 +- raven/contracts/__init__.py | 2 +- raven/contracts/tool.py | 33 + raven/rpc/methods/session.py | 22 + raven/rpc/models.py | 26 +- rpc-schema/openrpc.json | 23 +- tests/conftest.py | 14 + tests/test_agent_loop_session_stamps.py | 643 +++++++++++++++---- tests/test_contracts_two_tier_ledger.py | 3 +- tests/test_kernel_budget.py | 15 +- tests/test_rpc_session.py | 82 +++ tests/test_runtime_checkpoint.py | 535 +++++++++++++++ tests/test_shell_command_writes.py | 217 +++++++ ui-tui/src/rpc/generated.ts | 14 +- ui-web/src/features/desk/store.ts | 6 +- ui-web/src/features/workspace/record.test.ts | 130 ++++ ui-web/src/features/workspace/record.ts | 45 +- ui-web/src/features/workspace/types.ts | 4 + ui-web/src/lib/hunks.test.ts | 13 + ui-web/src/lib/hunks.ts | 14 +- ui-web/src/rpc/fixtures/turn.test.ts | 5 +- ui-web/src/rpc/fixtures/turn.ts | 11 +- ui-web/src/rpc/generated.ts | 14 +- 31 files changed, 2396 insertions(+), 289 deletions(-) create mode 100644 raven/agent/tools/command_writes.py create mode 100644 tests/test_shell_command_writes.py diff --git a/CONTEXT.md b/CONTEXT.md index ed55a7c61..92cf1a566 100644 --- a/CONTEXT.md +++ b/CONTEXT.md @@ -566,7 +566,15 @@ _Avoid_: a fourth door -- a tool reaching the table any other way skips admissio A once-per-turn commit of the session workspace into a shadow git repo (separate from the user's `.git`), so an interrupted or failed turn can be rolled back. One `CheckpointService` per working directory, cached by `AgentLoop._turn_checkpoint()` and keyed on the directory -the running turn is bound to. +the running turn is bound to. The same repo also answers what a file an `exec` command +rewrote or removed held before it. `ExecTool` holds it through `command_writes.ShadowTree`, +handed in by the loop, and does the measuring itself: `ExecTool.warm` starts staging the tree +in the background when a session opens on the directory (`session.create` / +`session.resume`, or the first turn where a session opens without either), and every +command stages it afresh inside its own call with `stage_tree`, into a per-process index of +its own (never the index the turn commit reads), waiting up to 120s before the command is +failed rather than run unmeasured. `read_blobs` reads the old contents back for the +command's `file_written` diff and `file_removed` body. _Avoid_: "shadow git" as the term — Checkpoint is the per-turn snapshot it produces. **Empty-Response Recovery** (`agent/loop/recovery.py`): diff --git a/raven/agent/loop/_shared.py b/raven/agent/loop/_shared.py index cc86794cc..1ad08e871 100644 --- a/raven/agent/loop/_shared.py +++ b/raven/agent/loop/_shared.py @@ -578,70 +578,29 @@ def _file_removed_payload(removals: Any) -> list[dict[str, Any]] | None: return out or None -#: A file the listing found is counted in lines only when it is text this size -#: or under. Past it the count is unknown rather than wrong: reading a gigabyte -#: to number it would cost the turn more than the row it draws is worth. -_FILE_WRITTEN_TEXT_MAX_BYTES = 256 * 1024 - - -def _file_written_payload( - created: Collection[str], - modified: Collection[str], - after: dict[str, tuple[int, int]] | None, - *, - already: Collection[str] = (), -) -> list[dict[str, Any]] | None: +def _file_written_payload(written: Any) -> list[dict[str, Any]] | None: """The files a command left behind, as plain mappings, or ``None`` for none. The other half of ``_file_change_payload``: a file tool reports what it - wrote, a command reports its output and nothing else, so this is read off - two listings of the working directory instead of off a result. Sizes and a - line count rather than contents -- one command can write a hundred files, - and what a row draws is that they were written and how big they are. - - ``lines`` belongs to a created file alone, and ``None`` there means unknown: - too large to read, or not text. A rewritten file has no count at all, since - the listing never held the old content and a number against nothing would - read as a change nobody measured. - - ``already`` are the paths this same call accounted for by name. The listing - sees those too, and reporting one again would draw a single write twice. + wrote, a command reports its output and nothing else, so the tool reads + these off its directory either side of the command (``command_writes``). + The change keys go only where the tool measured one, so an entry without + them still reads as "changed, by how much unknown". """ - accounted = {os.path.realpath(path) for path in already if isinstance(path, str) and path} out: list[dict[str, Any]] = [] - for path in created: - if os.path.realpath(path) in accounted: - continue - size = (after or {}).get(path, (0, 0))[0] - out.append({"path": path, "created": True, "size": size, "lines": _text_line_count(path, size)}) - for path in modified: - if os.path.realpath(path) in accounted: + for write in written or (): + path = getattr(write, "path", None) + if not isinstance(path, str) or not path: continue - out.append({"path": path, "created": False, "size": (after or {}).get(path, (0, 0))[0], "lines": None}) + entry: dict[str, Any] = {"path": path, "created": write.created, "size": write.size, "lines": write.lines} + if write.added is not None and write.removed is not None: + entry["added"], entry["removed"] = write.added, write.removed + if write.diff is not None: + entry["diff"] = write.diff + out.append(entry) return out or None -def _text_line_count(path: str, size: int) -> int | None: - """Lines in a file the listing found, or ``None`` when it cannot be counted.""" - if size > _FILE_WRITTEN_TEXT_MAX_BYTES: - return None - try: - return len(Path(path).read_text(encoding="utf-8").splitlines()) - except (OSError, UnicodeDecodeError): - return None - - -def _listing_removals(deleted: Collection[str], *, already: Collection[str] = ()) -> list[FileRemoval]: - """Files a listing says went, for the deletions no tool reported itself. - - Without a body: the file was gone before anything read it, and the turn only - knows it was there when the command started. ``already`` are the removals - the call reported by name, which the listing sees as well. - """ - accounted = {os.path.realpath(path) for path in already if isinstance(path, str) and path} - return [FileRemoval(path=path) for path in deleted if os.path.realpath(path) not in accounted] - - def monotonic() -> float: """The turn's elapsed-time clock, as one name the loop calls. diff --git a/raven/agent/loop/checkpoint.py b/raven/agent/loop/checkpoint.py index 330b715a0..53dfb6dba 100644 --- a/raven/agent/loop/checkpoint.py +++ b/raven/agent/loop/checkpoint.py @@ -30,7 +30,15 @@ from __future__ import annotations import asyncio +import concurrent.futures +import contextlib +import os +import shutil +import subprocess +import threading +import time from pathlib import Path +from typing import Collection from loguru import logger @@ -129,13 +137,62 @@ _GC_EVERY_N_COMMITS = 50 -# Upper bound on any single git subprocess. Without this, an NFS lock, a -# held ``.git/index.lock``, or a full disk could hang ``communicate()`` -# indefinitely and brick the agent loop — violating this service's -# "never break a turn" contract. Generous enough that normal cold-init -# fits comfortably; tight enough to detect a real hang within one turn. +# Upper bound on a git subprocess the turn waits behind (a staging's ``git add`` +# runs on a thread nothing waits behind and has its own, below). Without this, +# an NFS lock, a held ``.git/index.lock``, or a full disk could hang +# ``communicate()`` indefinitely and brick the agent loop — violating this +# service's "never break a turn" contract. Generous enough that normal +# cold-init fits comfortably; tight enough to detect a real hang within one turn. _GIT_TIMEOUT_SECONDS = 30.0 +# How long a command waits for the tree staged in front of it before the call +# fails. Staging a tree git has seen before is a stat walk (about 0.1s on a repo +# of a few thousand files, 0.3s on seventeen thousand); the first one in a +# directory hashes and writes every file and was measured at 14s on a 390 MB +# tree, and past 30s while a turn's commit hashed the same tree beside it. This +# is only reached by a filesystem that has stopped answering. +_STAGE_WAIT_SECONDS = 120.0 + +# The ceiling on a staging's ``git add``. Not ``_GIT_TIMEOUT_SECONDS``: that one +# bounds a call something waits behind, and a staging runs on a thread nothing +# waits behind past ``_STAGE_WAIT_SECONDS``. Killed at 30s, the first staging of +# a large directory (tens of seconds while a turn's commit hashes the same tree) +# was started over and killed again, and every command was held back for good. +_STAGE_ADD_TIMEOUT_SECONDS = 600.0 + +# A command's staging index left behind by a process that is gone. Age rather +# than a liveness probe: asking whether a pid is alive terminates it on Windows. +_STAGE_INDEX_STALE_SECONDS = 7 * 24 * 3600 + + +# The staging running on each index, across every service in this process: two +# services for one directory share the index file, so they share its one run. +_STAGING: dict[Path, "concurrent.futures.Future[str | None]"] = {} +_STAGE_LOCKS: dict[Path, threading.Lock] = {} + + +class StagingTimeoutError(TimeoutError): + """The tree a command is to be measured against is still being staged. + + A :class:`TimeoutError`, which is what ``ExecTool`` catches: the tool holds + this repo through a protocol and does not import the loop shell.""" + + +async def _within(staging: "concurrent.futures.Future[str | None]", deadline: float) -> bool: + """Whether ``staging`` finished by ``deadline``, waited for without owning it. + + Detached rather than awaited: a staging still running when the loop closes + must not hold the close up, and a cancelled waiter is what lets its late + result be dropped once the loop is gone. + """ + waiter = asyncio.wrap_future(staging) + try: + done, _ = await asyncio.wait({waiter}, timeout=max(0.0, deadline - time.monotonic())) + finally: + if not waiter.done(): + waiter.cancel() + return bool(done) + class CheckpointService: """Shadow-git working-tree snapshots, one commit per turn.""" @@ -174,6 +231,16 @@ def __init__(self, workspace: Path, shadow_dir: str = ".raven/shadow.git") -> No self._shadow_rel = shadow_dir self._ready = False self._commit_count = 0 + self._stage_pruned = False + self._warmed = False + self._initializing: concurrent.futures.Future[bool] | None = None + + def covers(self, path: Path | str) -> bool: + """Whether ``path`` lies in the work-tree this repo snapshots.""" + try: + return Path(path).expanduser().resolve().is_relative_to(self._workspace) + except OSError: + return False async def _git(self, *args: str) -> tuple[int, str, str]: """Run a git command against the shadow repo. Returns (rc, out, err). @@ -183,6 +250,10 @@ async def _git(self, *args: str) -> tuple[int, str, str]: without this, ``edited_files`` would land in the recovery prompt as ``"\\346\\265\\213"`` gibberish. """ + rc, out, err = await self._run(args) + return rc, out.decode(errors="replace"), err.decode(errors="replace") + + def _command(self, args: tuple[str, ...], index: Path | None) -> tuple[tuple[str, ...], dict[str, str] | None]: cmd = ( "git", f"--git-dir={self._git_dir}", @@ -191,16 +262,32 @@ async def _git(self, *args: str) -> tuple[int, str, str]: "core.quotePath=false", *args, ) + return cmd, None if index is None else {**os.environ, "GIT_INDEX_FILE": str(index)} + + async def _run( + self, + args: tuple[str, ...], + *, + index: Path | None = None, + stdin: bytes | None = None, + timeout: float | None = None, + ) -> tuple[int, bytes, bytes]: + """``_git`` with the raw bytes, and optionally against another index.""" + if timeout is None: + timeout = _GIT_TIMEOUT_SECONDS + cmd, env = self._command(args, index) proc = await asyncio.create_subprocess_exec( *cmd, + stdin=asyncio.subprocess.PIPE if stdin is not None else asyncio.subprocess.DEVNULL, stdout=asyncio.subprocess.PIPE, stderr=asyncio.subprocess.PIPE, cwd=str(self._workspace), + env=env, ) try: out, err = await asyncio.wait_for( - proc.communicate(), - timeout=_GIT_TIMEOUT_SECONDS, + proc.communicate() if stdin is None else proc.communicate(stdin), + timeout=timeout, ) except asyncio.TimeoutError: # NFS / index-lock / disk-full pathology: don't leak a zombie, @@ -213,14 +300,35 @@ async def _git(self, *args: str) -> tuple[int, str, str]: pass logger.debug( "checkpoint git timed out after {}s: {}", - _GIT_TIMEOUT_SECONDS, + timeout, " ".join(args[:2]), ) - return -1, "", "timeout" - return proc.returncode or 0, out.decode(errors="replace"), err.decode(errors="replace") + return -1, b"", b"timeout" + return proc.returncode or 0, out, err async def _ensure_init(self) -> bool: - """Lazily initialize the shadow repo. Idempotent; returns readiness.""" + """Lazily initialize the shadow repo. Idempotent; returns readiness. + + A warm-up runs this same setup on its own thread (:meth:`warm`), and two + at once fail on the repo's config lock -- which costs the turn its + commit when the turn ends before the warm-up's setup does. So a setup + already running is waited for, and repeated only if it did not succeed. + """ + if self._ready: + return True + running = self._initializing + if running is not None and not running.done(): + waiter = asyncio.wrap_future(running) + try: + await waiter + finally: + if not waiter.done(): + waiter.cancel() + if self._ready: + return True + return await self._init_repo() + + async def _init_repo(self) -> bool: if self._ready: return True try: @@ -305,6 +413,252 @@ async def commit_turn(self, label: str) -> tuple[str | None, list[str]]: logger.debug("checkpoint commit error: {}", exc) return None, [] + async def stage_tree(self) -> str | None: + """The work-tree as it stands, as a tree id in the shadow repo. + + Taken just before a command runs, so what the command changed can be + diffed afterwards against the contents it replaced -- a command names no + file it writes, and by the time it returns the old text is gone. Staged + into an index of its own: the per-turn commit reads the shared index as + "what the last turn left", and moving it here would make that commit miss + everything this turn did before the command. Nothing is committed; the + tree is only read back within the same call. + + Staged afresh for every command, inside the command's own call, so the + tree is the directory as it stood the moment before the command ran and + nothing about what happened since an earlier staging has to be known. A + staging already running (a warm-up, or another session's command in the + same directory) is waited for first: they share one index, and a + warm-up runs the repo setup on its thread too, where two ``git config`` + writes at once fail on the config lock. + + ``None`` when the tree cannot be staged at all (git failed), which costs + the call its diff and nothing else. :class:`StagingTimeoutError` when it + has not finished after :data:`_STAGE_WAIT_SECONDS`: the caller fails the + command rather than run it unmeasured. The staging is left running + rather than killed, because what it has hashed is what makes the next + one fast. + """ + index = self._stage_path() + deadline = time.monotonic() + _STAGE_WAIT_SECONDS + earlier = _STAGING.get(index) + if earlier is not None and not earlier.done() and not await _within(earlier, deadline): + raise StagingTimeoutError + if not await self._ensure_init(): + return None + self._prepare_index(index) + staging = self._start_stage(index) + if not await _within(staging, deadline): + raise StagingTimeoutError + return staging.result() + + async def warm(self) -> None: + """Start a staging in the background, so the first command finds the index warm. + + The first staging in a directory the shadow repo has never indexed hashes + every file in it, which on a large tree is seconds. Started when a session + opens on the directory, it runs while the user types and the model writes + its first reply instead of inside the first command. Returns at once: the + repo's own setup (``git init``, its config, seeding the index) runs on the + staging's thread too, so nobody waits for any of it. Once per service, + which is once per directory per process: after that every command's own + staging keeps the index warm. + """ + if self._warmed: + return + self._warmed = True + index = self._stage_path() + running = _STAGING.get(index) + if running is not None and not running.done(): + return + staging = self._register_stage(index) + if not self._ready: + self._initializing = concurrent.futures.Future() + threading.Thread(target=self._warm_up, args=(index, staging), name="raven-stage", daemon=True).start() + + def _warm_up(self, index: Path, staging: "concurrent.futures.Future[str | None]") -> None: + # A loop of the thread's own for the repo setup: the turn's loop is not + # to wait on it, and one that closes while the setup is still starting a + # git process would hold its close up. + initializing = self._initializing + try: + ready = asyncio.run(self._init_repo()) + except Exception as exc: # noqa: BLE001 -- a warm-up never breaks anything + logger.debug("checkpoint warm-up init error: {}", exc) + ready = False + if initializing is not None: + initializing.set_result(ready) + if not ready: + staging.set_result(None) + return + self._prepare_index(index) + self._stage(index, staging) + + def _start_stage(self, index: Path) -> "concurrent.futures.Future[str | None]": + staging = self._register_stage(index) + threading.Thread(target=self._stage, args=(index, staging), name="raven-stage", daemon=True).start() + return staging + + @staticmethod + def _register_stage(index: Path) -> "concurrent.futures.Future[str | None]": + staging: concurrent.futures.Future[str | None] = concurrent.futures.Future() + # Running from the start, so a waiter that gives up and cancels its + # wrapper cannot cancel the staging itself: the warm-up sets its repo up + # before it stages, and a staging cancelled in that window lost its + # result and raised on its thread when it finished. + staging.set_running_or_notify_cancel() + _STAGING[index] = staging + return staging + + def _stage(self, index: Path, result: "concurrent.futures.Future[str | None]") -> None: + """``git add -A`` then ``git write-tree`` on the staging index, on a thread of its own. + + A thread and blocking runs rather than asyncio subprocesses: a staging + outlives the call that started it whenever it is slow, and an asyncio + subprocess still starting when its loop closes holds the close up for + good (CPython 3.12, macOS). Both steps under one lock per index, because + ``write-tree`` writes the index back too and a second staging's ``add`` + beside it fails on the index lock. + """ + with _STAGE_LOCKS.setdefault(index, threading.Lock()): + if self._stage_step(("add", "-A"), index, timeout=_STAGE_ADD_TIMEOUT_SECONDS) is None: + result.set_result(None) + return + tree = self._stage_step(("write-tree",), index) + result.set_result(tree or None) + + def _stage_step(self, args: tuple[str, ...], index: Path, *, timeout: float | None = None) -> str | None: + """One git step of a staging: its output, or ``None`` when it failed.""" + if timeout is None: + timeout = _GIT_TIMEOUT_SECONDS + cmd, env = self._command(args, index) + try: + done = subprocess.run( + cmd, + cwd=str(self._workspace), + env=env, + stdin=subprocess.DEVNULL, + capture_output=True, + timeout=timeout, + ) + except subprocess.TimeoutExpired: + logger.debug("checkpoint stage timed out after {}s: {}", timeout, " ".join(args)) + # A killed git leaves the index lock behind, and every later stage + # would then fail on it. The index is this process's own and the + # stage lock is held, so no live git owns the lock. + with contextlib.suppress(OSError): + Path(f"{index}.lock").unlink() + return None + except OSError as exc: + logger.debug("checkpoint stage error: {}", exc) + return None + if done.returncode != 0: + logger.debug("checkpoint stage failed: {}", done.stderr.decode(errors="replace").strip()) + return None + return done.stdout.decode(errors="replace").strip() + + async def read_blobs(self, tree: str, paths: Collection[str], *, max_bytes: int) -> dict[str, bytes]: + """What each of ``paths`` held in ``tree``, keyed by the path as given. + + A path is left out when the tree never had it (new, ignored, excluded), + when it lies outside the work-tree, or when it held more than + ``max_bytes`` -- a caller reads a missing key as "not known", never as + "empty". + """ + rel_of: dict[str, str] = {} + for path in paths: + try: + rel = Path(path).resolve().relative_to(self._workspace).as_posix() + except (OSError, ValueError): + continue + if "\n" not in rel: + rel_of[path] = rel + if not rel_of: + return {} + wanted = list(rel_of.items()) + # A name that is not UTF-8 reaches Python surrogate-escaped; git wants + # the bytes the filesystem holds. + query = "".join(f"{tree}:{rel}\n" for _, rel in wanted).encode(errors="surrogateescape") + rc, out, _ = await self._run(("cat-file", "--batch-check"), stdin=query) + lines = out.decode(errors="replace").splitlines() + if rc != 0 or len(lines) != len(wanted): + return {} + small: list[tuple[str, str]] = [] + for (path, _), line in zip(wanted, lines): + parts = line.split() + if len(parts) == 3 and parts[1] == "blob" and parts[2].isdigit() and int(parts[2]) <= max_bytes: + small.append((path, parts[0])) + if not small: + return {} + rc, out, _ = await self._run(("cat-file", "--batch"), stdin="".join(f"{sha}\n" for _, sha in small).encode()) + if rc != 0: + return {} + found: dict[str, bytes] = {} + at = 0 + for path, _ in small: + end = out.find(b"\n", at) + if end < 0: + break + header = out[at:end].split() + if len(header) != 3 or not header[2].isdigit(): + break + size = int(header[2]) + found[path] = out[end + 1 : end + 1 + size] + at = end + 1 + size + 1 + return found + + async def trackable(self, paths: Collection[str]) -> set[str]: + """The subset of ``paths`` this repo would store, keyed by the path as given. + + By the repo's own rules -- the default excludes (credentials, ``.env``, + keys) and the work-tree's ``.gitignore`` files -- judged on the rules + alone, not on what an index happens to hold. The boundary a command's + created files must respect before their contents go anywhere: the + checkpoint keeps an ignored file out of storage, so its text must not + reach a diff either. A path outside the work-tree is never trackable, + and when git cannot answer nothing is. + """ + if not await self._ensure_init(): + return set() + rel_of: dict[str, str] = {} + for path in paths: + try: + rel_of[path] = Path(path).resolve().relative_to(self._workspace).as_posix() + except (OSError, ValueError): + continue + if not rel_of: + return set() + query = "".join(f"{rel}\0" for rel in rel_of.values()).encode(errors="surrogateescape") + rc, out, _ = await self._run(("check-ignore", "--no-index", "-z", "--stdin"), stdin=query) + # 0: some are ignored, 1: none are; anything else is git failing to say. + if rc not in (0, 1): + return set() + ignored = set(out.decode(errors="surrogateescape").split("\0")) - {""} + return {path for path, rel in rel_of.items() if rel not in ignored} + + def _stage_path(self) -> Path: + """This process's staging index. + + Per process because two processes can run commands in one directory and + an index is a single file. Seeded from the shared one (``_prepare_index``) + so a first staging finds git's stat cache already warm from the last + turn's commit instead of hashing the whole tree again. + """ + return self._git_dir / f"exec-{os.getpid()}.index" + + def _prepare_index(self, index: Path) -> None: + if not self._stage_pruned: + self._stage_pruned = True + now = time.time() + for other in self._git_dir.glob("exec-*.index"): + with contextlib.suppress(OSError): + if now - other.stat().st_mtime > _STAGE_INDEX_STALE_SECONDS: + other.unlink() + shared = self._git_dir / "index" + if not index.exists() and shared.exists(): + with contextlib.suppress(OSError): + shutil.copyfile(shared, index) + async def _maybe_gc(self) -> None: """Periodic ``git gc --auto`` so long-lived sessions don't accumulate loose objects forever. ``--auto`` is a no-op below ``gc.auto`` (256 @@ -326,4 +680,4 @@ async def _maybe_gc(self) -> None: logger.debug("checkpoint gc failed: {}", err.strip()) -__all__ = ["CheckpointService"] +__all__ = ["CheckpointService", "StagingTimeoutError"] diff --git a/raven/agent/loop/turn_path.py b/raven/agent/loop/turn_path.py index ee806f243..55b141a95 100644 --- a/raven/agent/loop/turn_path.py +++ b/raven/agent/loop/turn_path.py @@ -50,7 +50,6 @@ _file_removed_payload, _file_written_payload, _first_line, - _listing_removals, _runtime_origin, _stamp_reasoning_ms, _strip_inline_images, @@ -85,7 +84,6 @@ from raven.agent.loop.dead_end import NO_RESPONSE_FALLBACK, dead_reasons from raven.agent.loop.first_call import FirstCallGuard from raven.agent.loop.recovery import ContinuationGate, DraftGate, cut_reasoning_head, lower_reasoning_effort -from raven.agent.tools import snapshot as workdir_snapshot from raven.agent.tools.registry import call_failed from raven.agent.tools.removals import RemovalWatch from raven.agent.window import shrink @@ -103,6 +101,8 @@ from raven.token_wise.turn_spend import TurnSpend if TYPE_CHECKING: + from pathlib import Path + from raven.agent.loop.checkpoint import CheckpointService from raven.contracts.token_strategy import UsageSnapshot from raven.providers.base import ErrorClassification @@ -291,7 +291,13 @@ def _turn_checkpoint(self) -> "CheckpointService | None": would cross-contaminate their edited-file sets. """ target = workdir.current() - if target is None or not self._checkpoint_enabled: + if target is None: + return None + return self._checkpoint_for(target) + + def _checkpoint_for(self, target: Path) -> "CheckpointService | None": + """The shadow-git service for ``target``, made on first use; ``None`` when off.""" + if not self._checkpoint_enabled: return None if target not in self._checkpoints: from raven.agent.loop.checkpoint import CheckpointService @@ -306,6 +312,17 @@ def _turn_checkpoint(self) -> "CheckpointService | None": self._checkpoints[target] = None return self._checkpoints[target] + def _command_shadow(self, root: Path) -> "CheckpointService | None": + """The shadow repo a command run in ``root`` is measured against (``ExecTool``). + + The turn's own, and only where it covers ``root``: a ``working_dir`` + outside it has no copy of what its files held. Outside a turn -- a + session being opened and warmed -- nothing is bound, and ``root`` is the + session's directory itself. + """ + repo = self._checkpoint_for(workdir.current() or root) + return repo if repo is not None and repo.covers(root) else None + def _stash_recovery(self, session_key: str, outcome: "LoopOutcome") -> None: """Remember an interrupted turn's snapshot so the next turn in this session gets a recovery prompt. No-op unless checkpoint is enabled @@ -725,6 +742,10 @@ async def _run_agent_loop( # noqa: C901 (cc 100: pre-existing, above the ceilin # files is seen. Per turn for the reason the counters above are: the loop # is a singleton and another session's turn is running beside this one. removal_watch = RemovalWatch() + # A session opened by its first message (a channel's) was never warmed + # as it opened: warm its directory here instead. Once per directory. + if (target := workdir.current()) is not None and (warm := getattr(self.tools.get("exec"), "warm", None)): + await warm(target) # Empty-response recovery state, local to the turn — the AgentLoop is a # long-lived singleton shared across sessions, so per-instance counters # would leak across turns; resetting here gives clean per-turn budgets. @@ -1296,11 +1317,6 @@ def _hook_rollback(decision) -> bool: setter(tool_call.id) set_current_tool_call_id(tool_call.id) tool_t0 = time.monotonic() - # The working directory either side of a command, set by the - # branch below that actually runs one. Nothing here for every - # other call, which is what the empty diff of two Nones means. - exec_before: workdir_snapshot.Snapshot | None = None - exec_after: workdir_snapshot.Snapshot | None = None tracker = self.strategies.get("usage_tracker") if tracker is not None: await tracker.record_tool_call(tool_call.name, tool_call.id) @@ -1338,31 +1354,10 @@ def _hook_rollback(decision) -> bool: if stalled_verdict is NoProgressAction.END_TURN: stalled_tool = tool_call.name else: - # Only around a command: every other tool reports the - # file it touched, and walking the directory twice per - # call would cost the turn far more than the one change - # it could find. Off the loop, because the walk is tens - # of milliseconds of it and every other session on this - # process waits behind them. The directory is the one - # the command runs in, which the tool itself resolves: - # the turn's unless the call names another. - exec_root = ( - workdir_snapshot.root_for( - self.tools.get(tool_call.name), - tool_call.arguments, - workdir.current() or self.workspace, - ) - if tool_call.name == "exec" - else None - ) - if exec_root is not None: - exec_before = await asyncio.to_thread(workdir_snapshot.take, exec_root) result = await self.tools.execute( tool_call.name, tool_call.arguments, run_meta=tool_call.run_meta ) duration_ms = int((time.monotonic() - tool_t0) * 1000) - if exec_before is not None: - exec_after = await asyncio.to_thread(workdir_snapshot.take, exec_root) # The result itself is left alone: the note is the # system's own line and is placed by add_tool_result AFTER # the untrusted fence closes, so the model reads it as this @@ -1403,23 +1398,7 @@ def _hook_rollback(decision) -> bool: # so the file it just wrote is not stat'ed to say it exists. tool_removed = removal_watch.settle(getattr(result, "removed", ())) removal_watch.note_write(getattr(result, "file_change", None)) - # What the listing found beside what the call said itself. The - # paths the result named are held out of it: the listing sees - # those too, and one write drawn twice is two files to a reader. - tool_change = getattr(result, "file_change", None) - accounted = [removal.path for removal in tool_removed] - if isinstance(getattr(tool_change, "path", None), str): - accounted.append(tool_change.path) - created, modified, deleted = workdir_snapshot.diff(exec_before, exec_after) - # Off the loop for the reason the walks above are: this reads - # every created file to number its lines, and one command can - # create hundreds. The removals stay here -- they read nothing. - tool_written = ( - await asyncio.to_thread(_file_written_payload, created, modified, exec_after, already=accounted) - if created or modified - else None - ) - tool_removed.extend(_listing_removals(deleted, already=accounted)) + tool_written = _file_written_payload(getattr(result, "written", ())) if emit_tool_event: await on_tool_event( "complete", @@ -1442,8 +1421,8 @@ def _hook_rollback(decision) -> bool: # The deletions, which no tool reports as its # result: a command's own watch plus the turn's. "file_removed": _file_removed_payload(tool_removed), - # And what a command wrote, which it reports even - # less: read off the directory either side of it. + # And what a command wrote, which its output never + # names: the tool reads it off the directory. "file_written": tool_written, }, ) diff --git a/raven/agent/loop/wiring.py b/raven/agent/loop/wiring.py index 84ca646a5..4f35a27ca 100644 --- a/raven/agent/loop/wiring.py +++ b/raven/agent/loop/wiring.py @@ -934,6 +934,8 @@ def _register_default_tools(self) -> None: path_append=self.exec_config.path_append, executor=self._executor, extra_allowed_dirs=(self.workspace,), + record_writes=True, + shadow=self._command_shadow, ) ) # The registry writer beside exec's machine channel, for the products diff --git a/raven/agent/tools/command_writes.py b/raven/agent/tools/command_writes.py new file mode 100644 index 000000000..3108e5e2f --- /dev/null +++ b/raven/agent/tools/command_writes.py @@ -0,0 +1,202 @@ +"""What a command wrote, read off its directory either side of the call. + +``exec`` returns a command's output and nothing else, so the files it created, +rewrote or removed leave no record unless the directory is looked at before and +after it runs. Two looks, both taken by the tool around the command itself: + +- a listing (:mod:`raven.agent.tools.snapshot`): which paths changed, by size + and mtime; +- the checkpoint's shadow repo, where one covers the directory: a tree staged + just before the command, which holds what a rewritten or removed file held. + Without it a rewrite is still reported, with no counts and no diff. + +The shadow repo is handed to the tool (:data:`ShadowFor`) rather than imported: +it belongs to the loop shell, which no tool imports. +""" + +from __future__ import annotations + +import asyncio +import difflib +import os +from dataclasses import dataclass +from pathlib import Path +from typing import Callable, Collection, Mapping, Protocol + +from raven.agent.tools import snapshot +from raven.contracts.tool import FileRemoval, FileWrite + +#: A file is read for its text only this size or under. Past it the count and +#: the diff are unknown rather than wrong: reading a gigabyte to number it +#: would cost the call more than the row it draws is worth. +TEXT_MAX_BYTES = 256 * 1024 + +#: What the diffs of one call may add up to, the budget a call's removed bodies +#: and whole-file changes already share. Past it the counts still go and the +#: diff is dropped whole: half a diff reads as a smaller change than happened. +DIFF_BUDGET_CHARS = 512 * 1024 + +#: What the model reads for a command that was not run because the tree its +#: changes are measured against did not finish staging in time: not run rather +#: than run unmeasured. Only a filesystem that has stopped answering takes that +#: long, so the reply says so instead of inviting a retry loop. +NOT_STAGED_REPLY = ( + "Error: the command was not run. Raven snapshots the working directory before a " + "command so it can record what the command changes, and the snapshot did not finish " + "within 2 minutes; the filesystem may be very slow or unresponsive. Tell the user " + "rather than retrying repeatedly." +) + + +class ShadowTree(Protocol): + """The part of the checkpoint's shadow repo a command is measured against. + + ``stage_tree`` raises :class:`TimeoutError` when the staging did not finish + within its wait, and returns ``None`` when the tree cannot be staged at all. + """ + + async def warm(self) -> None: ... + + async def stage_tree(self) -> str | None: ... + + async def read_blobs(self, tree: str, paths: Collection[str], *, max_bytes: int) -> dict[str, bytes]: ... + + async def trackable(self, paths: Collection[str]) -> set[str]: ... + + +#: The shadow repo that covers a directory, or ``None`` where there is none. +ShadowFor = Callable[[Path], "ShadowTree | None"] + + +@dataclass(frozen=True) +class Before: + """The directory as it was when the command started.""" + + root: Path + listing: snapshot.Snapshot | None + shadow: ShadowTree | None = None + tree: str | None = None + + +async def before(root: Path, shadow_for: ShadowFor | None) -> Before: + """Look at ``root`` just before a command runs in it. + + Raises :class:`TimeoutError` when the shadow tree did not finish staging: + the command must then not run, since whatever it changed could no longer be + measured. A directory too large to list is not staged at all -- no listing + means nothing is reported, and a staging would be paid for nothing. + + Off the event loop: the walk is tens of milliseconds of a turn, and every + other session on this process waits behind whatever the loop does. + """ + listing = await asyncio.to_thread(snapshot.take, root) + shadow = shadow_for(root) if listing is not None and shadow_for is not None else None + tree = await shadow.stage_tree() if shadow is not None else None + if tree is None: + return Before(root, listing) + return Before(root, listing, shadow, tree) + + +async def after( + start: Before, *, already: Collection[str] = () +) -> tuple[tuple[FileWrite, ...], tuple[FileRemoval, ...]]: + """What the command changed under ``start.root``: files written, files removed. + + ``already`` are the removals the command reported by name, which the listing + sees as well; reporting one again would draw a single deletion twice. + + A created file carries its text as a diff only where the shadow repo would + store it (``trackable``): a ``.env``, a key, anything the user's ``.gitignore`` + keeps out is exactly what the checkpoint keeps out of storage, and a diff is + stored with the conversation. A rewritten or removed file needs no such + check, since the tree only ever holds files the repo stores. + """ + listing = await asyncio.to_thread(snapshot.take, start.root) + accounted = {os.path.realpath(path) for path in already if isinstance(path, str) and path} + created, modified, deleted = ( + [path for path in paths if os.path.realpath(path) not in accounted] + for paths in snapshot.diff(start.listing, listing) + ) + held: dict[str, bytes] = {} + shown: set[str] = set() + if start.shadow is not None and start.tree is not None: + if modified or deleted: + held = await start.shadow.read_blobs(start.tree, [*modified, *deleted], max_bytes=TEXT_MAX_BYTES) + if created: + shown = await start.shadow.trackable(created) + # Off the loop too: this reads every written file, and one command can write hundreds. + written = ( + await asyncio.to_thread(_writes, created, modified, listing or {}, held, shown) if created or modified else () + ) + removed = tuple(FileRemoval(path=path, before=_decoded(held.get(path))) for path in deleted) + return written, removed + + +def _writes( + created: Collection[str], + modified: Collection[str], + listing: snapshot.Snapshot, + held: Mapping[str, bytes], + shown: Collection[str], +) -> tuple[FileWrite, ...]: + budget = DIFF_BUDGET_CHARS + out: list[FileWrite] = [] + for path, was_created in [*((path, True) for path in created), *((path, False) for path in modified)]: + size = listing.get(path, (0, 0))[0] + old = "" if was_created else _decoded(held.get(path)) + text = None if old is None else _small_text(path, size) + lines = len(text.splitlines()) if was_created and text is not None else None + if text is None or old is None: + out.append(FileWrite(path=path, created=was_created, size=size, lines=lines)) + continue + diff, added, removed = _line_diff(old, text, os.path.basename(path)) + if was_created and path not in shown: + diff = None + if diff is not None and len(diff) <= budget: + budget -= len(diff) + else: + diff = None + out.append( + FileWrite(path=path, created=was_created, size=size, lines=lines, added=added, removed=removed, diff=diff) + ) + return tuple(out) + + +def _small_text(path: str, size: int) -> str | None: + """A listed file as text, or ``None`` when it is not worth reading.""" + if size > TEXT_MAX_BYTES: + return None + try: + return Path(path).read_text(encoding="utf-8") + except (OSError, UnicodeDecodeError): + return None + + +def _decoded(raw: bytes | None) -> str | None: + if raw is None or len(raw) > TEXT_MAX_BYTES: + return None + try: + return raw.decode("utf-8") + except UnicodeDecodeError: + return None + + +def _line_diff(old: str, new: str, name: str) -> tuple[str | None, int, int]: + """A unified diff of ``old`` to ``new`` with its added and removed line counts.""" + rows = list(difflib.unified_diff(old.splitlines(), new.splitlines(), fromfile=name, tofile=name, lineterm="")) + body = rows[2:] + added = sum(1 for row in body if row.startswith("+")) + removed = sum(1 for row in body if row.startswith("-")) + return ("\n".join(rows) if rows else None), added, removed + + +__all__ = [ + "DIFF_BUDGET_CHARS", + "NOT_STAGED_REPLY", + "TEXT_MAX_BYTES", + "Before", + "ShadowFor", + "ShadowTree", + "after", + "before", +] diff --git a/raven/agent/tools/registry.py b/raven/agent/tools/registry.py index d9e69502b..c4605cf60 100644 --- a/raven/agent/tools/registry.py +++ b/raven/agent/tools/registry.py @@ -1016,6 +1016,7 @@ async def execute( diff = result.diff file_change = result.file_change removed = result.removed + written = result.written else: model_text, display_text = str(result), None retryable, blocks_call = True, False @@ -1028,6 +1029,7 @@ async def execute( # return is already a ToolOutput (exec) misses the unwrap above, # and its removals would be dropped at this boundary. removed = tuple(getattr(result, "removed", ()) or ()) + written = tuple(getattr(result, "written", ()) or ()) # Remembered once the verdict is in, and only when it is good. A # rule that asks for a prior ``read_file`` is asking whether the # file was read; a read that errored read nothing, and letting it @@ -1052,6 +1054,9 @@ async def execute( # # An error also replaces the result, so any blocks it came with # are no longer what the model should be looking at. + # + # What the call did to the disk is kept: a command whose output + # happens to begin with the word still removed and wrote what it did. suffix = _hint if retryable else "" return ToolOutput( model_text + suffix, @@ -1060,6 +1065,8 @@ async def execute( blocks_call=blocks_call, continuation=continuation, ok=False, + removed=removed, + written=written, ) return ToolOutput( model_text, @@ -1072,6 +1079,7 @@ async def execute( diff=diff, file_change=file_change, removed=removed, + written=written, ) except asyncio.TimeoutError: return f"Error: Tool '{name}' timed out after {ceiling:.0f}s." + _hint diff --git a/raven/agent/tools/removals.py b/raven/agent/tools/removals.py index 1cbfb77ff..85ca802a5 100644 --- a/raven/agent/tools/removals.py +++ b/raven/agent/tools/removals.py @@ -58,10 +58,14 @@ def settle(self, reported: Any = ()) -> list[FileRemoval]: removals = [ removal for removal in (reported or ()) if isinstance(getattr(removal, "path", None), str) and removal.path ] - already = {removal.path for removal in removals} + already = {removal.path: index for index, removal in enumerate(removals)} for path in list(self._touched): if path in already: - self._forget(path) + # What this run wrote there is the file's last known text, which + # a report read off the disk after the fact may not have. + text = self._forget(path) + if removals[already[path]].before is None and text is not None: + removals[already[path]] = FileRemoval(path=path, before=text) continue if not os.path.exists(path): removals.append(FileRemoval(path=path, before=self._forget(path))) diff --git a/raven/agent/tools/shell.py b/raven/agent/tools/shell.py index ec8ec548c..c18ef2a52 100644 --- a/raven/agent/tools/shell.py +++ b/raven/agent/tools/shell.py @@ -14,8 +14,19 @@ from pathlib import Path from typing import Any +from loguru import logger + from raven.agent import workdir -from raven.contracts.tool import STOP_RETRY_INSTRUCTION, Continuation, FileRemoval, Tool, ToolOutput, ToolResult +from raven.agent.tools import command_writes +from raven.contracts.tool import ( + STOP_RETRY_INSTRUCTION, + Continuation, + FileRemoval, + FileWrite, + Tool, + ToolOutput, + ToolResult, +) from raven.permissions.shell_policy import ( _MAX_EMBEDDED_SHELL_DEPTH, _command_segments_with_separators, @@ -46,9 +57,10 @@ def __init__(self, construct: str) -> None: class ExecTool(Tool): """Tool to execute shell commands.""" - # Backstop above the 600s internal exec cap (``_MAX_TIMEOUT``); the + # Backstop above the 600s internal exec cap (``_MAX_TIMEOUT``) plus the + # 120s a command may wait for the tree it is measured against; the # executor's own timeout fires first, this only catches a wedged executor. - timeout_seconds = 660.0 + timeout_seconds = 780.0 approval_kind = "shell.exec" def __init__( @@ -62,6 +74,8 @@ def __init__( extra_allowed_dirs: tuple[Path, ...] = (), *, follow_binding: bool = True, + record_writes: bool = False, + shadow: command_writes.ShadowFor | None = None, ): self._timeout = timeout self.working_dir = working_dir @@ -76,6 +90,12 @@ def __init__( # convention as the filesystem tools). The main loop's ExecTool keeps # following the live binding as normal. self.follow_binding = follow_binding + # Whether a command's result says which files it created, rewrote and + # removed, read off its directory either side (``command_writes``); and + # the shadow repo that says what those files held, for their diffs. + # Off for a lane whose runner lists every call itself. + self.record_writes = record_writes + self._shadow = shadow self.path_append = path_append self._executor: SandboxExecutor = executor if executor is not None else DirectExecutor() if not self._executor.is_sandboxed: @@ -104,6 +124,20 @@ def timeout(self) -> int: def name(self) -> str: return "exec" + async def warm(self, root: Path) -> None: + """Start staging ``root`` into the shadow repo, ahead of its first command. + + The first staging of a directory hashes every file in it, which in a + large tree takes long enough to hold a command up; started as a session + opens, it runs while the user types and the model replies. Returns at + once, and does nothing where no shadow repo covers ``root``. + """ + if not self.record_writes or self._shadow is None: + return + shadow = self._shadow(root) + if shadow is not None: + await shadow.warm() + _MAX_TIMEOUT = 600 _MAX_OUTPUT = 10_000 @@ -317,6 +351,13 @@ async def execute( # the result is gone, and one on another machine names paths that are # not this filesystem's. watched = self._removal_watch(command, cwd) + start: command_writes.Before | None = None + if self.record_writes: + try: + start = await command_writes.before(Path(cwd), self._shadow) + except TimeoutError: + logger.warning("exec not run: staging {} did not finish in time", cwd) + return ToolResult(model_text=command_writes.NOT_STAGED_REPLY, retryable=False, ok=False) env: dict[str, str] | None = None if self.path_append: @@ -336,16 +377,17 @@ async def execute( except Exception as e: return f"Error executing command: {str(e)}" text = result.as_text(self._MAX_OUTPUT) + removed = tuple( + FileRemoval(path=path, before=before) for path, before in watched.items() if not os.path.exists(path) + ) + written: tuple[FileWrite, ...] = () + if start is not None: + written, listed = await command_writes.after(start, already=[removal.path for removal in removed]) + removed += listed # The exit code is the verdict a config change, a security call or a # syntax error share, and the text a failing command produced is not # token-safe to classify from -- so the caller gets it structurally. - return ToolOutput( - text, - ok=result.exit_code == 0, - removed=tuple( - FileRemoval(path=path, before=before) for path, before in watched.items() if not os.path.exists(path) - ), - ) + return ToolOutput(text, ok=result.exit_code == 0, removed=removed, written=written) def _removal_watch(self, command: str, cwd: str) -> dict[str, str | None]: """The files this command could remove, with the text they hold now. diff --git a/raven/contracts/__init__.py b/raven/contracts/__init__.py index a26538841..c95a2ff18 100644 --- a/raven/contracts/__init__.py +++ b/raven/contracts/__init__.py @@ -17,4 +17,4 @@ makes a silent shape change a red gate. """ -CONTRACTS_VERSION = "32" +CONTRACTS_VERSION = "33" diff --git a/raven/contracts/tool.py b/raven/contracts/tool.py index f4365262e..c27fddb54 100644 --- a/raven/contracts/tool.py +++ b/raven/contracts/tool.py @@ -66,6 +66,31 @@ class FileRemoval: before: str | None = None +@dataclass(frozen=True) +class FileWrite: + """One file a command left behind, found by listing its directory either side. + + A command reports its output and nothing else, so unlike a :class:`FileChange` + this is read off the disk rather than handed over by the call, and carries + no whole contents: one command can write a hundred files. + + ``lines`` belongs to a created file alone; ``None`` there means unknown (too + large to read, or not text). ``added`` / ``removed`` and ``diff`` are the + change itself, present only when what the file held before is known -- a + count against contents nobody held would read as a change somebody measured. + ``diff`` can be absent beside the counts: a created file whose text must not + leave the machine, or a diff past the call's budget. + """ + + path: str + created: bool + size: int + lines: int | None = None + added: int | None = None + removed: int | None = None + diff: str | None = None + + #: What a call the model wrote beside a blocked one is told. Every loop that #: cancels siblings says this, and it has to be one string: it reaches the model, #: so two versions of it are two different instructions. @@ -153,6 +178,9 @@ class ToolResult: vanish. No tool deletes as its purpose, so it is the shell tool that reports it, from what it saw on disk either side of the command; empty means nothing vanished, which is what every other tool reports. + + ``written`` is what that same command created or rewrote, read the same way: + the files a command leaves behind, which its output never names. """ model_text: str @@ -172,6 +200,7 @@ class ToolResult: diff: str | None = None file_change: "FileChange | None" = None removed: tuple["FileRemoval", ...] = () + written: tuple["FileWrite", ...] = () class ToolOutput(str): @@ -197,6 +226,7 @@ class ToolOutput(str): diff: str | None file_change: "FileChange | None" removed: tuple["FileRemoval", ...] + written: tuple["FileWrite", ...] def __new__( cls, @@ -211,6 +241,7 @@ def __new__( diff: str | None = None, file_change: "FileChange | None" = None, removed: tuple["FileRemoval", ...] = (), + written: tuple["FileWrite", ...] = (), ) -> "ToolOutput": out = super().__new__(cls, model_text) out.display_text = display_text @@ -222,6 +253,7 @@ def __new__( out.diff = diff out.file_change = file_change out.removed = removed + out.written = written return out @@ -404,6 +436,7 @@ def to_schema(self) -> dict[str, Any]: "Continuation", "FileChange", "FileRemoval", + "FileWrite", "ImagePart", "ImageURL", "RAW_ARGUMENTS_KEY", diff --git a/raven/rpc/methods/session.py b/raven/rpc/methods/session.py index 7c92566df..7149491a0 100644 --- a/raven/rpc/methods/session.py +++ b/raven/rpc/methods/session.py @@ -182,6 +182,26 @@ def _session_cwd(agent_loop: "AgentLoop | None", session_key: str | None) -> str return os.getcwd() +async def _warm_workdir(agent_loop: "AgentLoop | None", session_key: str) -> None: + """Start the shadow-repo staging for the directory this session opens on. + + As the session opens rather than inside its first command, which would + otherwise hash a large tree before it could run (``ExecTool.warm``). + Returns at once, and never fails the open. + """ + if agent_loop is None: + return + try: + warm = getattr(agent_loop.tools.get("exec"), "warm", None) + if warm is None: + return + target = agent_loop.peek_session_workdir(session_key) + if target.is_dir(): + await warm(target) + except Exception as exc: # noqa: BLE001 -- a warm-up never breaks a session open + logger.debug("session: warm-up for {} failed: {}", session_key, exc) + + def _session_model(agent_loop: "AgentLoop | None", config: "Config", session_key: str | None) -> str: """The model a session runs on: its own when it has one, else the default. @@ -462,6 +482,7 @@ async def session_create( raise ConfigValidationError(str(e), data={"field": "workdir"}) from e manager_for(agent_loop, config).get_or_create(session_id).metadata["workdir"] = str(resolved) info["cwd"] = str(resolved) + await _warm_workdir(agent_loop, session_id) return { "session_id": session_id, "info": info, @@ -536,6 +557,7 @@ async def session_resume( title = (raw.metadata or {}).get("title") if isinstance(title, str) and title: info["title"] = title + await _warm_workdir(agent_loop, session_key) return { "session_id": session_key, "info": info, diff --git a/raven/rpc/models.py b/raven/rpc/models.py index aaffccde5..3a145e682 100644 --- a/raven/rpc/models.py +++ b/raven/rpc/models.py @@ -656,8 +656,11 @@ class FileWritten(_Strict): Neither a :class:`FileChange` nor a :class:`FileRemoval`: a command reports its output and nothing else, so what is known of the file is what two listings of the directory said about it -- that it is there, how big it is, - and whether it was there before. No contents either way, because one command - can write a hundred files and a row draws none of their text. + and whether it was there before. What it changed from is known only when the + working directory's shadow repo held a copy from just before the command; + then the change itself rides along as counts and a unified diff. A created + file carries its counts, and its text only when the shadow repo would store + it: never for a file its excludes or the user's .gitignore keep out. """ path: str = Field(description="Absolute path of the file the command wrote.") @@ -677,6 +680,25 @@ class FileWritten(_Strict): "change therefore has no number." ), ) + added: int | None = Field( + default=None, + description=( + "Lines the command added to the file. Absent when the change could not be measured: " + "not text, too large, or a rewrite whose previous contents were never captured." + ), + ) + removed: int | None = Field( + default=None, + description="Lines the command removed from the file. Absent exactly when added is.", + ) + diff: str | None = Field( + default=None, + description=( + "Unified diff of the change, when it was measured and small enough to carry. " + "Absent past the event's budget even when the counts are present: a partial " + "diff reads as a smaller change than the one that happened." + ), + ) class ToolCompletePayload(_Strict): diff --git a/rpc-schema/openrpc.json b/rpc-schema/openrpc.json index ab746a5c6..d2354ab41 100644 --- a/rpc-schema/openrpc.json +++ b/rpc-schema/openrpc.json @@ -12317,7 +12317,7 @@ } }, "FileWritten": { - "description": "One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before.", + "description": "One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A created file carries its counts, and its text only when the shadow repo would store it: never for a file its excludes or the user's .gitignore keep out.", "type": "object", "additionalProperties": false, "required": [ @@ -12344,6 +12344,27 @@ "null" ], "description": "Lines in a created file, when it could be counted. Null, not absent: the key is always sent, and null says the count is unknown. Too large to read, not text, or a file that already existed, whose change therefore has no number." + }, + "added": { + "type": [ + "integer", + "null" + ], + "description": "Lines the command added to the file. Absent when the change could not be measured: not text, too large, or a rewrite whose previous contents were never captured." + }, + "removed": { + "type": [ + "integer", + "null" + ], + "description": "Lines the command removed from the file. Absent exactly when added is." + }, + "diff": { + "type": [ + "string", + "null" + ], + "description": "Unified diff of the change, when it was measured and small enough to carry. Absent past the event's budget even when the counts are present: a partial diff reads as a smaller change than the one that happened." } } }, diff --git a/tests/conftest.py b/tests/conftest.py index 20040c91a..2e9e75b02 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -323,6 +323,20 @@ def _spent(started: _Clocks, now: _Clocks) -> tuple[float, float, float]: return wall, wall - cpu - queued_s, queued_s +@pytest.hookimpl(tryfirst=True) +def pytest_runtest_teardown(item: pytest.Item, nextitem: pytest.Item | None) -> None: + """Let a checkpoint warm-up the test started finish before its fixtures go. + + A turn stages its working directory into the shadow repo on a thread of its + own (``CheckpointService.warm``), and a fixture removing that directory + under a git still writing into it fails the cleanup. Ahead of the fixture + finalizers, which run in the default teardown after this one. + """ + for thread in threading.enumerate(): + if thread.name == "raven-stage": + thread.join(30) + + @pytest.hookimpl(hookwrapper=True) def pytest_runtest_protocol(item: pytest.Item, nextitem: pytest.Item | None): item.stash[_CLOCKS] = _clocks() diff --git a/tests/test_agent_loop_session_stamps.py b/tests/test_agent_loop_session_stamps.py index 0b3a40c06..f43492218 100644 --- a/tests/test_agent_loop_session_stamps.py +++ b/tests/test_agent_loop_session_stamps.py @@ -10,9 +10,10 @@ from __future__ import annotations +import asyncio import json import tempfile -import threading +import time from pathlib import Path from typing import Any @@ -20,10 +21,12 @@ from raven.agent import workdir from raven.agent.loop import AgentLoop -from raven.agent.loop._shared import _FILE_WRITTEN_TEXT_MAX_BYTES -from raven.agent.loop.bundles import ToolWiring, TurnPolicy -from raven.contracts.tool import FileChange, FileRemoval, Tool, ToolResult +from raven.agent.loop.bundles import EngineWiring, ToolWiring, TurnPolicy +from raven.agent.tools import command_writes +from raven.config.raven import CheckpointConfig, RuntimeConfig +from raven.contracts.tool import FileRemoval, Tool, ToolResult from raven.providers.base import LLMProvider, LLMResponse +from raven.sandbox import ExecResult, SandboxExecutor from raven.spine.events import ToolEvent, ToolPhase from raven.spine.message import ChatType, Source from raven.spine.turn import Origin, TurnRequest @@ -541,56 +544,73 @@ async def test_a_call_that_removed_nothing_carries_no_removal_at_all(workspace): assert "file_removed" not in tool_entry and "_file_removed" not in tool_entry -class _CommandTool(Tool): - """Stands in for ``exec``: it changes files and reports only that it ran. +class _PythonExecutor(SandboxExecutor): + """Runs a Python action where the shell would run, behind the real ``exec``. - Registered under that name because the name is the decision under test -- - the loop lists the working directory around a command and around nothing - else. What it runs is Python rather than a shell so each test states the - change it wants instead of depending on a shell's own behaviour. + The tool around it is the one the loop wired -- its fence, its removal + watch, its listing and its shadow repo all run as served -- so each test + states the change it wants instead of depending on a shell's own behaviour. """ - def __init__(self, action: Any, *, removed: Any = (), change: Any = None) -> None: + def __init__(self, action: Any, *, stdout: str = "ran") -> None: self._action = action - self._removed = removed - self._change = change + self._stdout = stdout @property - def name(self) -> str: - return "exec" - - @property - def description(self) -> str: - return "runs a command" + def is_sandboxed(self) -> bool: + return False - @property - def parameters(self) -> dict: - return {"type": "object", "properties": {"command": {"type": "string"}}, "required": ["command"]} - - async def execute(self, command: str = "", **kwargs: Any) -> Any: + async def exec( + self, command: str, cwd: str | None = None, timeout: int | None = None, env: dict[str, str] | None = None + ) -> ExecResult: self._action() - if self._removed or self._change is not None: - return ToolResult(model_text="ran", removed=tuple(self._removed), file_change=self._change) - return "ran" - - -async def _run_command_turn(workspace: Path, work: Path, script: list[LLMResponse], *extra_tools: Tool): - """One real turn whose working directory is ``work``, as a served turn has. - - Bound rather than defaulted so the listing covers the directory the command - ran in and not the session store beside it. The checkpoint is off because - its shadow repo is a second tree inside that same directory, built for a - recovery nothing here tests. + return ExecResult(stdout=self._stdout, stderr="", exit_code=0) + + +def _command_agent( + workspace: Path, + script: list[LLMResponse], + action: Any = None, + *, + checkpoint: bool = False, + provider: LLMProvider | None = None, +) -> AgentLoop: + """A loop with its own ``exec``, running ``action`` in place of the shell when given. + + The checkpoint is off unless a test asks for it: its shadow repo is what a + command's diff is read against, and without it a rewrite is reported with + no measure of what changed. """ agent = AgentLoop( - provider=ScriptedProvider(script), + provider=provider or ScriptedProvider(script), workspace=workspace, model="stub", policy=TurnPolicy(max_iterations=4, interactive=False), tools=ToolWiring(restrict_to_workspace=True), + engine=EngineWiring( + runtime_config=RuntimeConfig(checkpoint=CheckpointConfig(policy="always" if checkpoint else "never")) + ), ) - for tool in extra_tools: - agent.tools.register(tool) + if action is not None: + agent.tools.get("exec")._executor = _PythonExecutor(action) + return agent + + +async def _run_command_turn( + workspace: Path, + work: Path, + script: list[LLMResponse], + action: Any = None, + *, + checkpoint: bool = False, + provider: LLMProvider | None = None, +): + """One real turn whose working directory is ``work``, as a served turn has. + + Bound rather than defaulted so the command runs in, and is measured in, the + directory the test prepared and not the session store beside it. + """ + agent = _command_agent(workspace, script, action, checkpoint=checkpoint, provider=provider) completes: list[dict[str, Any]] = [] async def on_tool_event(phase: str, info: dict[str, Any]) -> None: @@ -616,21 +636,24 @@ async def test_a_file_a_command_created_reaches_the_event_and_the_stored_entry(w no record at all unless the directory is read either side of the call. The line count is the created file's own: a client draws an added file with - how much arrived, and the command's output never says.""" + how much arrived, and the command's output never says. Without a shadow + repo there are no rules to say which files may be stored, so the text of + the file stays out of the entry and only its counts go.""" work = workspace / "work" work.mkdir() made = work / "made.txt" completes = await _run_command_turn( - workspace, work, _command_script(), _CommandTool(lambda: made.write_text("one\ntwo\n", encoding="utf-8")) + workspace, work, _command_script(), lambda: made.write_text("one\ntwo\n", encoding="utf-8") ) written = completes[0]["file_written"] assert len(written) == 1, written assert Path(written[0]["path"]).resolve() == made.resolve() assert written[0]["created"] is True - assert written[0]["lines"] == 2 + assert (written[0]["lines"], written[0]["added"], written[0]["removed"]) == (2, 2, 0) assert written[0]["size"] == len("one\ntwo\n") + assert "diff" not in written[0] tool_entry = next(m for m in _persisted_messages(workspace) if m.get("role") == "tool") assert "_file_written" not in tool_entry, "the in-flight key must be renamed at save time" assert tool_entry["file_written"] == written @@ -638,19 +661,17 @@ async def test_a_file_a_command_created_reaches_the_event_and_the_stored_entry(w @pytest.mark.asyncio async def test_a_file_a_command_rewrote_is_not_reported_as_a_new_one(workspace): - """A rewrite carries no count. The listing holds sizes, never contents, so - the old text was never known and a number against it would be invented -- - and a client that drew this as a creation would claim the whole file is new.""" + """Without a shadow repo a rewrite carries no count. The listing holds sizes, + never contents, so the old text was never known and a number against it + would be invented -- and a client that drew this as a creation would claim + the whole file is new.""" work = workspace / "work" work.mkdir() kept = work / "kept.txt" kept.write_text("one\n", encoding="utf-8") completes = await _run_command_turn( - workspace, - work, - _command_script(), - _CommandTool(lambda: kept.write_text("three\nfour\nfive\n", encoding="utf-8")), + workspace, work, _command_script(), lambda: kept.write_text("three\nfour\nfive\n", encoding="utf-8") ) written = completes[0]["file_written"] @@ -659,22 +680,142 @@ async def test_a_file_a_command_rewrote_is_not_reported_as_a_new_one(workspace): assert written[0]["created"] is False assert written[0]["lines"] is None assert written[0]["size"] == len("three\nfour\nfive\n") + assert "added" not in written[0] and "removed" not in written[0] and "diff" not in written[0] + + +@pytest.mark.asyncio +async def test_a_file_a_command_rewrote_carries_its_diff_when_the_shadow_repo_held_it(workspace): + """The tree staged in front of the command holds what the file said, so the + change is measured the way a file tool's is: counts and a unified diff of + only what the command did, not the whole file again. And it is stored with + the entry, so a reload draws what the live page drew.""" + work = workspace / "work" + work.mkdir() + kept = work / "kept.txt" + kept.write_text("one\ntwo\nthree\n", encoding="utf-8") + + completes = await _run_command_turn( + workspace, + work, + _command_script(), + lambda: kept.write_text("one\n2\nthree\nfour\n", encoding="utf-8"), + checkpoint=True, + ) + + written = completes[0]["file_written"] + assert len(written) == 1, written + assert written[0]["created"] is False + assert (written[0]["added"], written[0]["removed"]) == (2, 1) + body = written[0]["diff"].splitlines() + assert "-two" in body and "+2" in body and "+four" in body + assert " one" in body, "unchanged lines are context, not a rewrite" + tool_entry = next(m for m in _persisted_messages(workspace) if m.get("role") == "tool") + assert tool_entry["file_written"] == written + + +@pytest.mark.asyncio +async def test_a_file_a_command_created_carries_its_diff(workspace): + """A new file needs no earlier copy: everything in it was added. The same + shape as a rewrite's, so a client draws both the one way.""" + work = workspace / "work" + work.mkdir() + made = work / "made.txt" + + completes = await _run_command_turn( + workspace, + work, + _command_script(), + lambda: made.write_text("one\ntwo\n", encoding="utf-8"), + checkpoint=True, + ) + + written = completes[0]["file_written"] + assert (written[0]["added"], written[0]["removed"], written[0]["lines"]) == (2, 0, 2) + assert written[0]["diff"].splitlines()[2:] == ["@@ -0,0 +1,2 @@", "+one", "+two"] + + +@pytest.mark.asyncio +@pytest.mark.parametrize("name", [".env", "local.secret"]) +async def test_a_created_file_the_shadow_repo_would_not_store_carries_no_text(workspace, name): + """The checkpoint keeps credentials and whatever the user's .gitignore names + out of storage, and a diff is stored with the conversation. A command that + creates one of those files is reported with its counts and none of its text.""" + work = workspace / "work" + work.mkdir() + (work / ".gitignore").write_text("*.secret\n", encoding="utf-8") + made = work / name + + completes = await _run_command_turn( + workspace, + work, + _command_script(), + lambda: made.write_text("API_KEY=top-secret\n", encoding="utf-8"), + checkpoint=True, + ) + + written = completes[0]["file_written"] + assert len(written) == 1, written + assert "diff" not in written[0] + assert (written[0]["added"], written[0]["removed"]) == (1, 0) + assert "top-secret" not in json.dumps(_persisted_messages(workspace)) + + +@pytest.mark.asyncio +async def test_a_command_that_ran_before_this_one_is_not_part_of_its_diff(workspace): + """The tree is staged in front of each command, not once per turn: a second + command's diff is what the second command did, against the file as the + first one left it.""" + work = workspace / "work" + work.mkdir() + kept = work / "kept.txt" + kept.write_text("one\n", encoding="utf-8") + steps = iter(["one\ntwo\n", "one\ntwo\nthree\n"]) + script = [ + _tool_call("c1", "exec", {"command": "first"}), + _tool_call("c2", "exec", {"command": "second"}), + LLMResponse(content="done", finish_reason="stop"), + ] + + completes = await _run_command_turn( + workspace, work, script, lambda: kept.write_text(next(steps), encoding="utf-8"), checkpoint=True + ) + + assert [(c["file_written"][0]["added"], c["file_written"][0]["removed"]) for c in completes] == [(1, 0), (1, 0)] + assert "+three" in completes[1]["file_written"][0]["diff"].splitlines() + assert "+two" not in completes[1]["file_written"][0]["diff"].splitlines() + + +@pytest.mark.asyncio +async def test_a_rewrite_the_shadow_repo_does_not_hold_is_reported_without_a_diff(workspace): + """A file the shadow repo excludes (here a ``.env``, kept out as a likely + credential) has no earlier copy, so its rewrite is reported bare rather + than measured against nothing.""" + work = workspace / "work" + work.mkdir() + secret = work / ".env" + secret.write_text("A=1\n", encoding="utf-8") + + completes = await _run_command_turn( + workspace, work, _command_script(), lambda: secret.write_text("A=2\n", encoding="utf-8"), checkpoint=True + ) + + written = completes[0]["file_written"] + assert len(written) == 1, written + assert "added" not in written[0] and "diff" not in written[0] @pytest.mark.asyncio async def test_a_file_a_command_removed_without_naming_it_is_still_reported(workspace): """The turn never wrote this file, so the watch on its own writes cannot see it go and the command named nothing the fence could resolve. The listing is - the only witness, and it has no body to offer: the file was gone before - anything read it.""" + the only witness, and without a shadow repo it has no body to offer: the + file was gone before anything read it.""" work = workspace / "work" work.mkdir() doomed = work / "doomed.txt" doomed.write_text("one\ntwo\n", encoding="utf-8") - completes = await _run_command_turn( - workspace, work, _command_script("find . -name '*.txt' -delete"), _CommandTool(doomed.unlink) - ) + completes = await _run_command_turn(workspace, work, _command_script("find . -name '*.txt' -delete"), doomed.unlink) removed = completes[0]["file_removed"] assert len(removed) == 1, removed @@ -686,45 +827,87 @@ async def test_a_file_a_command_removed_without_naming_it_is_still_reported(work @pytest.mark.asyncio -async def test_a_removal_the_command_reported_is_not_reported_twice(workspace): - """The listing sees the same deletion the tool named. Reported once: two - rows for one file read as two files, and the row that carries the file's - last contents is the one worth keeping.""" +async def test_a_file_a_command_removed_carries_what_it_held_when_the_shadow_repo_had_it(workspace): + """The listing sees the file go after it is gone; the staged tree still has + it, which is the body a deletion row draws.""" work = workspace / "work" work.mkdir() doomed = work / "doomed.txt" doomed.write_text("one\ntwo\n", encoding="utf-8") completes = await _run_command_turn( - workspace, - work, - _command_script(f"rm {doomed}"), - _CommandTool(doomed.unlink, removed=(FileRemoval(path=str(doomed), before="one\ntwo\n"),)), + workspace, work, _command_script("find . -name '*.txt' -delete"), doomed.unlink, checkpoint=True ) - assert completes[0]["file_removed"] == [{"path": str(doomed), "before": "one\ntwo\n"}] + removed = completes[0]["file_removed"] + assert len(removed) == 1, removed + assert removed[0]["before"] == "one\ntwo\n" + tool_entry = next(m for m in _persisted_messages(workspace) if m.get("role") == "tool") + assert tool_entry["file_removed"] == [{"path": removed[0]["path"], "del": 2}] @pytest.mark.asyncio -async def test_a_file_the_call_already_named_is_not_reported_a_second_time(workspace): - """A call that reports its own write is believed over the listing: the - result carries the contents, which a listing of sizes never can.""" +async def test_a_removal_the_command_named_is_not_reported_twice(workspace): + """The listing sees the same deletion the command's own watch caught by + name. Reported once: two rows for one file read as two files, and the row + that carries the file's last contents is the one worth keeping.""" + work = workspace / "work" + work.mkdir() + doomed = work / "doomed.txt" + doomed.write_text("one\ntwo\n", encoding="utf-8") + + completes = await _run_command_turn(workspace, work, _command_script(f"rm {doomed}"), doomed.unlink) + + removed = completes[0]["file_removed"] + assert len(removed) == 1, removed + assert Path(removed[0]["path"]).resolve() == doomed.resolve() + assert removed[0]["before"] == "one\ntwo\n" + + +@pytest.mark.asyncio +async def test_a_file_this_turn_wrote_keeps_its_text_when_a_command_removes_it_unseen(workspace): + """The listing reports the deletion without a body when no shadow repo held + the file. The turn itself wrote it, though, so what it wrote is still the + last thing anyone knew the file to hold.""" work = workspace / "work" work.mkdir() made = work / "made.txt" + script = [ + _tool_call("c1", "write_file", {"path": str(made), "content": "x\ny\n"}), + _tool_call("c2", "exec", {"command": "find . -name '*.txt' -delete"}), + LLMResponse(content="done", finish_reason="stop"), + ] - completes = await _run_command_turn( - workspace, - work, - _command_script(), - _CommandTool( - lambda: made.write_text("one\ntwo\n", encoding="utf-8"), - change=FileChange(path=str(made), before=None, after="one\ntwo\n"), - ), + completes = await _run_command_turn(workspace, work, script, made.unlink) + + removed = completes[1]["file_removed"] + assert len(removed) == 1, removed + assert removed[0]["before"] == "x\ny\n" + + +@pytest.mark.asyncio +async def test_a_command_whose_output_reads_as_an_error_still_reports_its_files(workspace): + """The registry treats a result that begins with "Error" as a failure and + rebuilds it. What the command did to the disk happened all the same, and + has no other carrier.""" + work = workspace / "work" + work.mkdir() + made = work / "made.txt" + agent = _command_agent(workspace, _command_script()) + agent.tools.get("exec")._executor = _PythonExecutor( + lambda: made.write_text("one\n", encoding="utf-8"), stdout="Error: half of it failed" ) + completes: list[dict[str, Any]] = [] - assert completes[0]["file_change"] == {"path": str(made), "after": "one\ntwo\n"} - assert completes[0]["file_written"] is None + async def on_tool_event(phase: str, info: dict[str, Any]) -> None: + if phase == "complete": + completes.append(info) + + with workdir.bind(work): + await agent._process_message(_make_msg("run it"), on_tool_event=on_tool_event) + + assert completes[0]["ok"] is False + assert [Path(w["path"]).resolve() for w in completes[0]["file_written"]] == [made.resolve()] @pytest.mark.asyncio @@ -735,7 +918,7 @@ async def test_a_command_that_changed_nothing_carries_neither_key(workspace): work.mkdir() (work / "kept.txt").write_text("one\n", encoding="utf-8") - completes = await _run_command_turn(workspace, work, _command_script("ls"), _CommandTool(lambda: None)) + completes = await _run_command_turn(workspace, work, _command_script("ls"), lambda: None) assert completes[0]["file_written"] is None assert completes[0]["file_removed"] is None @@ -770,10 +953,10 @@ async def test_a_tool_that_is_not_a_command_is_never_worth_a_listing(workspace, @pytest.mark.asyncio async def test_the_real_command_tool_lists_the_directory_it_was_bound_to(workspace): - """The stubs above stand in for ``exec`` and agree with the listing by - construction. The one agreement the feature rests on is that the shell runs - in the directory the listing walks, and only the shell itself can show it: - ``ExecTool`` resolves its cwd from the same binding this turn is under.""" + """The executor above stands in for the shell. The one agreement the + feature rests on is that the shell runs in the directory the listing + walks, and only the shell itself can show it: ``ExecTool`` resolves its cwd + from the same binding this turn is under.""" work = workspace / "work" work.mkdir() (work / "keep.md").write_text("one\n", encoding="utf-8") @@ -789,6 +972,23 @@ async def test_the_real_command_tool_lists_the_directory_it_was_bound_to(workspa assert written[(work / "keep.md").resolve()]["created"] is False +@pytest.mark.asyncio +async def test_the_real_command_tool_rewrite_is_measured_against_the_staged_tree(workspace): + """A real shell writes through its own cwd, which is the tree the stage + covers -- the one agreement between the shell and the shadow repo only the + real tool can show.""" + work = workspace / "work" + work.mkdir() + (work / "keep.md").write_text("one\n", encoding="utf-8") + + completes = await _run_command_turn(workspace, work, _command_script("echo two >> keep.md"), checkpoint=True) + + written = completes[0]["file_written"] + assert [Path(w["path"]).resolve() for w in written] == [(work / "keep.md").resolve()] + assert (written[0]["added"], written[0]["removed"]) == (1, 0) + assert "+two" in written[0]["diff"].splitlines() + + @pytest.mark.asyncio async def test_a_created_file_that_is_not_text_is_reported_without_a_count(workspace): """A command writes images and archives as readily as it writes text, and a @@ -799,7 +999,7 @@ async def test_a_created_file_that_is_not_text_is_reported_without_a_count(works made = work / "out.bin" completes = await _run_command_turn( - workspace, work, _command_script(), _CommandTool(lambda: made.write_bytes(b"\xff\xfe\x00\x01")) + workspace, work, _command_script(), lambda: made.write_bytes(b"\xff\xfe\x00\x01") ) written = completes[0]["file_written"] @@ -807,22 +1007,23 @@ async def test_a_created_file_that_is_not_text_is_reported_without_a_count(works assert written[0]["created"] is True assert written[0]["lines"] is None assert written[0]["size"] == 4 + assert "added" not in written[0] @pytest.mark.asyncio async def test_a_created_file_past_the_reading_cap_is_reported_without_a_count(workspace): """Perfectly readable text, and still no number: reading a build artifact - whole to number it costs the turn more than the count is worth to the row, + whole to number it costs the call more than the count is worth to the row, so past the cap the count is unknown by decision rather than by failure.""" work = workspace / "work" work.mkdir() made = work / "big.txt" line = "a" * 63 + "\n" - body = line * (_FILE_WRITTEN_TEXT_MAX_BYTES // len(line) + 1) - assert len(body.encode()) > _FILE_WRITTEN_TEXT_MAX_BYTES + body = line * (command_writes.TEXT_MAX_BYTES // len(line) + 1) + assert len(body.encode()) > command_writes.TEXT_MAX_BYTES completes = await _run_command_turn( - workspace, work, _command_script(), _CommandTool(lambda: made.write_text(body, encoding="utf-8")) + workspace, work, _command_script(), lambda: made.write_text(body, encoding="utf-8") ) written = completes[0]["file_written"] @@ -832,34 +1033,6 @@ async def test_a_created_file_past_the_reading_cap_is_reported_without_a_count(w assert written[0]["size"] == len(body) -@pytest.mark.asyncio -async def test_numbering_the_files_a_command_wrote_never_runs_on_the_event_loop(workspace, monkeypatch): - """The two walks were put on a worker thread because every other session on - this process waits behind whatever the loop does. The counting that follows - reads each created file whole, which for a command that wrote a hundred of - them is the larger stall of the two.""" - from raven.agent.loop import turn_path as turn_path_module - - real = turn_path_module._file_written_payload - threads: list[int] = [] - - def watched(*args: Any, **kwargs: Any) -> Any: - threads.append(threading.get_ident()) - return real(*args, **kwargs) - - monkeypatch.setattr(turn_path_module, "_file_written_payload", watched) - work = workspace / "work" - work.mkdir() - made = work / "made.txt" - - completes = await _run_command_turn( - workspace, work, _command_script(), _CommandTool(lambda: made.write_text("one\n", encoding="utf-8")) - ) - - assert completes[0]["file_written"], completes[0] - assert threads and threading.get_ident() not in threads - - @pytest.mark.asyncio async def test_the_files_a_command_wrote_reach_the_spine_event_a_served_turn_emits(workspace): """``_process_message`` hands the payload to the callback the tests above @@ -869,14 +1042,7 @@ async def test_the_files_a_command_wrote_reach_the_spine_event_a_served_turn_emi work = workspace / "work" work.mkdir() made = work / "made.txt" - agent = AgentLoop( - provider=ScriptedProvider(_command_script()), - workspace=workspace, - model="stub", - policy=TurnPolicy(max_iterations=4, interactive=False), - tools=ToolWiring(restrict_to_workspace=True), - ) - agent.tools.register(_CommandTool(lambda: made.write_text("one\ntwo\n", encoding="utf-8"))) + agent = _command_agent(workspace, _command_script(), lambda: made.write_text("one\ntwo\n", encoding="utf-8")) events: list[Any] = [] async def emit(event: Any) -> None: @@ -912,19 +1078,49 @@ async def test_a_command_run_in_another_directory_is_listed_there(workspace): assert written[0]["lines"] == 2 -class _RemoteCommandTool(_CommandTool): - """A command that runs on a registered machine: its files are not here.""" +@pytest.mark.asyncio +async def test_a_command_outside_the_shadow_repo_is_reported_without_a_diff(workspace, monkeypatch): + """``working_dir`` can point anywhere, and the turn's shadow repo only holds + its own directory. Out there a rewrite is reported bare, as it always was, + rather than read against a tree that never held the file -- and the command + does not wait on a staging of a directory it is not running in.""" + from raven.agent.loop.checkpoint import CheckpointService + + stagings: list[Path] = [] + real_stage = CheckpointService.stage_tree - def listing_root(self, params: dict[str, Any]) -> Path | None: - return None + async def _stage(self: CheckpointService) -> str | None: + stagings.append(self._workspace) + return await real_stage(self) + + monkeypatch.setattr(CheckpointService, "stage_tree", _stage) + work = workspace / "work" + work.mkdir() + other = workspace / "other" + other.mkdir() + kept = other / "kept.txt" + kept.write_text("one\n", encoding="utf-8") + + completes = await _run_command_turn( + workspace, + work, + _command_script("printf 'two\\n' >> kept.txt", working_dir=str(other)), + checkpoint=True, + ) + + written = completes[0]["file_written"] + assert [Path(w["path"]).resolve() for w in written] == [kept.resolve()] + assert "added" not in written[0] and "diff" not in written[0] + assert not (other / ".raven").exists(), "no shadow repo is made for a directory the turn does not own" + assert stagings == [] @pytest.mark.asyncio async def test_a_command_run_on_another_machine_takes_no_listing(workspace, monkeypatch): """Not an empty listing but none: two walks of this tree around a command that ran elsewhere would attribute to it whatever else was written here in - the meantime, and cost the turn the walks for nothing.""" - from raven.agent.tools import snapshot + the meantime, and cost the call the walks for nothing.""" + from raven.agent.tools import machine_exec, snapshot roots: list[Any] = [] real = snapshot.take @@ -933,17 +1129,198 @@ def watched(root: Any) -> Any: roots.append(root) return real(root) - monkeypatch.setattr(snapshot, "take", watched) work = workspace / "work" work.mkdir() made = work / "meanwhile.txt" + async def _remote(command: str, *, connection: str, cwd: str | None = None) -> str: + made.write_text("written by someone else\n", encoding="utf-8") + return "ran" + + monkeypatch.setattr(snapshot, "take", watched) + monkeypatch.setattr(machine_exec, "run_on_machine", _remote) + + completes = await _run_command_turn(workspace, work, _command_script("make", machine="prod")) + + assert roots == [] + assert completes[0]["file_written"] is None + + +class _SlowFirstReply(ScriptedProvider): + """A model that takes its time over the first reply, the way a real one does.""" + + def __init__(self, script, delay: float) -> None: + super().__init__(script) + self._delay = delay + + async def chat(self, *args: Any, **kwargs: Any) -> Any: + if self._delay: + await asyncio.sleep(self._delay) + self._delay = 0 + return await super().chat(*args, **kwargs) + + +@pytest.mark.asyncio +@pytest.mark.production_timing # a slow first reply against a slow first staging is the property +async def test_the_first_command_in_a_cold_directory_is_measured_when_the_model_took_its_time(workspace, monkeypatch): + """The first staging in a directory the shadow repo has never indexed hashes + the whole tree -- seconds on a large one. A session opened by its first + message was never warmed as it opened, so the turn starts the staging, and + it runs while the model writes its first reply: the command that follows + finds it done well inside its wait.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + work = workspace / "work" + work.mkdir() + kept = work / "kept.txt" + kept.write_text("one\n", encoding="utf-8") + real = subprocess.run + cold = [True] + + def _cold_first(cmd, **kwargs): + if "add" in cmd and cold[0]: + cold[0] = False + time.sleep(1.0) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 0.6) + monkeypatch.setattr(cp_module.subprocess, "run", _cold_first) + script = _command_script() + completes = await _run_command_turn( workspace, work, - _command_script("make", machine="prod"), - _RemoteCommandTool(lambda: made.write_text("written by someone else\n", encoding="utf-8")), + script, + lambda: kept.write_text("one\ntwo\n", encoding="utf-8"), + checkpoint=True, + provider=_SlowFirstReply(script, delay=2.5), ) - assert roots == [] - assert completes[0]["file_written"] is None + written = completes[0]["file_written"] + assert (written[0]["added"], written[0]["removed"]) == (1, 0), written + + +@pytest.mark.asyncio +@pytest.mark.production_timing # a staging slower than the wait budget is the property +async def test_a_command_whose_snapshot_is_not_ready_in_time_is_not_run(workspace, monkeypatch): + """Run unmeasured, a command leaves a change nobody can show. Past the wait + it is not run instead: the call fails with a reply that says why, and the + staging carries on, so a later command runs and is measured.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + work = workspace / "work" + work.mkdir() + kept = work / "kept.txt" + kept.write_text("one\n", encoding="utf-8") + real = subprocess.run + cold = [True] + + def _cold_first(cmd, **kwargs): + if "add" in cmd and cold[0]: + cold[0] = False + time.sleep(0.5) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 0.1) + monkeypatch.setattr(cp_module.subprocess, "run", _cold_first) + runs: list[int] = [] + + def _append() -> None: + runs.append(1) + kept.write_text("one\ntwo\n", encoding="utf-8") + + script = [ + _tool_call("c1", "exec", {"command": "echo two >> kept.txt"}), + _tool_call("c2", "exec", {"command": "echo two >> kept.txt"}), + LLMResponse(content="done", finish_reason="stop"), + ] + + class _ThenPatient(ScriptedProvider): + async def chat(self, *args: Any, **kwargs: Any) -> Any: + if len(self._script) == 2: + # The second command comes after the model has read the + # refusal; by then the wait only has to cover a warm staging, + # however loaded the machine running this is. + await asyncio.sleep(0.6) + monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 30.0) + return await super().chat(*args, **kwargs) + + completes = await _run_command_turn( + workspace, work, script, _append, checkpoint=True, provider=_ThenPatient(script) + ) + + held, later = completes + assert held["ok"] is False + assert held["result_preview"] == command_writes.NOT_STAGED_REPLY + assert held["file_written"] is None + assert later["ok"] is True + assert (later["file_written"][0]["added"], later["file_written"][0]["removed"]) == (1, 0) + assert runs == [1], "the call that was not ready must not have run the command" + + +@pytest.mark.asyncio +async def test_a_file_saved_between_turns_is_not_counted_as_the_commands_change(workspace): + """Every command stages the tree afresh, so what the user saved between two + turns is already in the tree the second command is measured against, and + is not shown as that command's own edit.""" + work = workspace / "work" + work.mkdir() + kept = work / "kept.txt" + kept.write_text("one\n", encoding="utf-8") + + await _run_command_turn( + workspace, work, _command_script(), lambda: kept.write_text("one\ntwo\n", encoding="utf-8"), checkpoint=True + ) + kept.write_text("one\ntwo\nsaved by the user\n", encoding="utf-8") + completes = await _run_command_turn( + workspace, + work, + _command_script(), + lambda: kept.write_text("one\ntwo\nsaved by the user\ncmd\n", encoding="utf-8"), + checkpoint=True, + ) + + written = completes[0]["file_written"] + assert (written[0]["added"], written[0]["removed"]) == (1, 0), written + + +@pytest.mark.asyncio +async def test_opening_a_session_starts_staging_the_directory_it_works_in(workspace, monkeypatch): + """The loop's half of warming a session as it opens: handed the session's + directory before any turn has bound one, the command tool stages it in the + background against that directory's own shadow repo, and returns without + waiting for the staging.""" + import raven.agent.loop.checkpoint as cp_module + + monkeypatch.setattr(cp_module, "_STAGING", {}) + work = workspace / "project" + work.mkdir() + (work / "a.txt").write_text("a\n", encoding="utf-8") + agent = _command_agent(workspace, [], checkpoint=True) + + await agent.tools.get("exec").warm(work) + + staged = [index for index in cp_module._STAGING if index.is_relative_to(work.resolve())] + assert len(staged) == 1 + assert await asyncio.wrap_future(cp_module._STAGING[staged[0]]) is not None + + +@pytest.mark.asyncio +async def test_a_session_with_the_checkpoint_off_warms_nothing(workspace, monkeypatch): + """Only a command's diff is read against the staged tree, and with the + checkpoint off there is no tree to stage into.""" + import raven.agent.loop.checkpoint as cp_module + + monkeypatch.setattr(cp_module, "_STAGING", {}) + agent = _command_agent(workspace, []) + + await agent.tools.get("exec").warm(workspace) + + assert cp_module._STAGING == {} + assert not (workspace / ".raven" / "shadow.git").exists() diff --git a/tests/test_contracts_two_tier_ledger.py b/tests/test_contracts_two_tier_ledger.py index 4492d9698..5332133dd 100644 --- a/tests/test_contracts_two_tier_ledger.py +++ b/tests/test_contracts_two_tier_ledger.py @@ -77,6 +77,7 @@ def check_ledger(pkg_dir: Path, ledger: dict[str, set[str]]) -> list[str]: "ErrorClassification", "FileChange", "FileRemoval", + "FileWrite", "GenerationSettings", "ImagePart", "ImageURL", @@ -284,7 +285,7 @@ def test_import_guard_bites_machinery_and_spares_type_checking(tmp_path): # The contract tier is versioned: its shape moves only with a version bump # --------------------------------------------------------------------------- -PINNED_CONTRACT_SURFACE = ("32", "fb1e11f70125b48da8751a0bdaf3bbba788075680a2d2366af6f95f76a76ded5") +PINNED_CONTRACT_SURFACE = ("33", "a618f2a0a7c3c26949f982bae37a0a52583caff5bcaba28def32cc97a2c8e5ba") def _render(node) -> str: diff --git a/tests/test_kernel_budget.py b/tests/test_kernel_budget.py index 063ce5df1..eeb39942f 100644 --- a/tests/test_kernel_budget.py +++ b/tests/test_kernel_budget.py @@ -251,6 +251,19 @@ Measured at 3,593. + +And once more, 3,620 -> 3,660 (2026-09-29), for ``FileWrite`` on the tool +paper: the files a command created or rewrote, the other half of the record +``FileRemoval`` started. The shell tool lists its directory either side of the +command and, where the checkpoint's shadow repo covers it, reads what each file +held from a tree staged just before; the paper only names what travels back -- +a path, whether it is new, its size, and the line counts and diff when the +change could be measured -- and gives ``ToolResult`` and ``ToolOutput`` one +``written`` tuple each, empty for every other call. 34 lines, a dataclass and +its prose. + +Measured at 3,627. + """ from __future__ import annotations @@ -261,7 +274,7 @@ from pathlib import Path LINE_CEILING = 2_000 -CONTRACTS_LINE_CEILING = 3_620 +CONTRACTS_LINE_CEILING = 3_660 THIRD_PARTY_ALLOWED = frozenset({"loguru"}) DEBT_MARKER = re.compile(r"\b(TODO|FIXME|HACK)\b") diff --git a/tests/test_rpc_session.py b/tests/test_rpc_session.py index d2d55ae2f..337e61668 100644 --- a/tests/test_rpc_session.py +++ b/tests/test_rpc_session.py @@ -351,6 +351,88 @@ async def test_session_create_reports_where_the_new_session_will_run( assert result["info"]["cwd"] == str(expected) +def _warming_loop(tmp_path: Path, warmed: list[Path], *, fail: bool = False, exec_tool: bool = True) -> SimpleNamespace: + """The resolver stand-in with a command tool whose warm-up a session open calls. + + Each warm-up records the directory it was handed, so a test can tell it + covered the directory the session will actually work in.""" + loop = _loop_with_resolver(tmp_path) + loop.sessions = SessionManager(tmp_path) + # Resolved through the manager the open writes the override into, as the real loop is. + resolver = WorkdirResolver(WorkdirPolicy.PER_CHANNEL, agent_home=tmp_path / "home", sessions=loop.sessions) + loop.peek_session_workdir = lambda key: resolver.resolve(key, create=False) + + async def warm(target: Path) -> None: + warmed.append(target) + if fail: + raise RuntimeError("git is gone") + + command = SimpleNamespace(warm=warm) + loop.tools = SimpleNamespace(tool_names=[], get=lambda name: command if exec_tool and name == "exec" else None) + return loop + + +async def test_opening_a_session_warms_the_directory_it_will_work_in( + tmp_path: Path, monkeypatch: pytest.MonkeyPatch +) -> None: + """The first command of a session would otherwise hash a large tree inside + its own call. A new session warms its directory as it opens, after a + requested workdir has become the session's, so the warm-up covers it.""" + cfg = load_config() + cfg.agents.defaults.workspace = str(tmp_path) + monkeypatch.setattr(session_module, "load_config", lambda: cfg) + pinned = tmp_path / "project" + pinned.mkdir() + warmed: list[Path] = [] + loop = _warming_loop(tmp_path, warmed) + monkeypatch.setattr(session_module, "manager_for", lambda *_: loop.sessions) + + await session_create({"workdir": str(pinned)}, agent_loop_factory=lambda: loop) + + assert warmed == [pinned.resolve()] + + +async def test_resuming_a_session_warms_its_directory(tmp_path: Path, monkeypatch: pytest.MonkeyPatch) -> None: + cfg = load_config() + cfg.agents.defaults.workspace = str(tmp_path) + monkeypatch.setattr(session_module, "load_config", lambda: cfg) + warmed: list[Path] = [] + loop = _warming_loop(tmp_path, warmed) + session_key = "tui:20260929_120000_warm" + stored = loop.sessions.get_or_create(session_key) + stored.add_message("user", "hello") + loop.sessions.save(stored) + expected = loop.peek_session_workdir(session_key) + expected.mkdir(parents=True, exist_ok=True) + monkeypatch.setattr(session_module, "manager_for", lambda *_: loop.sessions) + + await session_resume({"session_id": session_key}, agent_loop_factory=lambda: loop) + + assert warmed == [expected] + + +@pytest.mark.parametrize("fail", [True, False], ids=["warm-up raises", "no command tool"]) +async def test_a_warm_up_that_cannot_run_does_not_fail_the_open( + tmp_path: Path, monkeypatch: pytest.MonkeyPatch, fail: bool +) -> None: + """A warm-up is best-effort: without it the first command stages the tree + itself, so a broken one -- or a loop with no command to warm for -- must + not cost the user the session.""" + cfg = load_config() + cfg.agents.defaults.workspace = str(tmp_path) + monkeypatch.setattr(session_module, "load_config", lambda: cfg) + pinned = tmp_path / "project" + pinned.mkdir() + warmed: list[Path] = [] + loop = _warming_loop(tmp_path, warmed, fail=fail, exec_tool=fail) + monkeypatch.setattr(session_module, "manager_for", lambda *_: loop.sessions) + + result = await session_create({"workdir": str(pinned)}, agent_loop_factory=lambda: loop) + + assert result["session_id"].startswith("tui:") + assert warmed == ([pinned.resolve()] if fail else []) + + async def test_session_resume_keeps_the_launch_dir_with_no_loop_to_ask( tmp_path: Path, monkeypatch: pytest.MonkeyPatch ) -> None: diff --git a/tests/test_runtime_checkpoint.py b/tests/test_runtime_checkpoint.py index 2f7276a2e..e8e9f1715 100644 --- a/tests/test_runtime_checkpoint.py +++ b/tests/test_runtime_checkpoint.py @@ -11,8 +11,11 @@ from __future__ import annotations +import asyncio +import os import subprocess import tempfile +import time from pathlib import Path import pytest @@ -80,6 +83,538 @@ async def test_checkpoint_does_not_touch_user_git(workspace): assert _git_count(workspace) == count_before, "no commits added to user repo" +async def test_a_staged_tree_holds_what_a_file_said_before_it_changed(workspace): + """What a command's diff is read against: the file as it stood when the tree + was staged, after the file has been rewritten on disk.""" + svc = CheckpointService(workspace) + kept = workspace / "kept.txt" + kept.write_text("one\n", encoding="utf-8") + + tree = await svc.stage_tree() + assert tree is not None + kept.write_text("two\n", encoding="utf-8") + (workspace / "new.txt").write_text("new\n", encoding="utf-8") + + held = await svc.read_blobs(tree, [str(kept), str(workspace / "new.txt")], max_bytes=1024) + assert held == {str(kept): b"one\n"}, "a file the tree never had is unknown, not empty" + + +async def test_a_blob_is_left_out_past_the_cap_or_outside_the_work_tree(workspace, tmp_path_factory): + svc = CheckpointService(workspace) + big = workspace / "big.txt" + big.write_text("x" * 64, encoding="utf-8") + outside = tmp_path_factory.mktemp("outside") / "o.txt" + outside.write_text("o\n", encoding="utf-8") + + tree = await svc.stage_tree() + assert tree is not None + + assert await svc.read_blobs(tree, [str(big), str(outside)], max_bytes=63) == {} + assert await svc.read_blobs(tree, [str(big)], max_bytes=64) == {str(big): b"x" * 64} + + +async def test_staging_a_tree_leaves_the_turn_commit_its_own_changes(workspace): + """The stage has an index of its own. Staged into the shared one, the turn's + commit would find this file already staged and report the turn as having + changed nothing -- the recovery prompt would lose it.""" + svc = CheckpointService(workspace) + (workspace / "a.py").write_text("print(1)\n", encoding="utf-8") + + assert await svc.stage_tree() is not None + cid, changed = await svc.commit_turn("turn 1") + + assert cid is not None + assert changed == ["a.py"] + + +async def test_a_stale_staging_index_is_pruned_and_a_fresh_one_kept(workspace): + """A process that died leaves its staging index behind. Pruned by age, never + by asking whether its pid is alive -- on Windows that question kills it.""" + import os + import time + + svc = CheckpointService(workspace) + assert await svc.stage_tree() is not None + git_dir = workspace / ".raven" / "shadow.git" + stale = git_dir / "exec-1.index" + fresh = git_dir / "exec-2.index" + stale.write_bytes(b"") + fresh.write_bytes(b"") + old = time.time() - 8 * 24 * 3600 + os.utime(stale, (old, old)) + + again = CheckpointService(workspace) + assert await again.stage_tree() is not None + + assert not stale.exists() + assert fresh.exists() + assert (git_dir / f"exec-{os.getpid()}.index").exists() + + +async def test_a_stage_that_timed_out_leaves_no_lock_behind(workspace, monkeypatch): + """A killed ``git add`` leaves its ``index.lock``, and every later stage would + fail on it for the rest of the process -- one slow command would cost every + command after it its diff.""" + import os + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + svc = CheckpointService(workspace) + assert await svc.stage_tree() is not None + lock = workspace / ".raven" / "shadow.git" / f"exec-{os.getpid()}.index.lock" + real = subprocess.run + + def _killed(cmd, **kwargs): + lock.write_bytes(b"") + raise subprocess.TimeoutExpired(cmd, 0.05) + + monkeypatch.setattr(cp_module.subprocess, "run", _killed) + assert await svc.stage_tree() is None + assert not lock.exists() + + monkeypatch.setattr(cp_module.subprocess, "run", real) + assert await svc.stage_tree() is not None + + +async def test_a_slow_first_stage_is_left_to_warm_the_index_behind_the_command(workspace, monkeypatch): + """The first stage in a directory hashes every file and can take seconds. + Past the budget the call is told so, the stage keeps running, a command + that arrives meanwhile does not start a second one, and the one after it + finds the index warm.""" + import asyncio + import subprocess + import threading + + import raven.agent.loop.checkpoint as cp_module + + svc = CheckpointService(workspace) + (workspace / "a.txt").write_text("a\n", encoding="utf-8") + real = subprocess.run + release = threading.Event() + adds: list[object] = [] + + def _slow(cmd, **kwargs): + if "add" in cmd: + adds.append(cmd) + release.wait(10) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 0.05) + monkeypatch.setattr(cp_module.subprocess, "run", _slow) + + with pytest.raises(cp_module.StagingTimeoutError): + await svc.stage_tree() + with pytest.raises(cp_module.StagingTimeoutError): + await svc.stage_tree() + assert len(adds) == 1, "a stage still running is not started again" + + release.set() + assert await asyncio.wrap_future(cp_module._STAGING[svc._stage_path()]) is not None + monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 30.0) + assert await svc.stage_tree() is not None + + +async def test_a_stage_waits_out_the_warm_up_and_stages_again(workspace, monkeypatch): + """The warm-up started with the session may still be running when the first + command arrives. Its tree may predate what happened since, so it is waited + for and never used; the command stages its own after it.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + svc = CheckpointService(workspace) + (workspace / "a.txt").write_text("a\n", encoding="utf-8") + real = subprocess.run + adds: list[object] = [] + + def _count(cmd, **kwargs): + if "add" in cmd: + adds.append(cmd) + if len(adds) == 1: + time.sleep(0.3) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module.subprocess, "run", _count) + + await svc.warm() + (workspace / "a.txt").write_text("changed while warming\n", encoding="utf-8") + tree = await svc.stage_tree() + + assert tree is not None + assert len(adds) == 2 + held = await svc.read_blobs(tree, [str(workspace / "a.txt")], max_bytes=1024) + assert held == {str(workspace / "a.txt"): b"changed while warming\n"} + + +async def test_a_warm_up_already_running_is_not_started_again(workspace, monkeypatch): + """Two turns starting in one directory warm it once: the second warm-up + would only queue a second hash of the same tree behind the first.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + real = subprocess.run + adds: list[object] = [] + + def _count(cmd, **kwargs): + if "add" in cmd: + adds.append(cmd) + time.sleep(0.2) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module.subprocess, "run", _count) + svc = CheckpointService(workspace) + + await svc.warm() + await CheckpointService(workspace).warm() + await asyncio.wrap_future(cp_module._STAGING[svc._stage_path()]) + + assert len(adds) == 1 + + +async def test_a_warm_up_returns_before_the_repo_is_even_set_up(workspace, monkeypatch): + """The turn awaits ``warm`` in front of its first model call, so everything + the warm-up does -- the repo's own ``git init`` and config as much as the + staging -- belongs on its thread. Awaited, a slow setup would be a first + reply that waits for it.""" + import raven.agent.loop.checkpoint as cp_module + + real = CheckpointService._ensure_init + + async def _slow_init(self) -> bool: + await asyncio.sleep(1.0) + return await real(self) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(CheckpointService, "_ensure_init", _slow_init) + svc = CheckpointService(workspace) + + started = time.monotonic() + await svc.warm() + assert time.monotonic() - started < 0.2 + + assert await asyncio.wrap_future(cp_module._STAGING[svc._stage_path()]) is not None + + +async def test_a_turn_that_ends_during_the_warm_up_still_commits(workspace, monkeypatch): + """A turn can end before its warm-up has set the repo up. Two setups at once + fail on the config lock, and the one that lost was the turn's commit -- so + the commit waits for the warm-up's setup instead of racing it.""" + import threading + + import raven.agent.loop.checkpoint as cp_module + + real = CheckpointService._init_repo + active = [0] + overlap = [0] + + async def _tracked(self) -> bool: + active[0] += 1 + overlap[0] = max(overlap[0], active[0]) + try: + if threading.current_thread().name == "raven-stage": + await asyncio.sleep(0.3) + return await real(self) + finally: + active[0] -= 1 + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(CheckpointService, "_init_repo", _tracked) + (workspace / "a.py").write_text("print(1)\n", encoding="utf-8") + svc = CheckpointService(workspace) + + await svc.warm() + cid, changed = await svc.commit_turn("turn 1") + + assert cid is not None and changed == ["a.py"] + assert overlap[0] == 1, "the commit's setup ran beside the warm-up's" + + +async def test_a_directory_is_warmed_once_and_not_every_turn(workspace, monkeypatch): + """Every turn starts with a warm-up call, and only the first does any work: + after it each command's own staging keeps the index warm, so another would + be one more stat walk of the whole tree per message for nothing.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + real = subprocess.run + adds: list[object] = [] + + def _count(cmd, **kwargs): + if "add" in cmd: + adds.append(cmd) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module.subprocess, "run", _count) + svc = CheckpointService(workspace) + + await svc.warm() + await asyncio.wrap_future(cp_module._STAGING[svc._stage_path()]) + await svc.warm() + await svc.warm() + + assert len(adds) == 1 + + +async def test_two_commands_behind_one_warm_up_each_stage_their_own_tree(workspace, monkeypatch): + """Two sessions in one directory both run a command while the warm-up is + still staging. Each waits it out and stages its own tree, one after the + other on the index's lock, rather than a second ``git add`` failing on the + lock beside the first.""" + import asyncio + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + svc = CheckpointService(workspace) + (workspace / "a.txt").write_text("a\n", encoding="utf-8") + real = subprocess.run + adds: list[object] = [] + + def _count(cmd, **kwargs): + if "add" in cmd: + adds.append(cmd) + if len(adds) == 1: + time.sleep(0.3) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module.subprocess, "run", _count) + + await svc.warm() + first, second = await asyncio.gather(svc.stage_tree(), CheckpointService(workspace).stage_tree()) + + assert first is not None and second is not None + assert len(adds) == 3 + + +async def test_a_slow_first_staging_is_not_cut_off_at_the_git_call_ceiling(workspace, monkeypatch): + """Every command is held back until the staging finishes. Killed at the + ceiling a turn's own git calls use, a staging that needs longer is started + over, killed again, and never finishes -- so no command would ever run.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + real = subprocess.run + ceilings: list[float] = [] + + def _spy(cmd, **kwargs): + if "add" in cmd: + ceilings.append(kwargs["timeout"]) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module.subprocess, "run", _spy) + assert await CheckpointService(workspace).stage_tree() is not None + + assert ceilings == [cp_module._STAGE_ADD_TIMEOUT_SECONDS] + assert ceilings[0] > cp_module._GIT_TIMEOUT_SECONDS * 10 + + +async def test_a_command_behind_a_staging_past_the_budget_is_refused(workspace, monkeypatch): + """The staging in front of the command -- here the warm-up -- has not + finished within the budget. The command is refused like one whose own + staging ran out of time, not run unmeasured because the staging in its way + was not its own.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + real = subprocess.run + + def _slow(cmd, **kwargs): + if "add" in cmd: + time.sleep(0.5) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 0.1) + monkeypatch.setattr(cp_module.subprocess, "run", _slow) + svc = CheckpointService(workspace) + + await svc.warm() + warm_up = cp_module._STAGING[svc._stage_path()] + with pytest.raises(cp_module.StagingTimeoutError): + await svc.stage_tree() + + # Giving up on it must not have cancelled it: its thread still finishes it. + assert await asyncio.wrap_future(warm_up) is not None + assert not warm_up.cancelled() + + +async def test_each_command_stages_the_directory_as_it_stands(workspace): + """Every command stages afresh, so whatever changed the directory since + the last command -- a tool call, the user, another session -- is already in + the tree the next one is measured against.""" + svc = CheckpointService(workspace) + kept = workspace / "a.txt" + kept.write_text("one\n", encoding="utf-8") + first = await svc.stage_tree() + + kept.write_text("two\n", encoding="utf-8") + second = await svc.stage_tree() + + assert first is not None and second is not None and second != first + assert await svc.read_blobs(second, [str(kept)], max_bytes=64) == {str(kept): b"two\n"} + + +@pytest.mark.production_timing # a first staging slower than any short wait is the property +async def test_a_slow_first_staging_is_waited_out_inside_the_command(workspace, monkeypatch): + """The first staging of a large directory can take many seconds. The + command waits for it inside its own call -- the warm-up it finds running, + then its own staging -- and gets its tree, instead of failing and leaving + the model to retry.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + real = subprocess.run + cold = [True] + + def _cold_first(cmd, **kwargs): + if "add" in cmd and cold[0]: + cold[0] = False + time.sleep(1.0) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module.subprocess, "run", _cold_first) + (workspace / "a.txt").write_text("a\n", encoding="utf-8") + svc = CheckpointService(workspace) + + await svc.warm() + started = time.monotonic() + tree = await svc.stage_tree() + + assert tree is not None + assert time.monotonic() - started >= 0.5, "the command did not wait for the warm-up" + + +async def test_trackable_follows_the_repos_own_exclusion_rules(workspace, tmp_path_factory): + """What a command's created files are checked against before their text + goes anywhere: the default excludes, the work-tree's .gitignore, and + nothing outside the work-tree.""" + svc = CheckpointService(workspace) + (workspace / ".gitignore").write_text("build/\n", encoding="utf-8") + (workspace / "build").mkdir() + outside = tmp_path_factory.mktemp("outside") / "o.txt" + names = { + "plain": workspace / "notes.md", + "default exclude": workspace / ".env", + "key": workspace / "id_ed25519", + "user ignore": workspace / "build" / "out.js", + "outside": outside, + } + for path in names.values(): + path.write_text("x\n", encoding="utf-8") + + kept = await svc.trackable([str(path) for path in names.values()]) + + assert kept == {str(names["plain"])} + + +async def test_a_name_that_is_not_utf8_is_judged_and_looked_up_by_its_bytes(workspace): + """A POSIX name holding byte 0xff reaches Python surrogate-escaped. The + query git reads must carry that byte, not fail to encode it after the + command has already run. Judged on the rules alone, so the names need not + exist (macOS refuses to create them).""" + svc = CheckpointService(workspace) + (workspace / ".gitignore").write_text("*.bin\n", encoding="utf-8") + plain = str(workspace / os.fsdecode(b"notes-\xff.md")) + ignored = str(workspace / os.fsdecode(b"blob-\xff.bin")) + + assert await svc.trackable([plain, ignored]) == {plain} + + tree = await svc.stage_tree() + assert tree is not None + assert await svc.read_blobs(tree, [plain], max_bytes=1024) == {} + + +async def test_trackable_vouches_for_nothing_when_git_cannot_answer(workspace, monkeypatch): + svc = CheckpointService(workspace) + (workspace / "notes.md").write_text("x\n", encoding="utf-8") + assert await svc.trackable([str(workspace / "notes.md")]) == {str(workspace / "notes.md")} + + async def _broken(*_args, **_kwargs): + return 128, b"", b"fatal" + + monkeypatch.setattr(svc, "_run", _broken) + assert await svc.trackable([str(workspace / "notes.md")]) == set() + + +async def test_a_first_stage_starts_from_the_last_turns_index(workspace, monkeypatch): + """The turn's commit has already hashed the tree into the shared index, and a + staging index copied from it only has to stat what changed since. Started + empty, the first command in every process would pay for hashing the whole + tree again.""" + import subprocess + + import raven.agent.loop.checkpoint as cp_module + + (workspace / "a.txt").write_text("a\n", encoding="utf-8") + assert (await CheckpointService(workspace).commit_turn("turn 1"))[0] is not None + shared = (workspace / ".raven" / "shadow.git" / "index").read_bytes() + real = subprocess.run + started_from: list[bytes] = [] + + def _spy(cmd, **kwargs): + if "add" in cmd: + started_from.append(Path(kwargs["env"]["GIT_INDEX_FILE"]).read_bytes()) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module.subprocess, "run", _spy) + assert await CheckpointService(workspace).stage_tree() is not None + assert started_from == [shared] + + +def test_a_staging_still_running_does_not_hold_the_loop_open(workspace, monkeypatch): + """Closing a loop cancels what is left on it. An asyncio subprocess still + starting at that moment never finishes cancelling (CPython 3.12, macOS) and + the close hangs -- which, for the gateway, is a shutdown that never ends.""" + import asyncio + import subprocess + import threading + import time + + import raven.agent.loop.checkpoint as cp_module + + real = subprocess.run + release = threading.Event() + + def _slow(cmd, **kwargs): + release.wait(10) + return real(cmd, **kwargs) + + monkeypatch.setattr(cp_module, "_STAGING", {}) + monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 0.05) + monkeypatch.setattr(cp_module.subprocess, "run", _slow) + + async def one_call() -> bool: + try: + await CheckpointService(workspace).stage_tree() + except cp_module.StagingTimeoutError: + return True + return False + + # On a thread of its own: asyncio.run on the main thread clears the default + # loop, and pytest-asyncio then makes one it never closes. + outcome: list[bool] = [] + started = time.monotonic() + runner = threading.Thread(target=lambda: outcome.append(asyncio.run(one_call()))) + runner.start() + runner.join(10) + assert outcome == [True] + assert time.monotonic() - started < 5 + release.set() + + def _os_environ(): import os diff --git a/tests/test_shell_command_writes.py b/tests/test_shell_command_writes.py new file mode 100644 index 000000000..2c33057d8 --- /dev/null +++ b/tests/test_shell_command_writes.py @@ -0,0 +1,217 @@ +"""The exec tool's record of what a command wrote: its directory either side. + +A command returns its output and nothing else, so the tool lists the directory +it runs in before and after, and -- where a shadow repo covers the directory -- +stages the tree first so a rewritten or removed file can be shown against what +it held. The shadow repo here is a stand-in: these are the tool's decisions +(when to stage, when not to run, what to hand back), and the real repo has its +own tests in ``test_runtime_checkpoint.py``. +""" + +from __future__ import annotations + +import threading +from pathlib import Path +from typing import Any, Collection + +import pytest + +from raven.agent.loop.checkpoint import StagingTimeoutError +from raven.agent.tools import command_writes, snapshot +from raven.agent.tools.shell import ExecTool + + +class _Shadow: + """A shadow repo whose tree is whatever the directory held at staging.""" + + def __init__(self, root: Path, *, stage: Any = None, ignored: Collection[str] = ()) -> None: + self._root = root + self._stage = stage + self._ignored = set(ignored) + self._trees: dict[str, dict[str, bytes]] = {} + self.staged = 0 + self.warmed = 0 + + async def warm(self) -> None: + self.warmed += 1 + + async def stage_tree(self) -> str | None: + self.staged += 1 + if self._stage is not None: + return self._stage() + tree = f"t{self.staged}" + self._trees[tree] = {str(p): p.read_bytes() for p in self._root.rglob("*") if p.is_file()} + return tree + + async def read_blobs(self, tree: str, paths: Collection[str], *, max_bytes: int) -> dict[str, bytes]: + held = self._trees.get(tree, {}) + return {path: held[path] for path in paths if path in held and len(held[path]) <= max_bytes} + + async def trackable(self, paths: Collection[str]) -> set[str]: + return {path for path in paths if Path(path).name not in self._ignored} + + +def _tool(root: Path, shadow: _Shadow | None = None, *, record_writes: bool = True) -> ExecTool: + return ExecTool( + working_dir=str(root), + restrict_to_workspace=True, + record_writes=record_writes, + shadow=(lambda _root: shadow) if shadow is not None else None, + ) + + +async def test_a_rewrite_is_measured_against_the_tree_staged_just_before_it(tmp_path): + (tmp_path / "notes.md").write_text("one\n") + shadow = _Shadow(tmp_path) + + result = await _tool(tmp_path, shadow).execute(command="echo two >> notes.md") + + assert shadow.staged == 1 + [write] = result.written + assert (write.path, write.created, write.added, write.removed) == (str(tmp_path / "notes.md"), False, 1, 0) + assert "+two" in write.diff.splitlines() + + +async def test_a_command_whose_tree_is_not_staged_in_time_is_not_run(tmp_path): + """Run unmeasured, the command would leave a change nobody can show. The + call fails instead, with no hint to find another way: the reply itself + says what to do.""" + + def _too_slow() -> str: + raise TimeoutError + + result = await _tool(tmp_path, _Shadow(tmp_path, stage=_too_slow)).execute(command="echo x > made.txt") + + assert not (tmp_path / "made.txt").exists(), "the command must not have run" + assert result.model_text == command_writes.NOT_STAGED_REPLY + assert result.ok is False and result.retryable is False + + +async def test_a_tree_that_cannot_be_staged_leaves_the_command_to_run_unmeasured(tmp_path): + """A git that failed, a directory the repo cannot hold: nothing about the + filesystem says the command should not run, so it does, reported without + the text no repo vouched for.""" + result = await _tool(tmp_path, _Shadow(tmp_path, stage=lambda: None)).execute(command="printf 'x\\n' > made.txt") + + assert (tmp_path / "made.txt").read_text() == "x\n" + [write] = result.written + assert (write.created, write.lines, write.added) == (True, 1, 1) + assert write.diff is None + + +async def test_a_created_file_the_repo_would_not_store_keeps_its_counts_and_loses_its_text(tmp_path): + result = await _tool(tmp_path, _Shadow(tmp_path, ignored={".env"})).execute( + command="printf 'API_KEY=top-secret\\n' > .env && printf 'ok\\n' > notes.md" + ) + + written = {Path(w.path).name: w for w in result.written} + assert written[".env"].diff is None and written[".env"].added == 1 + assert "+ok" in written["notes.md"].diff.splitlines() + + +async def test_a_removed_file_carries_what_the_staged_tree_held(tmp_path): + (tmp_path / "doomed.txt").write_text("one\ntwo\n") + + result = await _tool(tmp_path, _Shadow(tmp_path)).execute(command="find . -name '*.txt' -delete") + + assert [(r.path, r.before) for r in result.removed] == [(str(tmp_path / "doomed.txt"), "one\ntwo\n")] + + +async def test_a_tool_not_asked_to_record_writes_does_not_list_or_stage(tmp_path, monkeypatch): + """A sub-agent's runner lists every call itself, so its ``exec`` does not + walk the directory a second time around each command.""" + roots: list[Any] = [] + monkeypatch.setattr(snapshot, "take", lambda root: roots.append(root)) + shadow = _Shadow(tmp_path) + + result = await _tool(tmp_path, shadow, record_writes=False).execute(command="echo x > made.txt") + + assert roots == [] and shadow.staged == 0 + assert result.written == () + + +async def test_a_background_command_takes_no_listing(tmp_path, monkeypatch): + """Its files land after the call has returned, so a listing either side of + the start would describe nothing it did.""" + roots: list[Any] = [] + monkeypatch.setattr(snapshot, "take", lambda root: roots.append(root)) + + await _tool(tmp_path, _Shadow(tmp_path)).execute(command="true", run_in_background=True) + + assert roots == [] + + +async def test_a_directory_too_large_to_list_is_not_staged(tmp_path, monkeypatch): + """No listing means nothing to report, so a staging would be paid for nothing.""" + monkeypatch.setattr(snapshot, "take", lambda root: None) + shadow = _Shadow(tmp_path) + + result = await _tool(tmp_path, shadow).execute(command="echo x > made.txt") + + assert shadow.staged == 0 + assert result.written == () + + +async def test_reading_the_written_files_never_runs_on_the_event_loop(tmp_path, monkeypatch): + """This reads every written file whole, and one command can write a + hundred; every other session on the process waits behind the loop.""" + real = command_writes._writes + threads: list[int] = [] + + def watched(*args: Any, **kwargs: Any) -> Any: + threads.append(threading.get_ident()) + return real(*args, **kwargs) + + monkeypatch.setattr(command_writes, "_writes", watched) + + result = await _tool(tmp_path).execute(command="echo x > made.txt") + + assert result.written + assert threads and threading.get_ident() not in threads + + +async def test_past_the_calls_diff_budget_the_counts_still_go_and_the_diff_does_not(tmp_path, monkeypatch): + """One command can rewrite a hundred files. The diffs share the call's + budget, and one past it is dropped whole -- half a diff reads as a smaller + change -- while its counts, which cost nothing, still say how big it was.""" + monkeypatch.setattr(command_writes, "DIFF_BUDGET_CHARS", 60) + + result = await _tool(tmp_path, _Shadow(tmp_path)).execute( + command="printf 'one\\ntwo\\n' > a.txt && printf 'three\\nfour\\n' > b.txt" + ) + + first, second = sorted(result.written, key=lambda w: w.path) + assert first.diff is not None and second.diff is None + assert (second.added, second.removed) == (2, 0) + + +async def test_warming_stages_through_the_shadow_repo_and_is_a_no_op_without_one(tmp_path): + shadow = _Shadow(tmp_path) + + await _tool(tmp_path, shadow).warm(tmp_path) + await _tool(tmp_path).warm(tmp_path) + await _tool(tmp_path, shadow, record_writes=False).warm(tmp_path) + + assert shadow.warmed == 1, "only the tool that records writes warms for them" + + +def test_the_tools_ceiling_covers_the_longest_command_and_the_longest_wait(): + """The registry kills a call past the tool's ceiling. A command may wait out + its staging and then run to the executor's own cap, and a ceiling under the + two together would kill a command the executor was still allowed to run.""" + from raven.agent.loop import checkpoint + + assert ExecTool.timeout_seconds > ExecTool._MAX_TIMEOUT + checkpoint._STAGE_WAIT_SECONDS + + +@pytest.mark.parametrize("error", [TimeoutError, StagingTimeoutError]) +async def test_the_checkpoints_own_timeout_is_one_the_tool_catches(tmp_path, error): + """The tool holds the repo through a protocol and cannot import its error; + what it catches is ``TimeoutError``, so the repo's must be one.""" + + def _raise() -> str: + raise error + + result = await _tool(tmp_path, _Shadow(tmp_path, stage=_raise)).execute(command="true") + + assert result.model_text == command_writes.NOT_STAGED_REPLY diff --git a/ui-tui/src/rpc/generated.ts b/ui-tui/src/rpc/generated.ts index 5072b18da..d4d5558d3 100644 --- a/ui-tui/src/rpc/generated.ts +++ b/ui-tui/src/rpc/generated.ts @@ -298,7 +298,7 @@ export interface TranscriptFileRemoval { del: number; } /** - * One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. + * One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A created file carries its counts, and its text only when the shadow repo would store it: never for a file its excludes or the user's .gitignore keep out. * * This interface was referenced by `RavenRpcRoot`'s JSON-Schema * via the `definition` "FileWritten". @@ -320,6 +320,18 @@ export interface FileWritten { * Lines in a created file, when it could be counted. Null, not absent: the key is always sent, and null says the count is unknown. Too large to read, not text, or a file that already existed, whose change therefore has no number. */ lines?: number | null; + /** + * Lines the command added to the file. Absent when the change could not be measured: not text, too large, or a rewrite whose previous contents were never captured. + */ + added?: number | null; + /** + * Lines the command removed from the file. Absent exactly when added is. + */ + removed?: number | null; + /** + * Unified diff of the change, when it was measured and small enough to carry. Absent past the event's budget even when the counts are present: a partial diff reads as a smaller change than the one that happened. + */ + diff?: string | null; } /** * Why a turn's transcript stops where it does. diff --git a/ui-web/src/features/desk/store.ts b/ui-web/src/features/desk/store.ts index eccd0d284..a117bfd47 100644 --- a/ui-web/src/features/desk/store.ts +++ b/ui-web/src/features/desk/store.ts @@ -491,9 +491,9 @@ export function openDeskFile(path: string): void { export function openDeskDiff(change: WsChange): void { readItem('diff', `${change.key}:${change.turn}`) - /* A row with no hunks has no patch to draw: a command reports the files it - left behind and never how it changed them, so the listing that made the row - knows a count and nothing else. The file as it stands is the nearest thing + /* A row with no hunks has no patch to draw: a command whose change the + runtime could not measure (no earlier copy of the file, not text, or too + large) leaves a row that knows a count at most. The file as it stands is the nearest thing to the change and is what the reader clicked for -- an empty patch pane is not. A removal keeps its pane: there the missing hunk IS the answer, and there is no file left to open. */ diff --git a/ui-web/src/features/workspace/record.test.ts b/ui-web/src/features/workspace/record.test.ts index 08a878b5a..153583de2 100644 --- a/ui-web/src/features/workspace/record.test.ts +++ b/ui-web/src/features/workspace/record.test.ts @@ -488,6 +488,136 @@ describe('recording the files a command left behind', () => { expect(store.shared().changes.map((c) => c.kind).sort()).toEqual(['delete', 'write']) }) + /* The runtime read the file against the tree it staged in front of the + command, so the change comes measured, and the row is drawn like any file + tool's -- which is what sends a reader who opens it to the patch. */ + it('draws a measured rewrite with its hunk and counts', () => { + wsOnToolDone('exec', { command: 'python3 gen.py' }, true, '', null, undefined, undefined, undefined, [{ + path: '/w/log.json', created: false, size: 12, lines: null, added: 1, removed: 1, + diff: '--- log.json\n+++ log.json\n@@ -1,2 +1,2 @@\n a\n-b\n+B', + }]) + + const row = rowFor('/w/log.json') + expect(row?.kind).toBe('write') + expect(row?.hunks).toHaveLength(1) + expect([row?.add, row?.del]).toEqual([1, 1]) + expect(row?.listed).toBe(true) + }) + + /* Past the event's budget the diff is dropped and the counts still arrive: + the row says how big the change was even with no patch to open. */ + /* The runtime measured the change; the patch is for drawing. Where the two + disagree the runtime's numbers are the ones shown. */ + it('shows the runtime\'s counts over ones re-read from the patch', () => { + wsOnToolDone('exec', { command: 'python3 gen.py' }, true, '', null, undefined, undefined, undefined, [{ + path: '/w/log.json', created: false, size: 12, lines: null, added: 5, removed: 4, + diff: '--- log.json\n+++ log.json\n@@ -1,2 +1,2 @@\n a\n-b\n+B', + }]) + + const row = rowFor('/w/log.json') + expect(row?.hunks).toHaveLength(1) + expect([row?.add, row?.del]).toEqual([5, 4]) + }) + + /* The same preference where a second change is added to a row the turn + already has: this is where a command writing one file several times sums + its counts, and where a wrong number is least likely to be noticed. */ + it('adds the runtime\'s counts, not the patch\'s, to a row it already has', () => { + const args = { path: '/w/notes.md', content: 'a\n' } + wsOnTool('write_file', args) + wsOnToolDone('write_file', args, true, '', null, + '--- a/w/notes.md\n+++ b/w/notes.md\n@@ -0,0 +1,1 @@\n+a', { path: '/w/notes.md', after: 'a\n' }) + + wsOnToolDone('exec', { command: 'python3 gen.py' }, true, '', null, undefined, undefined, undefined, [{ + path: '/w/notes.md', created: false, size: 4, lines: null, added: 5, removed: 3, + diff: '--- notes.md\n+++ notes.md\n@@ -1,1 +1,2 @@\n a\n+b', + }]) + + const row = rowFor('/w/notes.md') + expect(row?.hunks).toHaveLength(2) + expect([row?.add, row?.del]).toEqual([1 + 5, 0 + 3]) + }) + + it('carries the counts of a measured change that came without its diff', () => { + wsOnToolDone('exec', { command: 'python3 gen.py' }, true, '', null, undefined, undefined, undefined, + [{ path: '/w/log.json', created: false, size: 12, lines: null, added: 40, removed: 7 }]) + + const row = rowFor('/w/log.json') + expect(row?.hunks).toHaveLength(0) + expect([row?.add, row?.del]).toEqual([40, 7]) + }) + + /* A command that changes a file a tool already wrote this turn: its diff is + against the file as the tool left it, so it is one more hunk on the row, + not a second row and not a replacement for the first. */ + it('adds a measured change to the row a file tool already made', () => { + const args = { path: '/w/notes.md', content: 'a\n' } + wsOnTool('write_file', args) + wsOnToolDone('write_file', args, true, '', null, + '--- a/w/notes.md\n+++ b/w/notes.md\n@@ -0,0 +1,1 @@\n+a', { path: '/w/notes.md', after: 'a\n' }) + + wsOnToolDone('exec', { command: 'echo b >> notes.md' }, true, '', null, undefined, undefined, undefined, [{ + path: '/w/notes.md', created: false, size: 4, lines: null, added: 1, removed: 0, + diff: '--- notes.md\n+++ notes.md\n@@ -1,1 +1,2 @@\n a\n+b', + }]) + + expect(store.shared().changes).toHaveLength(1) + const row = rowFor('/w/notes.md') + expect(row?.kind).toBe('add') + expect(row?.hunks).toHaveLength(2) + expect(row?.add).toBe(2) + }) + + /* A listing row that carries a hunk is still the listing's: a file tool that + follows under the path the model typed takes it over rather than opening a + second row for the same file. */ + it('lets a file tool take over a command\'s measured row', () => { + wsOnToolDone('exec', { command: 'python3 gen.py' }, true, '', null, undefined, undefined, undefined, [{ + path: '/w/notes.md', created: true, size: 2, lines: 1, added: 1, removed: 0, + diff: '--- notes.md\n+++ notes.md\n@@ -0,0 +1,1 @@\n+b', + }]) + + const args = { path: 'notes.md', old_text: 'b', new_text: 'B' } + wsOnTool('edit_file', args) + + expect(store.shared().changes).toHaveLength(1) + const row = rowFor('notes.md') + expect(row?.kind).toBe('add') + expect(row?.hunks).toHaveLength(2) + }) + + /* The row's change so far was never measured, so a measured second change + would put a partial count on it and a patch that shows only the half the + reader did not ask about. */ + it('leaves an unmeasured row bare when a later command is measured', () => { + wsOnToolDone('exec', { command: 'python3 gen.py' }, true, '', null, undefined, undefined, undefined, + [{ path: '/w/.env', created: false, size: 4, lines: null }]) + wsOnToolDone('exec', { command: 'python3 gen.py' }, true, '', null, undefined, undefined, undefined, [{ + path: '/w/.env', created: false, size: 4, lines: null, added: 1, removed: 1, + diff: '--- .env\n+++ .env\n@@ -1,1 +1,1 @@\n-A=1\n+A=2', + }]) + + const row = rowFor('/w/.env') + expect(row?.hunks).toHaveLength(0) + expect([row?.add, row?.del]).toEqual([0, 0]) + }) + + it('replays a stored measured change as the same row', () => { + const written = { + path: '/w/log.json', created: false, size: 12, lines: null, added: 1, removed: 1, + diff: '--- log.json\n+++ log.json\n@@ -1,2 +1,2 @@\n a\n-b\n+B', + } + wsOnHistory([ + { role: 'user', text: 'regenerate it' }, + { role: 'assistant', tool_calls: [{ id: 'c1', name: 'exec', arguments: JSON.stringify({ command: 'make' }) }] }, + { role: 'tool', tool_call_id: 'c1', file_written: [written] }, + ]) + + const row = rowFor('/w/log.json') + expect(row?.hunks).toHaveLength(1) + expect([row?.add, row?.del]).toEqual([1, 1]) + }) + /* A reload reads the same shape back: unlike a removal there is nothing to reduce, so live and replayed rows are identical. */ it('replays the stored listing as the same rows', () => { diff --git a/ui-web/src/features/workspace/record.ts b/ui-web/src/features/workspace/record.ts index 25cf247e6..7e4468765 100644 --- a/ui-web/src/features/workspace/record.ts +++ b/ui-web/src/features/workspace/record.ts @@ -132,33 +132,58 @@ function wsRecordRemoval(path: string, before?: string, lines?: number | null): desk would list one file twice. The tool's account is the one that can say what changed, so the listing's row carries on under the tool's spelling instead -- keeping the verdict the listing is better placed to know, that - the file was new. Only a row the listing made is taken this way, which is - what carrying no hunk means; a removal's bare row is its own answer. */ + the file was new. Only a row the listing made is taken this way; a + removal's bare row is its own answer. */ function adoptListing(key: string): void { const WS = record() const row = WS.changes.find((x) => x.turn === WS.turn && x.key !== key - && !x.hunks.length && x.kind !== 'delete' && sameFile(x.key, key)) + && x.listed && x.kind !== 'delete' && sameFile(x.key, key)) if (!row) return const { dir, name } = labelFor(key) row.key = key row.dir = dir row.name = name + row.listed = false } /* What a command left behind, which no tool result names: the runtime lists the directory the turn's tools run in before and after an `exec` and reports the - difference. A listing knows a file is there, how big it is and whether it was - there before -- never how it changed -- so the row carries a count and no - hunk, and the desk sends a reader who opens it to the file itself. + difference. Where it also held the file's previous contents (the working + directory's shadow repo, staged just before the command) or the file is new, + it measured the change and sends the diff, and the row is drawn like any + other. Otherwise the row carries what it can -- the counts, or for a created + file its lines -- and no hunk, and the desk sends a reader who opens it to + the file itself. - A row this turn already holds for the path is left alone: it came from a file - tool, whose arguments say everything a listing cannot. */ + A row this turn already holds for the path takes a measured change as one + more hunk, the way a second edit does: the diff was read against the file as + the earlier calls left it, so it is only what the command did. An unmeasured + one is dropped there -- it says nothing the row does not, and a row whose + change so far is unmeasured would read a partial count as the whole. */ function wsRecordWritten(w: FileWritten): void { const WS = record() const key = String(w.path) - if (WS.changes.some((x) => x.turn === WS.turn && sameFile(x.key, key))) return + const hunk = w.diff ? hunks.fromUnified(w.diff) : null + /* The runtime's own counts when it sent them: it measured the change, and a + number re-read off the patch text is a second source for the same fact. */ + const add = w.added ?? hunk?.add ?? null + const del = w.removed ?? hunk?.del ?? null + const had = WS.changes.find((x) => x.turn === WS.turn && sameFile(x.key, key)) + if (had) { + if (hunk && had.hunks.length && had.kind !== 'delete') { + had.hunks.push(hunk) + had.add += add ?? 0 + had.del += del ?? 0 + } + return + } const c = rowFor(key, w.created ? 'add' : 'write') - if (w.created) c.add = w.lines == null ? 0 : w.lines + c.listed = true + if (hunk) c.hunks.push(hunk) + if (add != null) { + c.add = add + c.del = del ?? 0 + } else if (w.created) c.add = w.lines == null ? 0 : w.lines } /* ── tool-event hooks ────────────────────────────────────────────────── diff --git a/ui-web/src/features/workspace/types.ts b/ui-web/src/features/workspace/types.ts index 87774731b..8a6cb91f2 100644 --- a/ui-web/src/features/workspace/types.ts +++ b/ui-web/src/features/workspace/types.ts @@ -22,6 +22,10 @@ export interface WsChange { edited -- either way nothing here can say what the file holds. Read only when the file is removed and the runtime caught none of its contents. */ body?: string | null + /* Made by a command's listing rather than by a file tool. Said outright + because the hunk no longer tells them apart: a listing that could measure + the change carries one too. */ + listed?: boolean turn: number open: boolean auto?: boolean diff --git a/ui-web/src/lib/hunks.test.ts b/ui-web/src/lib/hunks.test.ts index 0d706b656..31027229a 100644 --- a/ui-web/src/lib/hunks.test.ts +++ b/ui-web/src/lib/hunks.test.ts @@ -57,6 +57,19 @@ describe('diff hunk builders', () => { expect(hunk.rows[40]).toEqual(['gap', ['line 41']]) }) + it('keeps a removed line that reads like a file header', () => { + const hunk = fromUnified([ + '--- a/q.sql', '+++ b/q.sql', '@@ -1,2 +1,2 @@', + '--- old comment', '+++ new comment', ' select 1', + ]) + expect([hunk.add, hunk.del]).toEqual([1, 1]) + expect(hunk.rows.slice(1)).toEqual([ + ['del', '-- old comment', 1, null], + ['add', '++ new comment', null, 1], + ['ctx', 'select 1', 2, 2], + ]) + }) + it('drops file headers and numbers unified diff rows from the hunk header', () => { const hunk = fromUnified([ '--- a/file', '+++ b/file', '@@ -2,2 +2,3 @@', diff --git a/ui-web/src/lib/hunks.ts b/ui-web/src/lib/hunks.ts index f7000a68a..559c75d0b 100644 --- a/ui-web/src/lib/hunks.ts +++ b/ui-web/src/lib/hunks.ts @@ -145,8 +145,18 @@ export function fromUnified(lines: string | string[]): WsHunk { let del = 0 let oldLine: number | null = null let newLine: number | null = null - const source = typeof lines === 'string' ? lines.split('\n') : lines - source.filter((line) => !/^(---|\+\+\+)( |$)/.test(String(line))).forEach((raw) => { + const source = (typeof lines === 'string' ? lines.split('\n') : lines).map(String) + /* A file header is the `---`/`+++` pair in front of a hunk, not any line that + starts that way: a removed line reading `-- note` is written `--- note`, + and matching on the prefix alone dropped it, row and count both. */ + const header = new Set() + source.forEach((line, i) => { + const next = source[i + 2] + if (/^--- /.test(line) && /^\+\+\+ /.test(source[i + 1] ?? '') && (next === undefined || next.startsWith('@@'))) { + header.add(i).add(i + 1) + } + }) + source.filter((_, i) => !header.has(i)).forEach((raw) => { const line = String(raw) const header = line.match(/^@@ -(\d+)(?:,\d+)? \+(\d+)(?:,\d+)? @@/) if (header) { diff --git a/ui-web/src/rpc/fixtures/turn.test.ts b/ui-web/src/rpc/fixtures/turn.test.ts index 8d4991c64..129c64bfe 100644 --- a/ui-web/src/rpc/fixtures/turn.test.ts +++ b/ui-web/src/rpc/fixtures/turn.test.ts @@ -41,7 +41,10 @@ describe('the frames a scripted turn pushes', () => { .filter((e) => e?.type === 'tool.complete' && e.payload?.file_written) .map((e) => (e!.payload as unknown as ToolCompleteEvent['payload']).file_written) expect(written).toEqual([[ - { path: '~/work/raven/research/tally.txt', created: true, size: 96, lines: 4 }, + { + path: '~/work/raven/research/tally.txt', created: true, size: 89, lines: 4, added: 4, removed: 0, + diff: '--- tally.txt\n+++ tally.txt\n@@ -0,0 +1,4 @@\n+vendor leads replies\n+Clay 1240 88\n+Apollo 980 61\n+Unify 410 37', + }, { path: '~/work/raven/research/run.log', created: false, size: 412, lines: null }, ]]) }) diff --git a/ui-web/src/rpc/fixtures/turn.ts b/ui-web/src/rpc/fixtures/turn.ts index 01b382fdf..f75bc6932 100644 --- a/ui-web/src/rpc/fixtures/turn.ts +++ b/ui-web/src/rpc/fixtures/turn.ts @@ -60,7 +60,8 @@ export type ScriptEvent = { d?: number } & ( | { t: 't+'; id: number; n: string; a?: string | ToolArgs } | { t: 't-'; id: number; r: string; ok?: boolean; ms?: number; diff?: string[]; meta?: DeliveryMeta; removed?: Array<{ path: string; before: string }>; - wrote?: Array<{ path: string; created: boolean; size: number; lines: number | null }> } + wrote?: Array<{ path: string; created: boolean; size: number; lines: number | null; + added?: number; removed?: number; diff?: string }> } | DagEntry | { t: 'end' } ) @@ -153,11 +154,13 @@ const GTM_FILE_EVENTS: ScriptEvent[] = [ { t:'t-', d:110, id:11, ok:true, r:'', ms:110, removed:[{ path:'~/work/raven/research/gtm-notes.md', before: GTM_SUPERSEDED }] }, /* A command the runtime has no result to read: what it left on disk is known - only from listing the directory before and after it, which is where a - created file's line count comes from and why the rewritten one has none. */ + only from listing the directory before and after it. The created file is + measured against nothing and carries its diff; the log is one the shadow + repo excludes, so its rewrite has no earlier copy and no measure. */ { t:'t+', d:150, id:12, n:'exec', a:'python3 scripts/tally.py > research/tally.txt && date >> research/run.log' }, { t:'t-', d:260, id:12, ok:true, r:'', ms:260, - wrote:[{ path:'~/work/raven/research/tally.txt', created:true, size:96, lines:4 }, + wrote:[{ path:'~/work/raven/research/tally.txt', created:true, size:89, lines:4, added:4, removed:0, + diff:'--- tally.txt\n+++ tally.txt\n@@ -0,0 +1,4 @@\n+vendor leads replies\n+Clay 1240 88\n+Apollo 980 61\n+Unify 410 37' }, { path:'~/work/raven/research/run.log', created:false, size:412, lines:null }] }, ]; diff --git a/ui-web/src/rpc/generated.ts b/ui-web/src/rpc/generated.ts index 389c8c4d3..60742fd8d 100644 --- a/ui-web/src/rpc/generated.ts +++ b/ui-web/src/rpc/generated.ts @@ -246,7 +246,7 @@ export interface TranscriptFileRemoval { del: number; } /** - * One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. + * One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A created file carries its counts, and its text only when the shadow repo would store it: never for a file its excludes or the user's .gitignore keep out. */ export interface FileWritten { /** @@ -265,6 +265,18 @@ export interface FileWritten { * Lines in a created file, when it could be counted. Null, not absent: the key is always sent, and null says the count is unknown. Too large to read, not text, or a file that already existed, whose change therefore has no number. */ lines?: number | null; + /** + * Lines the command added to the file. Absent when the change could not be measured: not text, too large, or a rewrite whose previous contents were never captured. + */ + added?: number | null; + /** + * Lines the command removed from the file. Absent exactly when added is. + */ + removed?: number | null; + /** + * Unified diff of the change, when it was measured and small enough to carry. Absent past the event's budget even when the counts are present: a partial diff reads as a smaller change than the one that happened. + */ + diff?: string | null; } /** * Why a turn's transcript stops where it does. From 5f8ae3fd3fa9b8f69d223136d0e9c05f76650b9b Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Tue, 29 Sep 2026 21:28:59 +0800 Subject: [PATCH 2/9] fix(agent): settle every staging and judge every exec file's text by one rule Two defects review found in the exec diff. A turn cancelled while waiting on the warm-up's repo setup cancelled the setup's own future: it was never marked running. The warm-up thread then failed setting its result before it settled the staging it had already published in _STAGING, and every later command in that directory waited out the full 120s and was refused as if the filesystem had stopped answering. The setup future is now running from creation, and both the warm-up and a command's own staging settle their futures whatever happens on their thread. Only a created file's text was checked against the shadow repo's rules. A rewritten or removed file was read from the staged tree unfiltered, and a file staged before an ignore rule named it stays in the index, so its old text reached the diff and the removal body. Now one rule (trackable, the repo's rules alone) decides for every file a command created, rewrote or removed, including the files its own removal watch caught by name; a file the rules keep out goes out with its counts at most. Co-authored-by: Claude (claude-opus-5-5) --- raven/agent/loop/checkpoint.py | 57 ++++++++++++++------- raven/agent/tools/command_writes.py | 38 ++++++++------ raven/agent/tools/shell.py | 3 +- raven/rpc/models.py | 8 +-- rpc-schema/openrpc.json | 2 +- tests/test_agent_loop_session_stamps.py | 30 +++++++++++ tests/test_runtime_checkpoint.py | 68 +++++++++++++++++++++++++ tests/test_shell_command_writes.py | 12 +++++ ui-tui/src/rpc/generated.ts | 2 +- ui-web/src/rpc/generated.ts | 2 +- 10 files changed, 181 insertions(+), 41 deletions(-) diff --git a/raven/agent/loop/checkpoint.py b/raven/agent/loop/checkpoint.py index 53dfb6dba..da3fd0e83 100644 --- a/raven/agent/loop/checkpoint.py +++ b/raven/agent/loop/checkpoint.py @@ -38,7 +38,7 @@ import threading import time from pathlib import Path -from typing import Collection +from typing import Any, Collection from loguru import logger @@ -178,6 +178,12 @@ class StagingTimeoutError(TimeoutError): this repo through a protocol and does not import the loop shell.""" +def _settle(future: "concurrent.futures.Future[Any] | None", value: Any) -> None: + """Give ``future`` its result unless it already has one.""" + if future is not None and not future.done(): + future.set_result(value) + + async def _within(staging: "concurrent.futures.Future[str | None]", deadline: float) -> bool: """Whether ``staging`` finished by ``deadline``, waited for without owning it. @@ -473,26 +479,37 @@ async def warm(self) -> None: return staging = self._register_stage(index) if not self._ready: + # Running from the start for the reason the staging is: a turn + # cancelled while waiting on the setup (``_ensure_init``) must not + # cancel the setup itself. self._initializing = concurrent.futures.Future() + self._initializing.set_running_or_notify_cancel() threading.Thread(target=self._warm_up, args=(index, staging), name="raven-stage", daemon=True).start() def _warm_up(self, index: Path, staging: "concurrent.futures.Future[str | None]") -> None: # A loop of the thread's own for the repo setup: the turn's loop is not # to wait on it, and one that closes while the setup is still starting a # git process would hold its close up. + # + # Both futures are settled whatever happens here: the staging is + # published in ``_STAGING``, and one nobody settles would hold every + # later command in the directory to the full wait and then refuse it. initializing = self._initializing try: - ready = asyncio.run(self._init_repo()) - except Exception as exc: # noqa: BLE001 -- a warm-up never breaks anything - logger.debug("checkpoint warm-up init error: {}", exc) - ready = False - if initializing is not None: - initializing.set_result(ready) - if not ready: - staging.set_result(None) - return - self._prepare_index(index) - self._stage(index, staging) + try: + ready = asyncio.run(self._init_repo()) + except Exception as exc: # noqa: BLE001 -- a warm-up never breaks anything + logger.debug("checkpoint warm-up init error: {}", exc) + ready = False + _settle(initializing, ready) + if ready: + self._prepare_index(index) + self._stage(index, staging) + except Exception as exc: # noqa: BLE001 + logger.debug("checkpoint warm-up error: {}", exc) + finally: + _settle(initializing, False) + _settle(staging, None) def _start_stage(self, index: Path) -> "concurrent.futures.Future[str | None]": staging = self._register_stage(index) @@ -520,12 +537,16 @@ def _stage(self, index: Path, result: "concurrent.futures.Future[str | None]") - ``write-tree`` writes the index back too and a second staging's ``add`` beside it fails on the index lock. """ - with _STAGE_LOCKS.setdefault(index, threading.Lock()): - if self._stage_step(("add", "-A"), index, timeout=_STAGE_ADD_TIMEOUT_SECONDS) is None: - result.set_result(None) - return - tree = self._stage_step(("write-tree",), index) - result.set_result(tree or None) + try: + with _STAGE_LOCKS.setdefault(index, threading.Lock()): + if self._stage_step(("add", "-A"), index, timeout=_STAGE_ADD_TIMEOUT_SECONDS) is None: + return + tree = self._stage_step(("write-tree",), index) + _settle(result, tree or None) + except Exception as exc: # noqa: BLE001 -- a staging degrades to no tree, never to no answer + logger.debug("checkpoint stage error: {}", exc) + finally: + _settle(result, None) def _stage_step(self, args: tuple[str, ...], index: Path, *, timeout: float | None = None) -> str | None: """One git step of a staging: its output, or ``None`` when it failed.""" diff --git a/raven/agent/tools/command_writes.py b/raven/agent/tools/command_writes.py index 3108e5e2f..96488e4d1 100644 --- a/raven/agent/tools/command_writes.py +++ b/raven/agent/tools/command_writes.py @@ -98,21 +98,26 @@ async def before(root: Path, shadow_for: ShadowFor | None) -> Before: async def after( - start: Before, *, already: Collection[str] = () + start: Before, *, named: tuple[FileRemoval, ...] = () ) -> tuple[tuple[FileWrite, ...], tuple[FileRemoval, ...]]: """What the command changed under ``start.root``: files written, files removed. - ``already`` are the removals the command reported by name, which the listing - sees as well; reporting one again would draw a single deletion twice. - - A created file carries its text as a diff only where the shadow repo would - store it (``trackable``): a ``.env``, a key, anything the user's ``.gitignore`` - keeps out is exactly what the checkpoint keeps out of storage, and a diff is - stored with the conversation. A rewritten or removed file needs no such - check, since the tree only ever holds files the repo stores. + ``named`` are the removals the command's own watch caught by name, with the + text it read before the command ran. The listing sees them as well, and + reporting one again would draw a single deletion twice, so they come back + first and the listing adds only what they miss. + + One rule decides whether a file's contents may be shown, whichever way it + changed: the shadow repo's (``trackable``), the rules it stores by. A + ``.env``, a key, anything the user's ``.gitignore`` keeps out is what the + checkpoint keeps out of storage, and a diff is stored with the conversation. + The rules rather than the tree: a file staged before an ignore rule named it + stays in the index, and its text must not be shown for that. Where there is + no shadow repo to ask, a created file keeps its counts only, and a rewrite + or listed removal has no earlier text to show. """ listing = await asyncio.to_thread(snapshot.take, start.root) - accounted = {os.path.realpath(path) for path in already if isinstance(path, str) and path} + accounted = {os.path.realpath(removal.path) for removal in named} created, modified, deleted = ( [path for path in paths if os.path.realpath(path) not in accounted] for paths in snapshot.diff(start.listing, listing) @@ -120,15 +125,18 @@ async def after( held: dict[str, bytes] = {} shown: set[str] = set() if start.shadow is not None and start.tree is not None: - if modified or deleted: - held = await start.shadow.read_blobs(start.tree, [*modified, *deleted], max_bytes=TEXT_MAX_BYTES) - if created: - shown = await start.shadow.trackable(created) + subjects = [*created, *modified, *deleted, *(removal.path for removal in named if removal.before is not None)] + if subjects: + shown = await start.shadow.trackable(subjects) + readable = [path for path in [*modified, *deleted] if path in shown] + if readable: + held = await start.shadow.read_blobs(start.tree, readable, max_bytes=TEXT_MAX_BYTES) + named = tuple(removal if removal.path in shown else FileRemoval(path=removal.path) for removal in named) # Off the loop too: this reads every written file, and one command can write hundreds. written = ( await asyncio.to_thread(_writes, created, modified, listing or {}, held, shown) if created or modified else () ) - removed = tuple(FileRemoval(path=path, before=_decoded(held.get(path))) for path in deleted) + removed = named + tuple(FileRemoval(path=path, before=_decoded(held.get(path))) for path in deleted) return written, removed diff --git a/raven/agent/tools/shell.py b/raven/agent/tools/shell.py index c18ef2a52..7f362a392 100644 --- a/raven/agent/tools/shell.py +++ b/raven/agent/tools/shell.py @@ -382,8 +382,7 @@ async def execute( ) written: tuple[FileWrite, ...] = () if start is not None: - written, listed = await command_writes.after(start, already=[removal.path for removal in removed]) - removed += listed + written, removed = await command_writes.after(start, named=removed) # The exit code is the verdict a config change, a security call or a # syntax error share, and the text a failing command produced is not # token-safe to classify from -- so the caller gets it structurally. diff --git a/raven/rpc/models.py b/raven/rpc/models.py index 3a145e682..95c5399a5 100644 --- a/raven/rpc/models.py +++ b/raven/rpc/models.py @@ -658,9 +658,11 @@ class FileWritten(_Strict): listings of the directory said about it -- that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; - then the change itself rides along as counts and a unified diff. A created - file carries its counts, and its text only when the shadow repo would store - it: never for a file its excludes or the user's .gitignore keep out. + then the change itself rides along as counts and a unified diff. A file's + text goes out only when the shadow repo's rules would store it: never for a + file its excludes or the user's .gitignore keep out, even one the repo held a + copy of before the rule named it. Such a created file carries its counts + only, and such a rewrite neither. """ path: str = Field(description="Absolute path of the file the command wrote.") diff --git a/rpc-schema/openrpc.json b/rpc-schema/openrpc.json index d2354ab41..867ce4001 100644 --- a/rpc-schema/openrpc.json +++ b/rpc-schema/openrpc.json @@ -12317,7 +12317,7 @@ } }, "FileWritten": { - "description": "One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A created file carries its counts, and its text only when the shadow repo would store it: never for a file its excludes or the user's .gitignore keep out.", + "description": "One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A file's text goes out only when the shadow repo's rules would store it: never for a file its excludes or the user's .gitignore keep out, even one the repo held a copy of before the rule named it. Such a created file carries its counts only, and such a rewrite neither.", "type": "object", "additionalProperties": false, "required": [ diff --git a/tests/test_agent_loop_session_stamps.py b/tests/test_agent_loop_session_stamps.py index f43492218..5f3ad88d3 100644 --- a/tests/test_agent_loop_session_stamps.py +++ b/tests/test_agent_loop_session_stamps.py @@ -760,6 +760,36 @@ async def test_a_created_file_the_shadow_repo_would_not_store_carries_no_text(wo assert "top-secret" not in json.dumps(_persisted_messages(workspace)) +@pytest.mark.asyncio +@pytest.mark.parametrize("change", ["rewrite", "remove"]) +async def test_a_file_the_repo_already_held_shows_no_text_once_a_rule_ignores_it(workspace, change): + """The index keeps updating a path it already tracks after an ignore rule + names it, so the staged tree still holds the file's old text. What may be + shown is judged by the rules, not by what the tree happens to hold: the + rewrite goes out bare and the removal without its body.""" + work = workspace / "work" + work.mkdir() + keys = work / "keys.txt" + keys.write_text("OLD_SECRET=aaa\n", encoding="utf-8") + + def _act() -> None: + (work / ".gitignore").write_text("keys.txt\n", encoding="utf-8") + if change == "rewrite": + keys.write_text("NEW_SECRET=bbb\n", encoding="utf-8") + else: + keys.unlink() + + completes = await _run_command_turn(workspace, work, _command_script(), _act, checkpoint=True) + + written = {Path(w["path"]).name: w for w in completes[0]["file_written"]} + assert "+keys.txt" in written[".gitignore"]["diff"].splitlines() + if change == "rewrite": + assert "diff" not in written["keys.txt"] and "added" not in written["keys.txt"] + else: + assert [r.get("before") for r in completes[0]["file_removed"]] == [None] + assert "SECRET" not in json.dumps(completes) + json.dumps(_persisted_messages(workspace)) + + @pytest.mark.asyncio async def test_a_command_that_ran_before_this_one_is_not_part_of_its_diff(workspace): """The tree is staged in front of each command, not once per turn: a second diff --git a/tests/test_runtime_checkpoint.py b/tests/test_runtime_checkpoint.py index e8e9f1715..048c957e9 100644 --- a/tests/test_runtime_checkpoint.py +++ b/tests/test_runtime_checkpoint.py @@ -1049,3 +1049,71 @@ async def test_loop_runs_the_turn_when_the_root_is_refused(tmp_path, monkeypatch assert outcome.status == "interrupted" # max-iter, as in the sibling tests assert outcome.checkpoint_id is None # refused, so nothing was snapshotted assert (home / "a.py").exists() # the turn's edit still landed + + +async def test_a_turn_cancelled_while_the_warm_up_sets_the_repo_up_does_not_orphan_its_staging(workspace, monkeypatch): + """A turn that ends inside the warm-up's repo setup waits on it from its + commit, and a cancelled turn cancels that wait. Were the setup's own future + cancelled with it, the warm-up thread would fail on it before settling the + staging it had already published, and every later command in the directory + would wait out the full budget and be refused.""" + import raven.agent.loop.checkpoint as cp_module + + monkeypatch.setattr(cp_module, "_STAGING", {}) + real_init = CheckpointService._init_repo + + async def _slow_init(self: CheckpointService) -> bool: + await asyncio.sleep(0.3) + return await real_init(self) + + monkeypatch.setattr(CheckpointService, "_init_repo", _slow_init) + (workspace / "a.txt").write_text("a\n", encoding="utf-8") + svc = CheckpointService(workspace) + + await svc.warm() + waiter = asyncio.ensure_future(svc._ensure_init()) + while not svc._initializing._done_callbacks: + await asyncio.sleep(0.01) + waiter.cancel() + with pytest.raises(asyncio.CancelledError): + await waiter + + assert not svc._initializing.cancelled() + started = time.monotonic() + assert await svc.stage_tree() is not None + assert time.monotonic() - started < 30, "the staging was left for nobody to settle" + + +@pytest.mark.parametrize("broken", ["_stage_step", "_prepare_index"]) +async def test_a_staging_that_fails_unexpectedly_still_answers(workspace, monkeypatch, broken): + """A staging degrades to no tree, never to no answer: an unsettled one is + waited for until the budget runs out, and the command is refused for it.""" + import raven.agent.loop.checkpoint as cp_module + + monkeypatch.setattr(cp_module, "_STAGING", {}) + + def _raise(*_args: object, **_kwargs: object) -> None: + raise RuntimeError("unexpected") + + svc = CheckpointService(workspace) + monkeypatch.setattr(svc, broken, _raise) + await svc.warm() + + staging = cp_module._STAGING[svc._stage_path()] + assert await asyncio.wait_for(asyncio.wrap_future(staging), 30) is None + + +async def test_a_commands_own_staging_that_fails_unexpectedly_still_answers(workspace, monkeypatch): + """The same guarantee on the path a command takes when nothing was warming.""" + import raven.agent.loop.checkpoint as cp_module + + monkeypatch.setattr(cp_module, "_STAGING", {}) + + def _raise(*_args: object, **_kwargs: object) -> None: + raise RuntimeError("unexpected") + + svc = CheckpointService(workspace) + assert await svc.stage_tree() is not None + monkeypatch.setattr(svc, "_stage_step", _raise) + + assert await asyncio.wait_for(svc.stage_tree(), 30) is None diff --git a/tests/test_shell_command_writes.py b/tests/test_shell_command_writes.py index 2c33057d8..8a324c951 100644 --- a/tests/test_shell_command_writes.py +++ b/tests/test_shell_command_writes.py @@ -117,6 +117,18 @@ async def test_a_removed_file_carries_what_the_staged_tree_held(tmp_path): assert [(r.path, r.before) for r in result.removed] == [(str(tmp_path / "doomed.txt"), "one\ntwo\n")] +async def test_a_file_the_command_named_keeps_its_text_only_where_the_repo_would_store_it(tmp_path): + """The command's own watch reads a named file before it goes. That text is + held to the same rule as every other file's: a ``.env`` removed by name goes + out without its body, an ordinary file with it.""" + (tmp_path / ".env").write_text("API_KEY=top-secret\n") + (tmp_path / "notes.md").write_text("one\n") + + result = await _tool(tmp_path, _Shadow(tmp_path, ignored={".env"})).execute(command="rm .env notes.md") + + assert {Path(r.path).name: r.before for r in result.removed} == {".env": None, "notes.md": "one\n"} + + async def test_a_tool_not_asked_to_record_writes_does_not_list_or_stage(tmp_path, monkeypatch): """A sub-agent's runner lists every call itself, so its ``exec`` does not walk the directory a second time around each command.""" diff --git a/ui-tui/src/rpc/generated.ts b/ui-tui/src/rpc/generated.ts index d4d5558d3..435a8ac89 100644 --- a/ui-tui/src/rpc/generated.ts +++ b/ui-tui/src/rpc/generated.ts @@ -298,7 +298,7 @@ export interface TranscriptFileRemoval { del: number; } /** - * One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A created file carries its counts, and its text only when the shadow repo would store it: never for a file its excludes or the user's .gitignore keep out. + * One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A file's text goes out only when the shadow repo's rules would store it: never for a file its excludes or the user's .gitignore keep out, even one the repo held a copy of before the rule named it. Such a created file carries its counts only, and such a rewrite neither. * * This interface was referenced by `RavenRpcRoot`'s JSON-Schema * via the `definition` "FileWritten". diff --git a/ui-web/src/rpc/generated.ts b/ui-web/src/rpc/generated.ts index 60742fd8d..2365f5696 100644 --- a/ui-web/src/rpc/generated.ts +++ b/ui-web/src/rpc/generated.ts @@ -246,7 +246,7 @@ export interface TranscriptFileRemoval { del: number; } /** - * One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A created file carries its counts, and its text only when the shadow repo would store it: never for a file its excludes or the user's .gitignore keep out. + * One file a command left behind, found by listing its working directory. Neither a FileChange nor a FileRemoval: a command reports its output and nothing else, so what is known of the file is that it is there, how big it is, and whether it was there before. What it changed from is known only when the working directory's shadow repo held a copy from just before the command; then the change rides along as counts and a unified diff. A file's text goes out only when the shadow repo's rules would store it: never for a file its excludes or the user's .gitignore keep out, even one the repo held a copy of before the rule named it. Such a created file carries its counts only, and such a rewrite neither. */ export interface FileWritten { /** From 97b04ae8a7a496aef991514656d22d25cdd14641 Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Wed, 30 Sep 2026 10:18:02 +0800 Subject: [PATCH 3/9] fix(agent): run a command whose snapshot is late, without its diff A command whose tree had not finished staging within the 120s wait was not run, and the call failed. A tree that could not be staged at all already let the command run without a diff, so the two ways of having no snapshot were handled differently, and the stricter one bought nothing: refusing the command does not make its diff any more exact, it only stops the user's work. Both now end the same way: the command runs, it is still listed, and its files are reported without the text they held. The late staging is left running, so a later command usually finds it done. Co-authored-by: Claude (claude-opus-5-5) --- CONTEXT.md | 4 +-- raven/agent/loop/checkpoint.py | 4 +-- raven/agent/tools/command_writes.py | 29 +++++++++--------- raven/agent/tools/shell.py | 8 +---- tests/test_agent_loop_session_stamps.py | 39 ++++++++++++------------- tests/test_shell_command_writes.py | 35 +++++++++------------- 6 files changed, 50 insertions(+), 69 deletions(-) diff --git a/CONTEXT.md b/CONTEXT.md index 92cf1a566..ebfd58c89 100644 --- a/CONTEXT.md +++ b/CONTEXT.md @@ -572,8 +572,8 @@ handed in by the loop, and does the measuring itself: `ExecTool.warm` starts sta in the background when a session opens on the directory (`session.create` / `session.resume`, or the first turn where a session opens without either), and every command stages it afresh inside its own call with `stage_tree`, into a per-process index of -its own (never the index the turn commit reads), waiting up to 120s before the command is -failed rather than run unmeasured. `read_blobs` reads the old contents back for the +its own (never the index the turn commit reads), waiting up to 120s; a tree it cannot stage, +or not within that wait, leaves the command to run without a diff. `read_blobs` reads the old contents back for the command's `file_written` diff and `file_removed` body. _Avoid_: "shadow git" as the term — Checkpoint is the per-turn snapshot it produces. diff --git a/raven/agent/loop/checkpoint.py b/raven/agent/loop/checkpoint.py index da3fd0e83..7e65f8587 100644 --- a/raven/agent/loop/checkpoint.py +++ b/raven/agent/loop/checkpoint.py @@ -440,8 +440,8 @@ async def stage_tree(self) -> str | None: ``None`` when the tree cannot be staged at all (git failed), which costs the call its diff and nothing else. :class:`StagingTimeoutError` when it - has not finished after :data:`_STAGE_WAIT_SECONDS`: the caller fails the - command rather than run it unmeasured. The staging is left running + has not finished after :data:`_STAGE_WAIT_SECONDS`: the caller runs the + command without a diff all the same. The staging is left running rather than killed, because what it has hashed is what makes the next one fast. """ diff --git a/raven/agent/tools/command_writes.py b/raven/agent/tools/command_writes.py index 96488e4d1..741ee2724 100644 --- a/raven/agent/tools/command_writes.py +++ b/raven/agent/tools/command_writes.py @@ -23,6 +23,8 @@ from pathlib import Path from typing import Callable, Collection, Mapping, Protocol +from loguru import logger + from raven.agent.tools import snapshot from raven.contracts.tool import FileRemoval, FileWrite @@ -36,17 +38,6 @@ #: diff is dropped whole: half a diff reads as a smaller change than happened. DIFF_BUDGET_CHARS = 512 * 1024 -#: What the model reads for a command that was not run because the tree its -#: changes are measured against did not finish staging in time: not run rather -#: than run unmeasured. Only a filesystem that has stopped answering takes that -#: long, so the reply says so instead of inviting a retry loop. -NOT_STAGED_REPLY = ( - "Error: the command was not run. Raven snapshots the working directory before a " - "command so it can record what the command changes, and the snapshot did not finish " - "within 2 minutes; the filesystem may be very slow or unresponsive. Tell the user " - "rather than retrying repeatedly." -) - class ShadowTree(Protocol): """The part of the checkpoint's shadow repo a command is measured against. @@ -81,9 +72,10 @@ class Before: async def before(root: Path, shadow_for: ShadowFor | None) -> Before: """Look at ``root`` just before a command runs in it. - Raises :class:`TimeoutError` when the shadow tree did not finish staging: - the command must then not run, since whatever it changed could no longer be - measured. A directory too large to list is not staged at all -- no listing + A tree that could not be staged, or did not finish staging within its wait, + leaves the command to run without one: it is still listed, so what it wrote + is reported, only not what those files held. The command matters more than + its diff. A directory too large to list is not staged at all -- no listing means nothing is reported, and a staging would be paid for nothing. Off the event loop: the walk is tens of milliseconds of a turn, and every @@ -91,7 +83,13 @@ async def before(root: Path, shadow_for: ShadowFor | None) -> Before: """ listing = await asyncio.to_thread(snapshot.take, root) shadow = shadow_for(root) if listing is not None and shadow_for is not None else None - tree = await shadow.stage_tree() if shadow is not None else None + try: + tree = await shadow.stage_tree() if shadow is not None else None + except TimeoutError: + # Left running rather than abandoned: what it has hashed is what makes + # the next command's staging fast. + logger.warning("exec measured without a diff: staging {} did not finish in time", root) + tree = None if tree is None: return Before(root, listing) return Before(root, listing, shadow, tree) @@ -200,7 +198,6 @@ def _line_diff(old: str, new: str, name: str) -> tuple[str | None, int, int]: __all__ = [ "DIFF_BUDGET_CHARS", - "NOT_STAGED_REPLY", "TEXT_MAX_BYTES", "Before", "ShadowFor", diff --git a/raven/agent/tools/shell.py b/raven/agent/tools/shell.py index 7f362a392..592bb9855 100644 --- a/raven/agent/tools/shell.py +++ b/raven/agent/tools/shell.py @@ -14,8 +14,6 @@ from pathlib import Path from typing import Any -from loguru import logger - from raven.agent import workdir from raven.agent.tools import command_writes from raven.contracts.tool import ( @@ -353,11 +351,7 @@ async def execute( watched = self._removal_watch(command, cwd) start: command_writes.Before | None = None if self.record_writes: - try: - start = await command_writes.before(Path(cwd), self._shadow) - except TimeoutError: - logger.warning("exec not run: staging {} did not finish in time", cwd) - return ToolResult(model_text=command_writes.NOT_STAGED_REPLY, retryable=False, ok=False) + start = await command_writes.before(Path(cwd), self._shadow) env: dict[str, str] | None = None if self.path_append: diff --git a/tests/test_agent_loop_session_stamps.py b/tests/test_agent_loop_session_stamps.py index 5f3ad88d3..ceb404d17 100644 --- a/tests/test_agent_loop_session_stamps.py +++ b/tests/test_agent_loop_session_stamps.py @@ -1235,10 +1235,10 @@ def _cold_first(cmd, **kwargs): @pytest.mark.asyncio @pytest.mark.production_timing # a staging slower than the wait budget is the property -async def test_a_command_whose_snapshot_is_not_ready_in_time_is_not_run(workspace, monkeypatch): - """Run unmeasured, a command leaves a change nobody can show. Past the wait - it is not run instead: the call fails with a reply that says why, and the - staging carries on, so a later command runs and is measured.""" +async def test_a_command_whose_snapshot_is_not_ready_in_time_runs_without_a_diff(workspace, monkeypatch): + """The command matters more than its diff. Past the wait it runs all the + same, reported as a bare rewrite, and the staging carries on, so a later + command finds it done and is measured.""" import subprocess import raven.agent.loop.checkpoint as cp_module @@ -1259,39 +1259,38 @@ def _cold_first(cmd, **kwargs): monkeypatch.setattr(cp_module, "_STAGING", {}) monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 0.1) monkeypatch.setattr(cp_module.subprocess, "run", _cold_first) - runs: list[int] = [] - - def _append() -> None: - runs.append(1) - kept.write_text("one\ntwo\n", encoding="utf-8") - + steps = iter(["one\ntwo\n", "one\ntwo\nthree\n"]) script = [ _tool_call("c1", "exec", {"command": "echo two >> kept.txt"}), - _tool_call("c2", "exec", {"command": "echo two >> kept.txt"}), + _tool_call("c2", "exec", {"command": "echo three >> kept.txt"}), LLMResponse(content="done", finish_reason="stop"), ] class _ThenPatient(ScriptedProvider): async def chat(self, *args: Any, **kwargs: Any) -> Any: if len(self._script) == 2: - # The second command comes after the model has read the - # refusal; by then the wait only has to cover a warm staging, - # however loaded the machine running this is. + # By the second command the cold staging has finished, and the + # wait only has to cover a warm one, however loaded the machine. await asyncio.sleep(0.6) monkeypatch.setattr(cp_module, "_STAGE_WAIT_SECONDS", 30.0) return await super().chat(*args, **kwargs) completes = await _run_command_turn( - workspace, work, script, _append, checkpoint=True, provider=_ThenPatient(script) + workspace, + work, + script, + lambda: kept.write_text(next(steps), encoding="utf-8"), + checkpoint=True, + provider=_ThenPatient(script), ) - held, later = completes - assert held["ok"] is False - assert held["result_preview"] == command_writes.NOT_STAGED_REPLY - assert held["file_written"] is None + first, later = completes + assert first["ok"] is True + assert [Path(w["path"]).resolve() for w in first["file_written"]] == [kept.resolve()] + assert "added" not in first["file_written"][0] and "diff" not in first["file_written"][0] assert later["ok"] is True assert (later["file_written"][0]["added"], later["file_written"][0]["removed"]) == (1, 0) - assert runs == [1], "the call that was not ready must not have run the command" + assert kept.read_text(encoding="utf-8") == "one\ntwo\nthree\n" @pytest.mark.asyncio diff --git a/tests/test_shell_command_writes.py b/tests/test_shell_command_writes.py index 8a324c951..6e48d2bdc 100644 --- a/tests/test_shell_command_writes.py +++ b/tests/test_shell_command_writes.py @@ -72,19 +72,23 @@ async def test_a_rewrite_is_measured_against_the_tree_staged_just_before_it(tmp_ assert "+two" in write.diff.splitlines() -async def test_a_command_whose_tree_is_not_staged_in_time_is_not_run(tmp_path): - """Run unmeasured, the command would leave a change nobody can show. The - call fails instead, with no hint to find another way: the reply itself - says what to do.""" +@pytest.mark.parametrize("error", [TimeoutError, StagingTimeoutError]) +async def test_a_command_whose_tree_is_not_staged_in_time_still_runs_without_a_diff(tmp_path, error): + """The command matters more than its diff. Past the wait it runs all the + same and is still listed, so the file it rewrote is reported -- only not + what that file held. The checkpoint's own timeout must be a ``TimeoutError`` + for this: the tool holds the repo through a protocol and cannot import it.""" + (tmp_path / "notes.md").write_text("one\n") def _too_slow() -> str: - raise TimeoutError + raise error - result = await _tool(tmp_path, _Shadow(tmp_path, stage=_too_slow)).execute(command="echo x > made.txt") + result = await _tool(tmp_path, _Shadow(tmp_path, stage=_too_slow)).execute(command="echo two >> notes.md") - assert not (tmp_path / "made.txt").exists(), "the command must not have run" - assert result.model_text == command_writes.NOT_STAGED_REPLY - assert result.ok is False and result.retryable is False + assert (tmp_path / "notes.md").read_text() == "one\ntwo\n", "the command must have run" + assert result.ok is True + [write] = result.written + assert (write.created, write.added, write.diff) == (False, None, None) async def test_a_tree_that_cannot_be_staged_leaves_the_command_to_run_unmeasured(tmp_path): @@ -214,16 +218,3 @@ def test_the_tools_ceiling_covers_the_longest_command_and_the_longest_wait(): from raven.agent.loop import checkpoint assert ExecTool.timeout_seconds > ExecTool._MAX_TIMEOUT + checkpoint._STAGE_WAIT_SECONDS - - -@pytest.mark.parametrize("error", [TimeoutError, StagingTimeoutError]) -async def test_the_checkpoints_own_timeout_is_one_the_tool_catches(tmp_path, error): - """The tool holds the repo through a protocol and cannot import its error; - what it catches is ``TimeoutError``, so the repo's must be one.""" - - def _raise() -> str: - raise error - - result = await _tool(tmp_path, _Shadow(tmp_path, stage=_raise)).execute(command="true") - - assert result.model_text == command_writes.NOT_STAGED_REPLY From a00c8f1589dfdaa1df4063ddc99bcdbb30faf455 Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Wed, 30 Sep 2026 10:32:41 +0800 Subject: [PATCH 4/9] fix(agent): bound what exec measures after its command, inside its ceiling The registry's 780s ceiling covered the staging wait and the 600s command cap but not the measuring that follows the command. A command near its cap could finish and change files, then be cut off while its files were still being read, losing both its output and the record of what it wrote. Everything after the command is now bounded short of the ceiling. The shadow repo's reads (trackable, read_blobs) get 60s; past that every file goes out without text, a named removal's included. The whole post-command step (second walk, those reads, reading the written files) gets 120s; past that the call returns the command's output with no record of its files. The ceiling is now 900s: the 120s staging wait, the 600s command cap, the 120s measuring bound and a margin. A git read whose caller stops waiting now kills its process instead of leaving it running. Co-authored-by: Claude (claude-opus-5-5) --- raven/agent/loop/checkpoint.py | 6 ++++ raven/agent/tools/command_writes.py | 52 ++++++++++++++++++++++++++--- raven/agent/tools/shell.py | 11 +++--- tests/test_runtime_checkpoint.py | 29 ++++++++++++++++ tests/test_shell_command_writes.py | 52 +++++++++++++++++++++++++++-- 5 files changed, 139 insertions(+), 11 deletions(-) diff --git a/raven/agent/loop/checkpoint.py b/raven/agent/loop/checkpoint.py index 7e65f8587..9c1a17a12 100644 --- a/raven/agent/loop/checkpoint.py +++ b/raven/agent/loop/checkpoint.py @@ -310,6 +310,12 @@ async def _run( " ".join(args[:2]), ) return -1, b"", b"timeout" + except asyncio.CancelledError: + # A caller that stopped waiting (a bounded measurement, a + # cancelled turn) must not leave its git running. + with contextlib.suppress(ProcessLookupError): + proc.kill() + raise return proc.returncode or 0, out, err async def _ensure_init(self) -> bool: diff --git a/raven/agent/tools/command_writes.py b/raven/agent/tools/command_writes.py index 741ee2724..d8777200b 100644 --- a/raven/agent/tools/command_writes.py +++ b/raven/agent/tools/command_writes.py @@ -38,6 +38,16 @@ #: diff is dropped whole: half a diff reads as a smaller change than happened. DIFF_BUDGET_CHARS = 512 * 1024 +#: How long the shadow repo may take to say, after a command, which files may +#: be shown and what they held. Past it the files go out without their text. +READ_WAIT_SECONDS = 60.0 + +#: How long everything after a command may take: the second walk, those reads, +#: and reading the written files. Past it the call returns with the command's +#: output and no record of its files, rather than be cut off by the registry's +#: ceiling with neither. ``ExecTool.timeout_seconds`` budgets for it. +AFTER_WAIT_SECONDS = 120.0 + class ShadowTree(Protocol): """The part of the checkpoint's shadow repo a command is measured against. @@ -113,7 +123,24 @@ async def after( stays in the index, and its text must not be shown for that. Where there is no shadow repo to ask, a created file keeps its counts only, and a rewrite or listed removal has no earlier text to show. + + Bounded (:data:`AFTER_WAIT_SECONDS`): the command has already run, and its + output must reach the model whatever the measuring costs. Past the bound + nothing is reported, and a named removal keeps its text only where no + shadow repo could have ruled on it. """ + try: + return await asyncio.wait_for(_after(start, named), AFTER_WAIT_SECONDS) + except TimeoutError: + logger.warning("exec files not recorded: measuring {} did not finish in time", start.root) + if start.shadow is None: + return (), named + return (), tuple(FileRemoval(path=removal.path) for removal in named) + + +async def _after( + start: Before, named: tuple[FileRemoval, ...] +) -> tuple[tuple[FileWrite, ...], tuple[FileRemoval, ...]]: listing = await asyncio.to_thread(snapshot.take, start.root) accounted = {os.path.realpath(removal.path) for removal in named} created, modified, deleted = ( @@ -124,11 +151,14 @@ async def after( shown: set[str] = set() if start.shadow is not None and start.tree is not None: subjects = [*created, *modified, *deleted, *(removal.path for removal in named if removal.before is not None)] - if subjects: - shown = await start.shadow.trackable(subjects) - readable = [path for path in [*modified, *deleted] if path in shown] - if readable: - held = await start.shadow.read_blobs(start.tree, readable, max_bytes=TEXT_MAX_BYTES) + try: + shown, held = await asyncio.wait_for( + _shown_and_held(start.shadow, start.tree, subjects, [*modified, *deleted]), READ_WAIT_SECONDS + ) + except TimeoutError: + # Nothing the repo did not rule on goes out: every file stays bare. + logger.warning("exec diffs dropped: the shadow repo for {} did not answer in time", start.root) + shown, held = set(), {} named = tuple(removal if removal.path in shown else FileRemoval(path=removal.path) for removal in named) # Off the loop too: this reads every written file, and one command can write hundreds. written = ( @@ -138,6 +168,16 @@ async def after( return written, removed +async def _shown_and_held( + shadow: ShadowTree, tree: str, subjects: list[str], changed: list[str] +) -> tuple[set[str], dict[str, bytes]]: + """The subjects the repo's rules would store, and what those of ``changed`` held.""" + shown = await shadow.trackable(subjects) if subjects else set() + readable = [path for path in changed if path in shown] + held = await shadow.read_blobs(tree, readable, max_bytes=TEXT_MAX_BYTES) if readable else {} + return shown, held + + def _writes( created: Collection[str], modified: Collection[str], @@ -197,7 +237,9 @@ def _line_diff(old: str, new: str, name: str) -> tuple[str | None, int, int]: __all__ = [ + "AFTER_WAIT_SECONDS", "DIFF_BUDGET_CHARS", + "READ_WAIT_SECONDS", "TEXT_MAX_BYTES", "Before", "ShadowFor", diff --git a/raven/agent/tools/shell.py b/raven/agent/tools/shell.py index 592bb9855..6f3b1f7b7 100644 --- a/raven/agent/tools/shell.py +++ b/raven/agent/tools/shell.py @@ -55,10 +55,13 @@ def __init__(self, construct: str) -> None: class ExecTool(Tool): """Tool to execute shell commands.""" - # Backstop above the 600s internal exec cap (``_MAX_TIMEOUT``) plus the - # 120s a command may wait for the tree it is measured against; the - # executor's own timeout fires first, this only catches a wedged executor. - timeout_seconds = 780.0 + # Backstop above everything a call may legitimately spend: the 120s a + # command may wait for the tree it is measured against, the 600s internal + # exec cap (``_MAX_TIMEOUT``) and the 120s its files may take to measure + # afterwards (``command_writes.AFTER_WAIT_SECONDS``), plus a margin. Each + # of those has its own bound that fires first; this only catches a wedged + # executor, and cutting a call off here loses the command's output. + timeout_seconds = 900.0 approval_kind = "shell.exec" def __init__( diff --git a/tests/test_runtime_checkpoint.py b/tests/test_runtime_checkpoint.py index 048c957e9..75f351891 100644 --- a/tests/test_runtime_checkpoint.py +++ b/tests/test_runtime_checkpoint.py @@ -1117,3 +1117,32 @@ def _raise(*_args: object, **_kwargs: object) -> None: monkeypatch.setattr(svc, "_stage_step", _raise) assert await asyncio.wait_for(svc.stage_tree(), 30) is None + + +async def test_a_git_call_whose_caller_stops_waiting_is_killed(workspace, monkeypatch): + """A bounded measurement or a cancelled turn stops waiting on a git read; + the git itself must not be left running behind it.""" + import os + + svc = CheckpointService(workspace) + pid_file = workspace / "pid" + monkeypatch.setattr( + svc, "_command", lambda _args, _index: (["sh", "-c", f"echo $$ > {pid_file}; exec sleep 30"], None) + ) + + call = asyncio.ensure_future(svc._run(("cat-file", "--batch"), stdin=b"")) + while not pid_file.exists() or not pid_file.read_text().strip(): + await asyncio.sleep(0.01) + pid = int(pid_file.read_text()) + call.cancel() + with pytest.raises(asyncio.CancelledError): + await call + + for _ in range(200): + try: + os.kill(pid, 0) + except ProcessLookupError: + break + await asyncio.sleep(0.01) + else: + pytest.fail("the git process outlived the call that stopped waiting on it") diff --git a/tests/test_shell_command_writes.py b/tests/test_shell_command_writes.py index 6e48d2bdc..92ce34896 100644 --- a/tests/test_shell_command_writes.py +++ b/tests/test_shell_command_writes.py @@ -10,6 +10,7 @@ from __future__ import annotations +import asyncio import threading from pathlib import Path from typing import Any, Collection @@ -24,9 +25,12 @@ class _Shadow: """A shadow repo whose tree is whatever the directory held at staging.""" - def __init__(self, root: Path, *, stage: Any = None, ignored: Collection[str] = ()) -> None: + def __init__( + self, root: Path, *, stage: Any = None, ignored: Collection[str] = (), answer_after: float = 0.0 + ) -> None: self._root = root self._stage = stage + self._answer_after = answer_after self._ignored = set(ignored) self._trees: dict[str, dict[str, bytes]] = {} self.staged = 0 @@ -48,6 +52,7 @@ async def read_blobs(self, tree: str, paths: Collection[str], *, max_bytes: int) return {path: held[path] for path in paths if path in held and len(held[path]) <= max_bytes} async def trackable(self, paths: Collection[str]) -> set[str]: + await asyncio.sleep(self._answer_after) return {path for path in paths if Path(path).name not in self._ignored} @@ -217,4 +222,47 @@ def test_the_tools_ceiling_covers_the_longest_command_and_the_longest_wait(): two together would kill a command the executor was still allowed to run.""" from raven.agent.loop import checkpoint - assert ExecTool.timeout_seconds > ExecTool._MAX_TIMEOUT + checkpoint._STAGE_WAIT_SECONDS + spent = checkpoint._STAGE_WAIT_SECONDS + ExecTool._MAX_TIMEOUT + command_writes.AFTER_WAIT_SECONDS + assert ExecTool.timeout_seconds > spent + assert command_writes.AFTER_WAIT_SECONDS > command_writes.READ_WAIT_SECONDS + + +async def test_a_shadow_repo_too_slow_to_answer_after_the_command_leaves_every_file_bare(tmp_path, monkeypatch): + """The command has run; what the repo would have said about its files is + worth less than its output. Past the wait the files go out without text -- + including a named removal's, which the repo never got to rule on.""" + monkeypatch.setattr(command_writes, "READ_WAIT_SECONDS", 0.05) + (tmp_path / "notes.md").write_text("one\n") + (tmp_path / "gone.txt").write_text("secret\n") + + result = await _tool(tmp_path, _Shadow(tmp_path, answer_after=5.0)).execute( + command="echo two >> notes.md && rm gone.txt" + ) + + assert "Exit code: 0" in result + [write] = result.written + assert (write.added, write.diff) == (None, None) + assert [(Path(r.path).name, r.before) for r in result.removed] == [("gone.txt", None)] + + +async def test_measuring_that_runs_past_its_bound_still_returns_the_commands_output(tmp_path, monkeypatch): + """Everything after the command is bounded short of the registry's ceiling, + so a slow walk costs the record of the files and never the output.""" + monkeypatch.setattr(command_writes, "AFTER_WAIT_SECONDS", 0.2) + real_take = snapshot.take + walks: list[int] = [] + + def _slow_second_walk(root: Any) -> Any: + walks.append(1) + if len(walks) == 2: + import time + + time.sleep(1.0) + return real_take(root) + + monkeypatch.setattr(snapshot, "take", _slow_second_walk) + + result = await _tool(tmp_path, _Shadow(tmp_path)).execute(command="echo done && echo x > made.txt") + + assert "done" in result and result.ok is True + assert result.written == () From e87f0252738967e6986d6dd76e4434f2843fb3cb Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Wed, 30 Sep 2026 12:36:11 +0800 Subject: [PATCH 5/9] fix(agent): gate exec file text on the repo's rules even without a tree Three holes in what an exec command reports about its files: - A staging that failed or ran late dropped the shadow repo along with its tree, so a named removal such as `rm .env` kept its body. Whether text may be shown is the repo's rules (`trackable`), which need no tree; `Before` now keeps the repo whenever one was handed in, and only the earlier text of a rewrite or removal needs the tree. - The turn's removal watch refilled a removal the tool had reported without its body, which is exactly the blank the gate writes. The watch now takes the tool's report as given, as it did before. - Measuring was switched on by a constructor argument at the one place the built-in exec is built, so a plugin's same-name replacement (raven-code's CodeExecTool) reported no files. The loop now asks whatever answers to `exec` once every tool is registered (`ExecTool.measure_writes`), and that call raises the tool's registry ceiling by what measuring may take, so the replacement's own ceiling keeps its margin too. Co-authored-by: Claude (claude-opus-5-5) --- raven/agent/loop/wiring.py | 7 ++- raven/agent/tools/command_writes.py | 20 +++++--- raven/agent/tools/removals.py | 10 ++-- raven/agent/tools/shell.py | 36 +++++++++----- tests/test_agent_loop_session_stamps.py | 66 ++++++++++++++++++++----- tests/test_removal_watch.py | 16 +++++- tests/test_shell_command_writes.py | 61 ++++++++++++++++++----- 7 files changed, 165 insertions(+), 51 deletions(-) diff --git a/raven/agent/loop/wiring.py b/raven/agent/loop/wiring.py index 4f35a27ca..6e3f16499 100644 --- a/raven/agent/loop/wiring.py +++ b/raven/agent/loop/wiring.py @@ -934,8 +934,6 @@ def _register_default_tools(self) -> None: path_append=self.exec_config.path_append, executor=self._executor, extra_allowed_dirs=(self.workspace,), - record_writes=True, - shadow=self._command_shadow, ) ) # The registry writer beside exec's machine channel, for the products @@ -1056,6 +1054,11 @@ def picture_vendor() -> str: # playbook funnel) assembled after even this registry is populated. for tool in self.plugin_tools: self.tools.register(tool) + # Whatever answers to ``exec`` now, the built-in or a plugin's same-name + # replacement, reports the files its commands wrote and removed. + measure_writes = getattr(self.tools.get("exec"), "measure_writes", None) + if callable(measure_writes): + measure_writes(self._command_shadow) # Skill retrieval tools (body -> scripts). Both are source-agnostic and # both serve local/everos straight from the registry, so both register diff --git a/raven/agent/tools/command_writes.py b/raven/agent/tools/command_writes.py index d8777200b..2f73c69e5 100644 --- a/raven/agent/tools/command_writes.py +++ b/raven/agent/tools/command_writes.py @@ -45,9 +45,14 @@ #: How long everything after a command may take: the second walk, those reads, #: and reading the written files. Past it the call returns with the command's #: output and no record of its files, rather than be cut off by the registry's -#: ceiling with neither. ``ExecTool.timeout_seconds`` budgets for it. +#: ceiling with neither. AFTER_WAIT_SECONDS = 120.0 +#: The most measuring adds to a call: the shadow repo's wait for a staging (the +#: checkpoint's ``_STAGE_WAIT_SECONDS``) and :data:`AFTER_WAIT_SECONDS`. A tool +#: that measures raises its registry ceiling by it. +MEASURE_SECONDS = 120.0 + AFTER_WAIT_SECONDS + class ShadowTree(Protocol): """The part of the checkpoint's shadow repo a command is measured against. @@ -75,7 +80,9 @@ class Before: root: Path listing: snapshot.Snapshot | None + #: The repo that rules on what may be shown, wherever one covers ``root``. shadow: ShadowTree | None = None + #: What it staged just before the command, or ``None`` where that failed. tree: str | None = None @@ -100,8 +107,8 @@ async def before(root: Path, shadow_for: ShadowFor | None) -> Before: # the next command's staging fast. logger.warning("exec measured without a diff: staging {} did not finish in time", root) tree = None - if tree is None: - return Before(root, listing) + # The repo is kept without a tree: what a file held needs the tree, but + # whether its text may be shown is the repo's rules, which need none. return Before(root, listing, shadow, tree) @@ -149,7 +156,7 @@ async def _after( ) held: dict[str, bytes] = {} shown: set[str] = set() - if start.shadow is not None and start.tree is not None: + if start.shadow is not None: subjects = [*created, *modified, *deleted, *(removal.path for removal in named if removal.before is not None)] try: shown, held = await asyncio.wait_for( @@ -169,12 +176,12 @@ async def _after( async def _shown_and_held( - shadow: ShadowTree, tree: str, subjects: list[str], changed: list[str] + shadow: ShadowTree, tree: str | None, subjects: list[str], changed: list[str] ) -> tuple[set[str], dict[str, bytes]]: """The subjects the repo's rules would store, and what those of ``changed`` held.""" shown = await shadow.trackable(subjects) if subjects else set() readable = [path for path in changed if path in shown] - held = await shadow.read_blobs(tree, readable, max_bytes=TEXT_MAX_BYTES) if readable else {} + held = await shadow.read_blobs(tree, readable, max_bytes=TEXT_MAX_BYTES) if tree is not None and readable else {} return shown, held @@ -239,6 +246,7 @@ def _line_diff(old: str, new: str, name: str) -> tuple[str | None, int, int]: __all__ = [ "AFTER_WAIT_SECONDS", "DIFF_BUDGET_CHARS", + "MEASURE_SECONDS", "READ_WAIT_SECONDS", "TEXT_MAX_BYTES", "Before", diff --git a/raven/agent/tools/removals.py b/raven/agent/tools/removals.py index 85ca802a5..585425a79 100644 --- a/raven/agent/tools/removals.py +++ b/raven/agent/tools/removals.py @@ -58,14 +58,12 @@ def settle(self, reported: Any = ()) -> list[FileRemoval]: removals = [ removal for removal in (reported or ()) if isinstance(getattr(removal, "path", None), str) and removal.path ] - already = {removal.path: index for index, removal in enumerate(removals)} + already = {removal.path for removal in removals} for path in list(self._touched): if path in already: - # What this run wrote there is the file's last known text, which - # a report read off the disk after the fact may not have. - text = self._forget(path) - if removals[already[path]].before is None and text is not None: - removals[already[path]] = FileRemoval(path=path, before=text) + # The report stands as given, a blank body included: a tool that + # withheld a file's text (``command_writes``) did so on purpose. + self._forget(path) continue if not os.path.exists(path): removals.append(FileRemoval(path=path, before=self._forget(path))) diff --git a/raven/agent/tools/shell.py b/raven/agent/tools/shell.py index 6f3b1f7b7..9ac7c4c42 100644 --- a/raven/agent/tools/shell.py +++ b/raven/agent/tools/shell.py @@ -55,13 +55,11 @@ def __init__(self, construct: str) -> None: class ExecTool(Tool): """Tool to execute shell commands.""" - # Backstop above everything a call may legitimately spend: the 120s a - # command may wait for the tree it is measured against, the 600s internal - # exec cap (``_MAX_TIMEOUT``) and the 120s its files may take to measure - # afterwards (``command_writes.AFTER_WAIT_SECONDS``), plus a margin. Each - # of those has its own bound that fires first; this only catches a wedged - # executor, and cutting a call off here loses the command's output. - timeout_seconds = 900.0 + # Backstop above the 600s internal exec cap (``_MAX_TIMEOUT``); the + # executor's own timeout fires first, this only catches a wedged executor. + # A tool that measures its commands' files adds what the measuring may + # take (``measure_writes``): cutting a call off here loses its output. + timeout_seconds = 660.0 approval_kind = "shell.exec" def __init__( @@ -91,12 +89,10 @@ def __init__( # convention as the filesystem tools). The main loop's ExecTool keeps # following the live binding as normal. self.follow_binding = follow_binding - # Whether a command's result says which files it created, rewrote and - # removed, read off its directory either side (``command_writes``); and - # the shadow repo that says what those files held, for their diffs. - # Off for a lane whose runner lists every call itself. - self.record_writes = record_writes - self._shadow = shadow + self.record_writes = False + self._shadow: command_writes.ShadowFor | None = None + if record_writes: + self.measure_writes(shadow) self.path_append = path_append self._executor: SandboxExecutor = executor if executor is not None else DirectExecutor() if not self._executor.is_sandboxed: @@ -125,6 +121,20 @@ def timeout(self) -> int: def name(self) -> str: return "exec" + def measure_writes(self, shadow: command_writes.ShadowFor | None) -> None: + """Have each command's result say which files it created, rewrote and removed. + + Read off its directory either side (``command_writes``), with ``shadow`` + saying what those files held, for their diffs, and which of them may be + shown. Asked of whatever tool answers to ``exec`` once the loop's tools + are all registered, so a same-name replacement measures as the built-in + does. Left off for a lane whose runner lists every call itself. + """ + if not self.record_writes: + self.timeout_seconds += command_writes.MEASURE_SECONDS + self.record_writes = True + self._shadow = shadow + async def warm(self, root: Path) -> None: """Start staging ``root`` into the shadow repo, ahead of its first command. diff --git a/tests/test_agent_loop_session_stamps.py b/tests/test_agent_loop_session_stamps.py index ceb404d17..cae991cae 100644 --- a/tests/test_agent_loop_session_stamps.py +++ b/tests/test_agent_loop_session_stamps.py @@ -574,6 +574,7 @@ def _command_agent( *, checkpoint: bool = False, provider: LLMProvider | None = None, + plugin_tools: list[Tool] | None = None, ) -> AgentLoop: """A loop with its own ``exec``, running ``action`` in place of the shell when given. @@ -586,7 +587,7 @@ def _command_agent( workspace=workspace, model="stub", policy=TurnPolicy(max_iterations=4, interactive=False), - tools=ToolWiring(restrict_to_workspace=True), + tools=ToolWiring(restrict_to_workspace=True, plugin_tools=plugin_tools), engine=EngineWiring( runtime_config=RuntimeConfig(checkpoint=CheckpointConfig(policy="always" if checkpoint else "never")) ), @@ -604,13 +605,16 @@ async def _run_command_turn( *, checkpoint: bool = False, provider: LLMProvider | None = None, + plugin_tools: list[Tool] | None = None, ): """One real turn whose working directory is ``work``, as a served turn has. Bound rather than defaulted so the command runs in, and is measured in, the directory the test prepared and not the session store beside it. """ - agent = _command_agent(workspace, script, action, checkpoint=checkpoint, provider=provider) + agent = _command_agent( + workspace, script, action, checkpoint=checkpoint, provider=provider, plugin_tools=plugin_tools + ) completes: list[dict[str, Any]] = [] async def on_tool_event(phase: str, info: dict[str, Any]) -> None: @@ -895,24 +899,27 @@ async def test_a_removal_the_command_named_is_not_reported_twice(workspace): @pytest.mark.asyncio -async def test_a_file_this_turn_wrote_keeps_its_text_when_a_command_removes_it_unseen(workspace): - """The listing reports the deletion without a body when no shadow repo held - the file. The turn itself wrote it, though, so what it wrote is still the - last thing anyone knew the file to hold.""" +@pytest.mark.parametrize("name", ["made.txt", "local.secret"]) +async def test_a_file_this_turn_wrote_is_removed_with_the_text_the_command_reported(workspace, name): + """The turn's own watch also holds what the turn wrote to a path, and a + command that removes it reports that removal itself. The command's report + stands: where the repo's rules keep the file's text back, a body the watch + still holds must not put it on the wire.""" work = workspace / "work" work.mkdir() - made = work / "made.txt" + (work / ".gitignore").write_text("*.secret\n", encoding="utf-8") + made = work / name script = [ - _tool_call("c1", "write_file", {"path": str(made), "content": "x\ny\n"}), - _tool_call("c2", "exec", {"command": "find . -name '*.txt' -delete"}), + _tool_call("c1", "write_file", {"path": str(made), "content": "TOKEN=x\n"}), + _tool_call("c2", "exec", {"command": "find . -name 'made.txt' -delete -o -name '*.secret' -delete"}), LLMResponse(content="done", finish_reason="stop"), ] - completes = await _run_command_turn(workspace, work, script, made.unlink) + completes = await _run_command_turn(workspace, work, script, made.unlink, checkpoint=True) removed = completes[1]["file_removed"] - assert len(removed) == 1, removed - assert removed[0]["before"] == "x\ny\n" + assert [Path(r["path"]).name for r in removed] == [name] + assert removed[0].get("before") == ("TOKEN=x\n" if name == "made.txt" else None) @pytest.mark.asyncio @@ -1002,6 +1009,41 @@ async def test_the_real_command_tool_lists_the_directory_it_was_bound_to(workspa assert written[(work / "keep.md").resolve()]["created"] is False +@pytest.mark.asyncio +async def test_a_plugin_exec_that_replaces_the_built_in_reports_its_files_as_the_built_in_does(workspace, monkeypatch): + """A plugin may replace a built-in by contributing its name, and raven-code + ships an ``exec`` that does. Whatever answers to ``exec`` once the tools are + registered is the one asked to measure, so a command run through the + replacement reports what it created and what it removed without naming.""" + monkeypatch.syspath_prepend(str(Path(__file__).resolve().parent.parent / "agents/raven-code/plugins/code-flow")) + from code_flow.tools.exec import CodeExecTool, CodeExecutor + + work = workspace / "work" + work.mkdir() + (work / "gone.txt").write_text("x\n", encoding="utf-8") + replacement = CodeExecTool( + working_dir=str(workspace), + restrict_to_workspace=True, + executor=CodeExecutor(max_timeout=1200, spill_dir=workspace / "spill"), + extra_allowed_dirs=(workspace,), + max_timeout=1200, + ) + + completes = await _run_command_turn( + workspace, + work, + _command_script("printf 'a\\nb\\n' > made.txt && find . -name 'gone.txt' -delete"), + checkpoint=True, + plugin_tools=[replacement], + ) + + assert not (work / "gone.txt").exists() and (work / "made.txt").exists(), "the command must have run" + [write] = completes[0]["file_written"] + assert (Path(write["path"]).name, write["created"], write["added"]) == ("made.txt", True, 2) + assert [(Path(r["path"]).name, r.get("before")) for r in completes[0]["file_removed"]] == [("gone.txt", "x\n")] + assert replacement.timeout_seconds == 1200 + 60 + command_writes.MEASURE_SECONDS + + @pytest.mark.asyncio async def test_the_real_command_tool_rewrite_is_measured_against_the_staged_tree(workspace): """A real shell writes through its own cwd, which is the tree the stage diff --git a/tests/test_removal_watch.py b/tests/test_removal_watch.py index 25a98936e..abd97cc92 100644 --- a/tests/test_removal_watch.py +++ b/tests/test_removal_watch.py @@ -11,7 +11,7 @@ from pathlib import Path from raven.agent.tools.removals import WATCHED_TEXT_MAX_CHARS, WATCHED_TOTAL_MAX_CHARS, RemovalWatch -from raven.contracts.tool import FileChange +from raven.contracts.tool import FileChange, FileRemoval def test_a_written_file_that_vanished_is_reported_with_what_it_held(tmp_path: Path) -> None: @@ -79,3 +79,17 @@ def test_rewriting_a_path_gives_its_room_back(tmp_path: Path) -> None: gone.unlink() assert [(r.path, r.before) for r in watch.settle()] == [(str(gone), body)] + + +def test_a_removal_the_tool_reported_keeps_the_body_it_was_reported_with(tmp_path: Path) -> None: + """A tool that reports a removal without its body may have withheld it on + purpose -- the command tool does, for a file the checkpoint would not store. + What the watch holds for that path must not put the body back.""" + gone = tmp_path / "creds.env" + gone.write_text("SECRET") + watch = RemovalWatch() + watch.note_write(FileChange(path=str(gone), after="SECRET")) + gone.unlink() + + assert [(r.path, r.before) for r in watch.settle((FileRemoval(path=str(gone)),))] == [(str(gone), None)] + assert watch.settle() == [] diff --git a/tests/test_shell_command_writes.py b/tests/test_shell_command_writes.py index 92ce34896..2654fe3d2 100644 --- a/tests/test_shell_command_writes.py +++ b/tests/test_shell_command_writes.py @@ -48,6 +48,7 @@ async def stage_tree(self) -> str | None: return tree async def read_blobs(self, tree: str, paths: Collection[str], *, max_bytes: int) -> dict[str, bytes]: + assert tree is not None, "no tree was staged, so there is none to read" held = self._trees.get(tree, {}) return {path: held[path] for path in paths if path in held and len(held[path]) <= max_bytes} @@ -96,16 +97,47 @@ def _too_slow() -> str: assert (write.created, write.added, write.diff) == (False, None, None) -async def test_a_tree_that_cannot_be_staged_leaves_the_command_to_run_unmeasured(tmp_path): +async def test_a_tree_that_cannot_be_staged_leaves_the_command_to_run_without_what_its_files_held(tmp_path): """A git that failed, a directory the repo cannot hold: nothing about the - filesystem says the command should not run, so it does, reported without - the text no repo vouched for.""" - result = await _tool(tmp_path, _Shadow(tmp_path, stage=lambda: None)).execute(command="printf 'x\\n' > made.txt") + filesystem says the command should not run, so it does. A rewrite has no + earlier text to be shown against; a created file needs none.""" + (tmp_path / "notes.md").write_text("one\n") + + result = await _tool(tmp_path, _Shadow(tmp_path, stage=lambda: None)).execute( + command="printf 'x\\n' > made.txt && echo two >> notes.md" + ) assert (tmp_path / "made.txt").read_text() == "x\n" + written = {Path(w.path).name: w for w in result.written} + assert (written["made.txt"].created, written["made.txt"].lines, written["made.txt"].added) == (True, 1, 1) + assert "+x" in written["made.txt"].diff.splitlines() + assert (written["notes.md"].added, written["notes.md"].diff) == (None, None) + + +def _no_tree() -> None: + return None + + +def _late_tree() -> str: + raise TimeoutError + + +@pytest.mark.parametrize("stage", [_no_tree, _late_tree], ids=["not-staged", "staged-too-late"]) +async def test_a_tree_that_was_not_staged_still_leaves_the_repo_to_rule_on_what_may_be_shown(tmp_path, stage): + """Whether a file's text may be shown is the repo's rules, which need no + tree. A staging that failed or ran late costs the diffs a tree would give; + it must not also let a ``.env`` the command removed by name, or created, + go out with its text, while an ordinary file keeps its own.""" + (tmp_path / ".env").write_text("API_KEY=top-secret\n") + (tmp_path / "notes.md").write_text("one\n") + + result = await _tool(tmp_path, _Shadow(tmp_path, stage=stage, ignored={".env", "made.env"})).execute( + command="rm .env notes.md && printf 'TOKEN=x\\n' > made.env" + ) + + assert {Path(r.path).name: r.before for r in result.removed} == {".env": None, "notes.md": "one\n"} [write] = result.written - assert (write.created, write.lines, write.added) == (True, 1, 1) - assert write.diff is None + assert (Path(write.path).name, write.added, write.diff) == ("made.env", 1, None) async def test_a_created_file_the_repo_would_not_store_keeps_its_counts_and_loses_its_text(tmp_path): @@ -216,14 +248,21 @@ async def test_warming_stages_through_the_shadow_repo_and_is_a_no_op_without_one assert shadow.warmed == 1, "only the tool that records writes warms for them" -def test_the_tools_ceiling_covers_the_longest_command_and_the_longest_wait(): - """The registry kills a call past the tool's ceiling. A command may wait out - its staging and then run to the executor's own cap, and a ceiling under the - two together would kill a command the executor was still allowed to run.""" +def test_a_measuring_tools_ceiling_covers_the_longest_command_and_the_longest_waits(): + """The registry kills a call past the tool's ceiling. A measured command may + wait out its staging, run to the executor's own cap and then have its files + measured, and a ceiling under the three together would kill a command the + executor was still allowed to run -- losing its output. Asked twice, the + tool raises its ceiling once.""" from raven.agent.loop import checkpoint + tool = ExecTool(record_writes=True) spent = checkpoint._STAGE_WAIT_SECONDS + ExecTool._MAX_TIMEOUT + command_writes.AFTER_WAIT_SECONDS - assert ExecTool.timeout_seconds > spent + assert tool.timeout_seconds > spent + assert command_writes.MEASURE_SECONDS == checkpoint._STAGE_WAIT_SECONDS + command_writes.AFTER_WAIT_SECONDS + tool.measure_writes(None) + assert tool.timeout_seconds == ExecTool.timeout_seconds + command_writes.MEASURE_SECONDS + assert ExecTool().timeout_seconds == ExecTool.timeout_seconds > ExecTool._MAX_TIMEOUT assert command_writes.AFTER_WAIT_SECONDS > command_writes.READ_WAIT_SECONDS From 77678e904f3a00b9fe5834c338438e23a0aa7667 Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Wed, 30 Sep 2026 12:48:46 +0800 Subject: [PATCH 6/9] fix(agent): tell a withheld removal body apart from an unknown one The previous fix stopped the turn's removal watch from refilling any removal the tool reported without a body. That closed the secret refill but also dropped the only copy of a file the turn wrote and a command then removed unseen with the checkpoint off, where no tree can supply the text. `FileRemoval` gains `withheld`: set when the command tool kept the text back on purpose (the repo's rules would not store the file, or no rule was read in time). The watch fills in a bare removal from what the turn wrote only when it is not withheld. Only a present shadow repo can withhold, so with the checkpoint off every bare removal stays fillable, as before this PR. Co-authored-by: Claude (claude-opus-5-5) --- raven/agent/tools/command_writes.py | 18 ++++++++++++----- raven/agent/tools/removals.py | 12 ++++++++---- raven/contracts/tool.py | 5 +++++ tests/test_agent_loop_session_stamps.py | 21 ++++++++++++++++++++ tests/test_contracts_two_tier_ledger.py | 2 +- tests/test_removal_watch.py | 23 +++++++++++++++++----- tests/test_shell_command_writes.py | 26 ++++++++++++++++++++++--- 7 files changed, 89 insertions(+), 18 deletions(-) diff --git a/raven/agent/tools/command_writes.py b/raven/agent/tools/command_writes.py index 2f73c69e5..4ab66405c 100644 --- a/raven/agent/tools/command_writes.py +++ b/raven/agent/tools/command_writes.py @@ -134,7 +134,7 @@ async def after( Bounded (:data:`AFTER_WAIT_SECONDS`): the command has already run, and its output must reach the model whatever the measuring costs. Past the bound nothing is reported, and a named removal keeps its text only where no - shadow repo could have ruled on it. + shadow repo could have ruled on it; elsewhere it goes out ``withheld``. """ try: return await asyncio.wait_for(_after(start, named), AFTER_WAIT_SECONDS) @@ -142,7 +142,7 @@ async def after( logger.warning("exec files not recorded: measuring {} did not finish in time", start.root) if start.shadow is None: return (), named - return (), tuple(FileRemoval(path=removal.path) for removal in named) + return (), tuple(FileRemoval(path=removal.path, withheld=True) for removal in named) async def _after( @@ -157,7 +157,7 @@ async def _after( held: dict[str, bytes] = {} shown: set[str] = set() if start.shadow is not None: - subjects = [*created, *modified, *deleted, *(removal.path for removal in named if removal.before is not None)] + subjects = [*created, *modified, *deleted, *(removal.path for removal in named)] try: shown, held = await asyncio.wait_for( _shown_and_held(start.shadow, start.tree, subjects, [*modified, *deleted]), READ_WAIT_SECONDS @@ -166,12 +166,20 @@ async def _after( # Nothing the repo did not rule on goes out: every file stays bare. logger.warning("exec diffs dropped: the shadow repo for {} did not answer in time", start.root) shown, held = set(), {} - named = tuple(removal if removal.path in shown else FileRemoval(path=removal.path) for removal in named) + named = tuple( + removal if removal.path in shown else FileRemoval(path=removal.path, withheld=True) for removal in named + ) # Off the loop too: this reads every written file, and one command can write hundreds. written = ( await asyncio.to_thread(_writes, created, modified, listing or {}, held, shown) if created or modified else () ) - removed = named + tuple(FileRemoval(path=path, before=_decoded(held.get(path))) for path in deleted) + # A body the rules kept back is marked so, and no other record of the file + # may put it back; one that is merely unknown is left for them to supply. + ruled = start.shadow is not None + removed = named + tuple( + FileRemoval(path=path, before=_decoded(held.get(path)), withheld=ruled and path not in shown) + for path in deleted + ) return written, removed diff --git a/raven/agent/tools/removals.py b/raven/agent/tools/removals.py index 585425a79..69e466308 100644 --- a/raven/agent/tools/removals.py +++ b/raven/agent/tools/removals.py @@ -58,12 +58,16 @@ def settle(self, reported: Any = ()) -> list[FileRemoval]: removals = [ removal for removal in (reported or ()) if isinstance(getattr(removal, "path", None), str) and removal.path ] - already = {removal.path for removal in removals} + already = {removal.path: index for index, removal in enumerate(removals)} for path in list(self._touched): if path in already: - # The report stands as given, a blank body included: a tool that - # withheld a file's text (``command_writes``) did so on purpose. - self._forget(path) + # What this run wrote there is the file's last known text, which + # a report read off the disk after the fact may not have -- unless + # the tool kept that text back on purpose. + text = self._forget(path) + report = removals[already[path]] + if getattr(report, "before", None) is None and not getattr(report, "withheld", False) and text: + removals[already[path]] = FileRemoval(path=path, before=text) continue if not os.path.exists(path): removals.append(FileRemoval(path=path, before=self._forget(path))) diff --git a/raven/contracts/tool.py b/raven/contracts/tool.py index c27fddb54..c337e549a 100644 --- a/raven/contracts/tool.py +++ b/raven/contracts/tool.py @@ -60,10 +60,15 @@ class FileRemoval: too large to hold, was not utf-8, or nothing had read it this turn. That is a missing value rather than a distinction: a reader draws the deletion either way, and only the body of the removed file is lost. + + ``withheld`` is the one exception: the text was kept back on purpose (a file + the checkpoint would not store, or one no rule was read for in time), and + ``before`` is ``None`` for that. A reader must not fill it in from elsewhere. """ path: str before: str | None = None + withheld: bool = False @dataclass(frozen=True) diff --git a/tests/test_agent_loop_session_stamps.py b/tests/test_agent_loop_session_stamps.py index cae991cae..9d0d52c08 100644 --- a/tests/test_agent_loop_session_stamps.py +++ b/tests/test_agent_loop_session_stamps.py @@ -898,6 +898,27 @@ async def test_a_removal_the_command_named_is_not_reported_twice(workspace): assert removed[0]["before"] == "one\ntwo\n" +@pytest.mark.asyncio +async def test_a_file_this_turn_wrote_keeps_its_text_when_a_command_removes_it_unseen(workspace): + """The listing reports the deletion without a body when no shadow repo held + the file. The turn itself wrote it, though, so what it wrote is still the + last thing anyone knew the file to hold.""" + work = workspace / "work" + work.mkdir() + made = work / "made.txt" + script = [ + _tool_call("c1", "write_file", {"path": str(made), "content": "x\ny\n"}), + _tool_call("c2", "exec", {"command": "find . -name '*.txt' -delete"}), + LLMResponse(content="done", finish_reason="stop"), + ] + + completes = await _run_command_turn(workspace, work, script, made.unlink) + + removed = completes[1]["file_removed"] + assert len(removed) == 1, removed + assert removed[0]["before"] == "x\ny\n" + + @pytest.mark.asyncio @pytest.mark.parametrize("name", ["made.txt", "local.secret"]) async def test_a_file_this_turn_wrote_is_removed_with_the_text_the_command_reported(workspace, name): diff --git a/tests/test_contracts_two_tier_ledger.py b/tests/test_contracts_two_tier_ledger.py index 5332133dd..8692c0d2d 100644 --- a/tests/test_contracts_two_tier_ledger.py +++ b/tests/test_contracts_two_tier_ledger.py @@ -285,7 +285,7 @@ def test_import_guard_bites_machinery_and_spares_type_checking(tmp_path): # The contract tier is versioned: its shape moves only with a version bump # --------------------------------------------------------------------------- -PINNED_CONTRACT_SURFACE = ("33", "a618f2a0a7c3c26949f982bae37a0a52583caff5bcaba28def32cc97a2c8e5ba") +PINNED_CONTRACT_SURFACE = ("33", "6406b01b8614809acf9b28bab5606273c1eeabb44027927ec02bf0b80907e7bf") def _render(node) -> str: diff --git a/tests/test_removal_watch.py b/tests/test_removal_watch.py index abd97cc92..7e3b84d98 100644 --- a/tests/test_removal_watch.py +++ b/tests/test_removal_watch.py @@ -81,15 +81,28 @@ def test_rewriting_a_path_gives_its_room_back(tmp_path: Path) -> None: assert [(r.path, r.before) for r in watch.settle()] == [(str(gone), body)] -def test_a_removal_the_tool_reported_keeps_the_body_it_was_reported_with(tmp_path: Path) -> None: - """A tool that reports a removal without its body may have withheld it on - purpose -- the command tool does, for a file the checkpoint would not store. - What the watch holds for that path must not put the body back.""" +def test_a_removal_the_tool_reported_without_a_body_gets_the_one_this_run_wrote(tmp_path: Path) -> None: + """A tool that read the disk after the fact may not know what a file held; + what this run wrote there is its last known text.""" + gone = tmp_path / "made.txt" + gone.write_text("x\ny\n") + watch = RemovalWatch() + watch.note_write(FileChange(path=str(gone), after="x\ny\n")) + gone.unlink() + + assert [(r.path, r.before) for r in watch.settle((FileRemoval(path=str(gone)),))] == [(str(gone), "x\ny\n")] + assert watch.settle() == [] + + +def test_a_removal_whose_body_the_tool_withheld_stays_without_one(tmp_path: Path) -> None: + """The command tool keeps back the text of a file the checkpoint would not + store, and says so. What the watch holds for that path must not put it back.""" gone = tmp_path / "creds.env" gone.write_text("SECRET") watch = RemovalWatch() watch.note_write(FileChange(path=str(gone), after="SECRET")) gone.unlink() - assert [(r.path, r.before) for r in watch.settle((FileRemoval(path=str(gone)),))] == [(str(gone), None)] + [removal] = watch.settle((FileRemoval(path=str(gone), withheld=True),)) + assert (removal.path, removal.before, removal.withheld) == (str(gone), None, True) assert watch.settle() == [] diff --git a/tests/test_shell_command_writes.py b/tests/test_shell_command_writes.py index 2654fe3d2..7b727608f 100644 --- a/tests/test_shell_command_writes.py +++ b/tests/test_shell_command_writes.py @@ -167,7 +167,24 @@ async def test_a_file_the_command_named_keeps_its_text_only_where_the_repo_would result = await _tool(tmp_path, _Shadow(tmp_path, ignored={".env"})).execute(command="rm .env notes.md") - assert {Path(r.path).name: r.before for r in result.removed} == {".env": None, "notes.md": "one\n"} + assert {Path(r.path).name: (r.before, r.withheld) for r in result.removed} == { + ".env": (None, True), + "notes.md": ("one\n", False), + } + + +@pytest.mark.parametrize("shadowed", [True, False]) +async def test_a_listed_removal_says_whether_its_body_was_kept_back_or_is_unknown(tmp_path, shadowed): + """A bare removal is either one the rules kept back, which nothing else may + fill in, or one whose text nobody had, which the turn's own record of the + file may. Only a repo that ruled can say the first.""" + (tmp_path / "keys.secret").write_text("TOKEN=x\n") + shadow = _Shadow(tmp_path, stage=lambda: None, ignored={"keys.secret"}) if shadowed else None + + result = await _tool(tmp_path, shadow).execute(command="find . -name '*.secret' -delete") + + [removal] = result.removed + assert (removal.before, removal.withheld) == (None, shadowed) async def test_a_tool_not_asked_to_record_writes_does_not_list_or_stage(tmp_path, monkeypatch): @@ -281,7 +298,7 @@ async def test_a_shadow_repo_too_slow_to_answer_after_the_command_leaves_every_f assert "Exit code: 0" in result [write] = result.written assert (write.added, write.diff) == (None, None) - assert [(Path(r.path).name, r.before) for r in result.removed] == [("gone.txt", None)] + assert [(Path(r.path).name, r.before, r.withheld) for r in result.removed] == [("gone.txt", None, True)] async def test_measuring_that_runs_past_its_bound_still_returns_the_commands_output(tmp_path, monkeypatch): @@ -301,7 +318,10 @@ def _slow_second_walk(root: Any) -> Any: monkeypatch.setattr(snapshot, "take", _slow_second_walk) - result = await _tool(tmp_path, _Shadow(tmp_path)).execute(command="echo done && echo x > made.txt") + (tmp_path / "gone.txt").write_text("secret\n") + + result = await _tool(tmp_path, _Shadow(tmp_path)).execute(command="echo done && echo x > made.txt && rm gone.txt") assert "done" in result and result.ok is True assert result.written == () + assert [(Path(r.path).name, r.before, r.withheld) for r in result.removed] == [("gone.txt", None, True)] From 0d95b4153ade4297a7eea0b986467caddd46db03 Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Wed, 30 Sep 2026 12:55:48 +0800 Subject: [PATCH 7/9] fix(contracts): bump the contract version for FileRemoval.withheld The new field changed the contract tier's declared surface, and the version moves with every shape change, not once per pull request. Co-authored-by: Claude (claude-opus-5-5) --- raven/contracts/__init__.py | 2 +- tests/test_contracts_two_tier_ledger.py | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/raven/contracts/__init__.py b/raven/contracts/__init__.py index c95a2ff18..a10cd3b4b 100644 --- a/raven/contracts/__init__.py +++ b/raven/contracts/__init__.py @@ -17,4 +17,4 @@ makes a silent shape change a red gate. """ -CONTRACTS_VERSION = "33" +CONTRACTS_VERSION = "34" diff --git a/tests/test_contracts_two_tier_ledger.py b/tests/test_contracts_two_tier_ledger.py index 8692c0d2d..14c5f2b59 100644 --- a/tests/test_contracts_two_tier_ledger.py +++ b/tests/test_contracts_two_tier_ledger.py @@ -285,7 +285,7 @@ def test_import_guard_bites_machinery_and_spares_type_checking(tmp_path): # The contract tier is versioned: its shape moves only with a version bump # --------------------------------------------------------------------------- -PINNED_CONTRACT_SURFACE = ("33", "6406b01b8614809acf9b28bab5606273c1eeabb44027927ec02bf0b80907e7bf") +PINNED_CONTRACT_SURFACE = ("34", "6406b01b8614809acf9b28bab5606273c1eeabb44027927ec02bf0b80907e7bf") def _render(node) -> str: From 6bd97b98c2645c51b740f8639f8626f14f9c7d22 Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Wed, 30 Sep 2026 14:38:37 +0800 Subject: [PATCH 8/9] test(contracts): record the contract line count at the branch head The budget log's last entry was measured before FileRemoval gained its withheld flag and the version moved to 34; the surface now stands at 3,632 lines, inside the 3,660 ceiling. Co-authored-by: Claude (claude-opus-5-5) --- tests/test_kernel_budget.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/tests/test_kernel_budget.py b/tests/test_kernel_budget.py index eeb39942f..61ffc25a9 100644 --- a/tests/test_kernel_budget.py +++ b/tests/test_kernel_budget.py @@ -260,9 +260,11 @@ a path, whether it is new, its size, and the line counts and diff when the change could be measured -- and gives ``ToolResult`` and ``ToolOutput`` one ``written`` tuple each, empty for every other call. 34 lines, a dataclass and -its prose. +its prose. The same change gives ``FileRemoval`` a ``withheld`` flag, set when +the shell tool kept a removed file's text back on purpose, so nothing else may +fill it in: five more lines. -Measured at 3,627. +Measured at 3,632. """ From 0db7c513c9dd98ccb53f6fdcddea44cd3ae76f9e Mon Sep 17 00:00:00 2001 From: arelchan <204152633+arelchan@users.noreply.github.com> Date: Wed, 30 Sep 2026 17:15:35 +0800 Subject: [PATCH 9/9] fix(agent): raise the exec ceiling before the registry admits the tool The registry reads a tool's ceiling off the spec it admits, never off the tool afterwards. Measuring was switched on after every tool had been registered, so the 240 s it adds never reached the spec and a measured command was still cut off at 660 s. The built-in takes record_writes and the shadow resolver at construction again, and a plugin's same-name exec replacement is asked to measure before it is registered. Tests now pin the admitted spec for both. Also from the same review: pin the diff budget to the loop's file change budget it shares, warn once per directory when the shadow repo cannot stage (the failure was only logged at debug), and bring CONTEXT.md and the session.read docstring up to date (the checkpoint cache, the staging wait, the trackable rule, the file_written row). Co-authored-by: Claude (claude-opus-5-5) --- CONTEXT.md | 19 ++++++++++----- raven/agent/loop/wiring.py | 14 +++++++---- raven/agent/tools/command_writes.py | 9 +++++++ raven/agent/tools/shell.py | 7 +++--- raven/rpc/methods/session.py | 3 ++- tests/test_agent_loop_session_stamps.py | 32 +++++++++++++++++++------ tests/test_shell_command_writes.py | 26 ++++++++++++++++++++ 7 files changed, 88 insertions(+), 22 deletions(-) diff --git a/CONTEXT.md b/CONTEXT.md index ebfd58c89..c89597cff 100644 --- a/CONTEXT.md +++ b/CONTEXT.md @@ -565,16 +565,23 @@ _Avoid_: a fourth door -- a tool reaching the table any other way skips admissio **Checkpoint** (`agent/loop/checkpoint.py`): A once-per-turn commit of the session workspace into a shadow git repo (separate from the user's `.git`), so an interrupted or failed turn can be rolled back. One `CheckpointService` -per working directory, cached by `AgentLoop._turn_checkpoint()` and keyed on the directory -the running turn is bound to. The same repo also answers what a file an `exec` command -rewrote or removed held before it. `ExecTool` holds it through `command_writes.ShadowTree`, +per working directory, cached by `AgentLoop._checkpoint_for()` and keyed on the directory +it covers: the running turn's (`_turn_checkpoint()`), or for an `exec` command and the +session-open warm-up (`_command_shadow()`) the directory a turn is bound to or, with none +bound, the one the command runs in. The same repo also answers what a file an `exec` command rewrote or removed held +before it. `ExecTool` holds it through `command_writes.ShadowTree`, handed in by the loop, and does the measuring itself: `ExecTool.warm` starts staging the tree in the background when a session opens on the directory (`session.create` / `session.resume`, or the first turn where a session opens without either), and every command stages it afresh inside its own call with `stage_tree`, into a per-process index of -its own (never the index the turn commit reads), waiting up to 120s; a tree it cannot stage, -or not within that wait, leaves the command to run without a diff. `read_blobs` reads the old contents back for the -command's `file_written` diff and `file_removed` body. +its own (never the index the turn commit reads), waiting up to 120s for the staging itself +(a first use also sets the repo up, before that wait starts); a tree it cannot stage, or not +within that wait, leaves the command to run without a diff. `read_blobs` reads the old +contents back for the command's `file_written` diff and `file_removed` body. +A file's text leaves only where it is *trackable*: `CheckpointService.trackable`, the repo's +own rules (its default excludes and the user's `.gitignore`, `git check-ignore --no-index`), +judged without a tree, so a file the checkpoint would not store has no diff and a removal of +it goes out `withheld`, which nothing else may fill in. _Avoid_: "shadow git" as the term — Checkpoint is the per-turn snapshot it produces. **Empty-Response Recovery** (`agent/loop/recovery.py`): diff --git a/raven/agent/loop/wiring.py b/raven/agent/loop/wiring.py index 6e3f16499..d571195b1 100644 --- a/raven/agent/loop/wiring.py +++ b/raven/agent/loop/wiring.py @@ -934,6 +934,8 @@ def _register_default_tools(self) -> None: path_append=self.exec_config.path_append, executor=self._executor, extra_allowed_dirs=(self.workspace,), + record_writes=True, + shadow=self._command_shadow, ) ) # The registry writer beside exec's machine channel, for the products @@ -1053,12 +1055,14 @@ def picture_vendor() -> str: # ``_bind_plugin_runtime``, not here: the handles carry organs (the # playbook funnel) assembled after even this registry is populated. for tool in self.plugin_tools: + # A same-name replacement of ``exec`` reports the files its commands + # wrote and removed, as the built-in does. Asked before the door: + # measuring raises the tool's ceiling, and the registry reads the + # ceiling off the spec it admits, never off the tool afterwards. + measure_writes = getattr(tool, "measure_writes", None) + if tool.name == "exec" and callable(measure_writes): + measure_writes(self._command_shadow) self.tools.register(tool) - # Whatever answers to ``exec`` now, the built-in or a plugin's same-name - # replacement, reports the files its commands wrote and removed. - measure_writes = getattr(self.tools.get("exec"), "measure_writes", None) - if callable(measure_writes): - measure_writes(self._command_shadow) # Skill retrieval tools (body -> scripts). Both are source-agnostic and # both serve local/everos straight from the registry, so both register diff --git a/raven/agent/tools/command_writes.py b/raven/agent/tools/command_writes.py index 4ab66405c..e1d1bff53 100644 --- a/raven/agent/tools/command_writes.py +++ b/raven/agent/tools/command_writes.py @@ -54,6 +54,10 @@ MEASURE_SECONDS = 120.0 + AFTER_WAIT_SECONDS +#: Directories a staging has failed in, warned about once each. +_UNSTAGED: set[Path] = set() + + class ShadowTree(Protocol): """The part of the checkpoint's shadow repo a command is measured against. @@ -107,6 +111,11 @@ async def before(root: Path, shadow_for: ShadowFor | None) -> Before: # the next command's staging fast. logger.warning("exec measured without a diff: staging {} did not finish in time", root) tree = None + else: + if shadow is not None and tree is None and root not in _UNSTAGED: + # Once per directory: a broken repo fails every command the same way. + _UNSTAGED.add(root) + logger.warning("exec measured without a diff: the shadow repo could not stage {}", root) # The repo is kept without a tree: what a file held needs the tree, but # whether its text may be shown is the repo's rules, which need none. return Before(root, listing, shadow, tree) diff --git a/raven/agent/tools/shell.py b/raven/agent/tools/shell.py index 9ac7c4c42..1221d132f 100644 --- a/raven/agent/tools/shell.py +++ b/raven/agent/tools/shell.py @@ -126,9 +126,10 @@ def measure_writes(self, shadow: command_writes.ShadowFor | None) -> None: Read off its directory either side (``command_writes``), with ``shadow`` saying what those files held, for their diffs, and which of them may be - shown. Asked of whatever tool answers to ``exec`` once the loop's tools - are all registered, so a same-name replacement measures as the built-in - does. Left off for a lane whose runner lists every call itself. + shown. Asked of the built-in and of a plugin's same-name replacement + alike, and before either is registered: the ceiling it raises is read + off the spec the registry admits. Left off for a lane whose runner lists + every call itself. """ if not self.record_writes: self.timeout_seconds += command_writes.MEASURE_SECONDS diff --git a/raven/rpc/methods/session.py b/raven/rpc/methods/session.py index 7149491a0..9b3ae70d9 100644 --- a/raven/rpc/methods/session.py +++ b/raven/rpc/methods/session.py @@ -329,7 +329,8 @@ def _map_to_wire(messages: list[dict[str, Any]], session_key: str) -> list[dict[ Nothing else records a deletion: the arguments of the command that did it are a string, and the file it names is gone by the time anyone looks. * ``file_written`` — the files a command left behind, as - ``{path, created, size, lines}``. The other half of the same silence: a + ``{path, created, size, lines}``, with ``added`` / ``removed`` / ``diff`` + where the change could be measured. The other half of the same silence: a command reports its output, never the files it wrote. * ``reasoning_ms`` / ``duration_ms`` — how long the thought on that assistant entry took, and how long the call that ``role="tool"`` entry diff --git a/tests/test_agent_loop_session_stamps.py b/tests/test_agent_loop_session_stamps.py index 9d0d52c08..b542efae6 100644 --- a/tests/test_agent_loop_session_stamps.py +++ b/tests/test_agent_loop_session_stamps.py @@ -1042,13 +1042,17 @@ async def test_a_plugin_exec_that_replaces_the_built_in_reports_its_files_as_the work = workspace / "work" work.mkdir() (work / "gone.txt").write_text("x\n", encoding="utf-8") - replacement = CodeExecTool( - working_dir=str(workspace), - restrict_to_workspace=True, - executor=CodeExecutor(max_timeout=1200, spill_dir=workspace / "spill"), - extra_allowed_dirs=(workspace,), - max_timeout=1200, - ) + + def _replacement() -> CodeExecTool: + return CodeExecTool( + working_dir=str(workspace), + restrict_to_workspace=True, + executor=CodeExecutor(max_timeout=1200, spill_dir=workspace / "spill"), + extra_allowed_dirs=(workspace,), + max_timeout=1200, + ) + + replacement = _replacement() completes = await _run_command_turn( workspace, @@ -1062,7 +1066,21 @@ async def test_a_plugin_exec_that_replaces_the_built_in_reports_its_files_as_the [write] = completes[0]["file_written"] assert (Path(write["path"]).name, write["created"], write["added"]) == ("made.txt", True, 2) assert [(Path(r["path"]).name, r.get("before")) for r in completes[0]["file_removed"]] == [("gone.txt", "x\n")] + # The registry reads the ceiling off the spec it admitted, not the tool. assert replacement.timeout_seconds == 1200 + 60 + command_writes.MEASURE_SECONDS + spec = _command_agent(workspace, [], plugin_tools=[_replacement()]).tools.spec_of("exec") + assert spec is not None and spec.timeout_seconds == 1200 + 60 + command_writes.MEASURE_SECONDS + + +def test_the_built_in_exec_is_admitted_with_the_ceiling_its_measuring_needs(workspace): + """A measured command may wait out its staging, run to its cap and then + have its files measured; the registry kills it at the ceiling it admitted, + so the raise must be on the spec, not only on the tool.""" + from raven.agent.tools.shell import ExecTool + + spec = _command_agent(workspace, []).tools.spec_of("exec") + + assert spec is not None and spec.timeout_seconds == ExecTool.timeout_seconds + command_writes.MEASURE_SECONDS @pytest.mark.asyncio diff --git a/tests/test_shell_command_writes.py b/tests/test_shell_command_writes.py index 7b727608f..cdd3a3ec1 100644 --- a/tests/test_shell_command_writes.py +++ b/tests/test_shell_command_writes.py @@ -283,6 +283,32 @@ def test_a_measuring_tools_ceiling_covers_the_longest_command_and_the_longest_wa assert command_writes.AFTER_WAIT_SECONDS > command_writes.READ_WAIT_SECONDS +def test_a_calls_diffs_share_the_budget_its_file_changes_and_removed_bodies_do(): + """One event budget, written in two places: the tool cannot import the + loop's constant, so this holds them equal.""" + from raven.agent.loop import _shared + + assert command_writes.DIFF_BUDGET_CHARS == _shared._FILE_CHANGE_MAX_CHARS + + +async def test_a_shadow_repo_that_cannot_stage_says_so_once_per_directory(tmp_path, monkeypatch): + """A broken repo measures every command without diffs, and the reason + must reach the log above debug -- once, not on every command.""" + from loguru import logger + + monkeypatch.setattr(command_writes, "_UNSTAGED", set()) + seen: list[str] = [] + sink = logger.add(lambda message: seen.append(str(message)), level="WARNING") + try: + tool = _tool(tmp_path, _Shadow(tmp_path, stage=lambda: None)) + await tool.execute(command="echo one > a.txt") + await tool.execute(command="echo two > b.txt") + finally: + logger.remove(sink) + + assert sum("could not stage" in line for line in seen) == 1 + + async def test_a_shadow_repo_too_slow_to_answer_after_the_command_leaves_every_file_bare(tmp_path, monkeypatch): """The command has run; what the repo would have said about its files is worth less than its output. Past the wait the files go out without text --