From 4b5ac5f9d7ddc4000882e1b02dde3b4d9b78e783 Mon Sep 17 00:00:00 2001 From: Christian Meyer Date: Mon, 31 Aug 2026 17:03:40 +0200 Subject: [PATCH] feat: improve worker diagnostics --- .env.example | 1 + README.md | 4 ++++ docker-compose.yml | 1 + src/lai_automation/agent.py | 26 +++++++++++++++++++++++++- src/lai_automation/cli.py | 3 ++- src/lai_automation/git.py | 13 +++++++++++++ src/lai_automation/worker.py | 28 +++++++++++++++++++++++++++- tests/test_worker.py | 17 +++++++++++++++++ 8 files changed, 90 insertions(+), 3 deletions(-) diff --git a/.env.example b/.env.example index 996dd0b..8f657e6 100644 --- a/.env.example +++ b/.env.example @@ -11,6 +11,7 @@ GITEA_RUNNING_LABEL=ai:running GITEA_READY_LABEL=ai:ready GITEA_FAILED_LABEL=ai:failed POLL_SECONDS=60 +LOG_LEVEL=INFO AGENT_MODEL=mistral/devstral-latest MISTRAL_API_KEY= diff --git a/README.md b/README.md index 539b64f..86b9304 100644 --- a/README.md +++ b/README.md @@ -44,6 +44,10 @@ Start the worker with Docker Compose. Use `lai-agent check` inside the image for validation, `lai-agent preflight` for clean-clone setup and tests without a model call, or `lai-agent once` for a single polling cycle. +Set `LOG_LEVEL=DEBUG` to include redacted output from setup and test commands. Agent runs always +log their model, configured limits, call count, cost, exit status, and trajectory path. `INFO` is +the default for normal operation. + ## Archived implementation The previous database-polling Aider implementation is preserved unchanged in `old_2026-08-31/`. diff --git a/docker-compose.yml b/docker-compose.yml index 79dd555..091b919 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -20,6 +20,7 @@ services: AGENT_TIMEOUT_SECONDS: ${AGENT_TIMEOUT_SECONDS:-1200} AGENT_STEP_LIMIT: ${AGENT_STEP_LIMIT:-50} AGENT_COST_LIMIT: ${AGENT_COST_LIMIT:-5} + LOG_LEVEL: ${LOG_LEVEL:-INFO} AGENT_USER: coder MISTRAL_API_KEY: ${MISTRAL_API_KEY:-} POLL_SECONDS: ${POLL_SECONDS:-60} diff --git a/src/lai_automation/agent.py b/src/lai_automation/agent.py index 2ced26d..697530d 100644 --- a/src/lai_automation/agent.py +++ b/src/lai_automation/agent.py @@ -1,5 +1,6 @@ from __future__ import annotations +import logging from pathlib import Path from minisweagent.agents.default import DefaultAgent @@ -9,6 +10,8 @@ from .config import Settings from .models import AgentResult, Issue from .security import SafeLocalEnvironment +logger = logging.getLogger(__name__) + _SYSTEM_TEMPLATE = """You are a careful coding agent working in one checked-out repository. Solve only the supplied issue. Inspect existing code and tests before editing. Keep the patch minimal, add or update regression tests, and preserve public APIs @@ -80,6 +83,17 @@ class MiniSWEAgentRunner: workspace: Path, trajectory_path: Path, ) -> AgentResult: + logger.info( + "Starting agent for issue #%s: model=%s step_limit=%s cost_limit=%.2f " + "wall_time_limit=%ss command_timeout=%ss trajectory=%s", + issue.number, + self.settings.agent_model, + self.settings.agent_step_limit, + self.settings.agent_cost_limit, + self.settings.agent_wall_time_seconds, + self.settings.agent_command_timeout_seconds, + trajectory_path, + ) model_kwargs: dict[str, object] = { "timeout": min(self.settings.agent_wall_time_seconds, 600), } @@ -117,12 +131,22 @@ class MiniSWEAgentRunner: output_path=trajectory_path, ) info = agent.run(self._task(issue)) - return AgentResult( + result = AgentResult( exit_status=str(info.get("exit_status") or "unknown"), submission=str(info.get("submission") or ""), model_calls=agent.n_calls, cost=float(agent.cost), ) + logger.info( + "Agent finished for issue #%s: status=%s model_calls=%s cost=%.4f " + "trajectory=%s", + issue.number, + result.exit_status, + result.model_calls, + result.cost, + trajectory_path, + ) + return result @staticmethod def _task(issue: Issue) -> str: diff --git a/src/lai_automation/cli.py b/src/lai_automation/cli.py index 05a335e..fb15ca6 100644 --- a/src/lai_automation/cli.py +++ b/src/lai_automation/cli.py @@ -2,6 +2,7 @@ from __future__ import annotations import argparse import logging +import os from .config import Settings from .worker import Worker @@ -15,7 +16,7 @@ def main() -> None: nargs="?", default="worker", ) - parser.add_argument("--log-level", default="INFO") + parser.add_argument("--log-level", default=os.getenv("LOG_LEVEL", "INFO")) arguments = parser.parse_args() logging.basicConfig( level=getattr(logging, arguments.log_level.upper(), logging.INFO), diff --git a/src/lai_automation/git.py b/src/lai_automation/git.py index 190c042..164e827 100644 --- a/src/lai_automation/git.py +++ b/src/lai_automation/git.py @@ -1,5 +1,6 @@ from __future__ import annotations +import logging import os import pwd import re @@ -15,6 +16,8 @@ from .config import Settings from .models import ChangeSummary from .security import redact +logger = logging.getLogger(__name__) + _TRAILING_WHITESPACE = re.compile(r"^(.*):(\d+): trailing whitespace\.$") @@ -65,6 +68,8 @@ class GitWorkspace: extra_environment: Mapping[str, str] | None = None, timeout: int = 1800, ) -> subprocess.CompletedProcess[str]: + safe_command = redact(command, 1_000) + logger.info("Running trusted command: %s", safe_command) environment, identity = self._safe_process_context(extra_environment) result = subprocess.run( command, @@ -83,7 +88,15 @@ class GitWorkspace: 8_000, ) detail = f":\n{output}" if output else "" + logger.error("Trusted command failed: %s%s", safe_command, detail) raise RuntimeError(f"Command failed ({command}){detail}") + logger.info("Trusted command completed: %s", safe_command) + if result.stdout or result.stderr: + logger.debug( + "Trusted command output (%s):\n%s", + safe_command, + redact("\n".join(filter(None, (result.stdout, result.stderr))), 8_000), + ) return result def summary(self) -> ChangeSummary: diff --git a/src/lai_automation/worker.py b/src/lai_automation/worker.py index b68e020..ece5ecb 100644 --- a/src/lai_automation/worker.py +++ b/src/lai_automation/worker.py @@ -93,9 +93,14 @@ class Worker: / "trajectories" / f"issue-{issue.number}-{timestamp}.traj.json" ) + started_at = time.monotonic() result = self.agent.run(current_issue, workspace.path, trajectory) + elapsed = time.monotonic() - started_at if result.exit_status != "Submitted": - raise RuntimeError(f"Agent stopped with status {result.exit_status}") + details = self._agent_failure_details(result, elapsed, trajectory) + raise RuntimeError( + f"Agent stopped with status {result.exit_status}: {details}" + ) summary = workspace.summary() normalized = workspace.normalize_changed_whitespace(summary) @@ -177,6 +182,27 @@ class Worker: finally: workspace.cleanup() + def _agent_failure_details( + self, + result, + elapsed: float, + trajectory, + ) -> str: + limits: list[str] = [] + if result.model_calls >= self.settings.agent_step_limit: + limits.append(f"step limit reached ({self.settings.agent_step_limit})") + if self.settings.agent_cost_limit and result.cost >= self.settings.agent_cost_limit: + limits.append(f"cost limit reached ({self.settings.agent_cost_limit:.2f})") + if elapsed >= self.settings.agent_wall_time_seconds: + limits.append( + f"wall-time limit reached ({self.settings.agent_wall_time_seconds}s)" + ) + reason = ", ".join(limits) or "limit source not reported by mini-SWE-agent" + return ( + f"{reason}; model_calls={result.model_calls}; cost={result.cost:.4f}; " + f"elapsed={elapsed:.1f}s; trajectory={trajectory}" + ) + def _pull_request_body( self, issue: Issue, diff --git a/tests/test_worker.py b/tests/test_worker.py index 80d0ca2..a383624 100644 --- a/tests/test_worker.py +++ b/tests/test_worker.py @@ -1,5 +1,6 @@ from __future__ import annotations +from pathlib import Path from unittest.mock import Mock, call, patch from lai_automation.models import ( @@ -158,6 +159,22 @@ def test_run_once_returns_false_without_work(settings) -> None: assert Worker(settings, gitea, Mock()).run_once() is False +def test_agent_failure_details_identify_step_limit(settings) -> None: + worker = Worker(settings, Mock(), Mock()) + result = AgentResult("LimitsExceeded", "", settings.agent_step_limit, 0.2) + + details = worker._agent_failure_details( + result, + elapsed=180.0, + trajectory=Path("/workspaces/trajectories/issue-43.traj.json"), + ) + + assert f"step limit reached ({settings.agent_step_limit})" in details + assert "model_calls=40" in details + assert "cost=0.2000" in details + assert "issue-43.traj.json" in details + + @patch("lai_automation.worker.GitWorkspace") def test_preflight_runs_setup_and_tests_without_model( GitWorkspace,