fix(api): default event loop to asyncio + cancellation-safe commit — kills the CI segfault (#340)

* fix(api): default the event loop to asyncio + cancellation-safe commit

The recurring CI e2e segfault traced to uvloop: the harness's
uvicorn.run() auto-selected it while production's serve() path never
consulted Config.loop (stock asyncio, accidentally safe). Every launch
site now resolves ROBOCO_UVICORN_LOOP (default asyncio; uvloop opt-in),
and DbCommitMiddleware's commit-in-send can no longer be interrupted
mid-wire: on cancellation it gets a bounded grace to finish (committed
data survives the 504), else invalidate-and-reraise.

* feat(runtime): expected-stop breadcrumbs attribute container deaths

Two production exit-143s had no attributable source: every orchestrator
kill path now records a short reason breadcrumb, and the exit monitor
consumes it -- an expected stop logs its reason at info, a genuinely
unexpected one logs none_recorded plus docker-inspect diagnostics
(OOMKilled, timestamps) so the next mystery SIGTERM self-identifies.

---------

Co-authored-by: Renn F <rennf93@users.noreply.github.com>
This commit is contained in:
Renzo F
2026-07-08 16:01:01 +02:00
committed by GitHub
co-authored by Renn F
parent 312ec990dd
commit 0e9f21de69
18 changed files with 710 additions and 65 deletions
+64 -21
View File
@@ -9,6 +9,7 @@ import json
import time
import uuid
from collections.abc import Callable, Sequence
from contextlib import suppress
from typing import Any, cast
import structlog
@@ -619,22 +620,30 @@ class DbCommitMiddleware:
see ``setup_middleware`` — so a hanging commit on a flow-verb request
stays bounded by Flow's ``asyncio.timeout``. That timeout is scoped to
the WHOLE ``self.app(...)`` call including this middleware, so its
deadline can fire while ``await session.commit()`` below is itself
in flight (not just while a route handler hangs before responding) —
``started`` in the outer middleware is still ``False`` at that point
(its own wrapped ``send`` hasn't been called yet), so it sends its 504
normally once this ``await`` raises ``CancelledError``. That
``CancelledError`` is a ``BaseException`` the ``except Exception`` below
does not catch, so it propagates up through FastAPI's dependency
``AsyncExitStack`` (still open here — ``response(scope, receive, send)``
is called from inside it, see ``get_db_committed``'s docstring) straight
into ``get_db``'s own ``except asyncio.CancelledError``, which invalidates
the session rather than rolling it back: a rollback would issue another
command over a connection whose wire-protocol state this cancellation may
have already left mid-flight, corrupting it further (SQLAlchemy's own
docs prescribe ``invalidate()``, not ``rollback()``, for this exact
external-cancellation case). Skipping that step is what let a later,
unrelated request's pool checkout crash on the poisoned connection.
deadline can fire while the commit below is itself in flight (not just
while a route handler hangs before responding) — ``started`` in the
outer middleware is still ``False`` at that point (its own wrapped
``send`` hasn't been called yet), so it sends its 504 normally once the
``CancelledError`` below propagates.
The commit itself (``_commit_shielded``) runs cancellation-safe: a bare
``await session.commit()`` cancelled mid-wire abandons the asyncpg
connection in an undefined protocol state, and the pool's own recovery —
``invalidate()`` forcing the driver's ``terminate()`` — is itself
implicated in a uvloop/asyncpg segfault class observed on CI (uvloop
0.22 + asyncpg 0.31 + Python 3.13; see ``ROBOCO_UVICORN_LOOP``). So the
commit runs as its own task, shielded from this request's cancellation,
and gets a short grace (``settings.db_commit_cancel_grace_seconds``) to
finish naturally instead of being severed on the spot. Only a commit
that actually fails, or one still stuck past the grace, gets invalidated
— and re-raising the original ``CancelledError`` afterward still
propagates up through FastAPI's dependency ``AsyncExitStack`` (still
open here — ``response(scope, receive, send)`` is called from inside it,
see ``get_db_committed``'s docstring) into ``get_db``'s own
``except asyncio.CancelledError``, which invalidates the session again —
a safe no-op (SQLAlchemy's ``Session.invalidate()`` only touches the
connection once; a session with no open transaction left skips it) that
keeps the two layers independent rather than coupled.
"""
def __init__(self, app: ASGIApp) -> None:
@@ -649,11 +658,45 @@ class DbCommitMiddleware:
if message["type"] == "http.response.start":
session = scope.get("state", {}).get("db_session")
if session is not None and session.in_transaction():
try:
await session.commit()
except Exception:
await session.rollback()
raise
await _commit_shielded(session)
await send(message)
await self.app(scope, receive, send_wrapper)
async def _commit_shielded(session: Any) -> None:
"""Commit ``session`` without abandoning it mid-wire on cancellation.
Runs the commit as an independent task and shields the wait on it from
this request's own cancellation (a plain ``await session.commit()``
would otherwise hand the request task's cancel straight to the commit
task, since awaiting a Task makes it the awaiter's ``_fut_waiter``).
On cancel, the commit keeps running in the background for up to
``settings.db_commit_cancel_grace_seconds``:
- finishes successfully -> nothing to undo, just re-raise the cancel
(the client's retry is idempotent-safe; data is already durable).
- finishes with an error, or is still stuck past the grace -> the
connection is in a state worth discarding; invalidate() then re-raise.
A non-cancellation commit failure (shield propagates it unchanged)
takes the plain rollback path, unchanged from before.
"""
commit_task = asyncio.ensure_future(session.commit())
try:
await asyncio.shield(commit_task)
except asyncio.CancelledError:
done, _pending = await asyncio.wait(
{commit_task}, timeout=settings.db_commit_cancel_grace_seconds
)
if commit_task not in done:
commit_task.cancel()
with suppress(BaseException):
await commit_task
if not commit_task.cancelled() and commit_task.exception() is None:
raise # committed despite the cancel — nothing to undo
await session.invalidate()
raise
except Exception:
await session.rollback()
raise
+3 -1
View File
@@ -371,7 +371,9 @@ async def stop_agent(agent_id: str, graceful: bool = True) -> None:
"""Stop an agent."""
agent_id = _validated_agent_id(agent_id)
orchestrator = get_orchestrator()
await orchestrator.stop_agent(agent_id, graceful=graceful)
await orchestrator.stop_agent(
agent_id, graceful=graceful, stop_reason="stop_agent_api"
)
@router.post(
+6
View File
@@ -38,6 +38,12 @@ async def _run_api_server() -> None:
port=settings.port,
log_level="info",
reload=False, # Don't reload in production/container
# Cosmetic here — server.serve() (below) never reads Config.loop, it
# only matters to Server.run()/uvicorn.run(). The real switch is
# cli.py's asyncio.run(loop_factory=resolve_uvicorn_loop_factory(...)),
# which picks the loop this whole process (including this server)
# already runs on. Kept in sync so the two never silently disagree.
loop=settings.uvicorn_loop,
)
server = uvicorn.Server(config)
await server.serve()
+8 -2
View File
@@ -9,6 +9,7 @@ import argparse
import asyncio
from roboco.bootstrap import main
from roboco.config import resolve_uvicorn_loop_factory, settings
from roboco.db import bootstrap_database
@@ -41,16 +42,21 @@ def parse_args() -> argparse.Namespace:
def cli() -> None:
"""CLI entry point."""
args = parse_args()
# Sets the process-wide event loop for the whole run — including the
# API server started inside main() via Server.serve(), which never
# reads uvicorn's own Config.loop (see resolve_uvicorn_loop_factory).
loop_factory = resolve_uvicorn_loop_factory(settings.uvicorn_loop)
if args.db_only:
asyncio.run(bootstrap_database())
asyncio.run(bootstrap_database(), loop_factory=loop_factory)
else:
asyncio.run(
main(
skip_db=args.skip_db,
skip_orchestrator=args.skip_orchestrator,
spawn_agents=args.spawn,
)
),
loop_factory=loop_factory,
)
+52
View File
@@ -4,8 +4,11 @@ RoboCo Configuration
Environment-based settings using Pydantic Settings.
"""
import asyncio
import importlib
import ipaddress
import os
from collections.abc import Callable
from functools import lru_cache
from typing import Literal
from urllib.parse import urlparse
@@ -43,6 +46,20 @@ class Settings(BaseSettings):
# ==========================================================================
host: str = Field(default="127.0.0.1", description="Use 0.0.0.0 for containers")
port: int = 8000
uvicorn_loop: Literal["asyncio", "uvloop"] = Field(
default="asyncio",
description=(
"Event loop for the production orchestrator's API server and the "
"e2e smoke harness's in-thread uvicorn (env ROBOCO_UVICORN_LOOP). "
"Default 'asyncio': this API is a control plane, not a high-QPS "
"service — deterministic beats fast, and a uvloop+asyncpg "
"segfault class (uvloop 0.22 + asyncpg 0.31 + Python 3.13, GitHub "
"CI) never reproduces on stock asyncio. 'uvloop' opts back in; "
"uvloop stays an installed dependency either way. See "
"resolve_uvicorn_loop_factory() for the asyncio.run() call sites "
"(uvicorn's own Config.loop is only read by Server.run())."
),
)
api_url: str | None = Field(
default=None,
description="Override API URL for containerized agents (e.g., http://roboco-orchestrator:8000)",
@@ -1316,6 +1333,20 @@ class Settings(BaseSettings):
"request path instead of the default."
),
)
db_commit_cancel_grace_seconds: float = Field(
default=5.0,
ge=0.0,
description=(
"Grace period DbCommitMiddleware gives an in-flight "
"session.commit() that FlowVerbTimeoutMiddleware's asyncio.timeout "
"cancelled mid-wire, before giving up and invalidating the "
"session. The commit runs shielded from that cancellation so it "
"can finish naturally within the grace window instead of being "
"severed on the spot — severing an asyncpg operation mid-protocol "
"is implicated in a uvloop segfault class, so this bounds how "
"often that ever happens instead of eliminating it outright."
),
)
git_commit_timeout_seconds: int = Field(
default=180,
ge=30,
@@ -1584,6 +1615,27 @@ class Settings(BaseSettings):
)
def resolve_uvicorn_loop_factory(
loop: Literal["asyncio", "uvloop"],
) -> Callable[[], asyncio.AbstractEventLoop] | None:
"""``asyncio.run(..., loop_factory=...)`` input for ``settings.uvicorn_loop``.
uvicorn's own ``Config.loop`` only takes effect through ``Server.run()`` /
``uvicorn.run()`` (they resolve it via ``asyncio.run(loop_factory=...)``
internally); a launch site that calls ``Server.serve()`` inside an
already-running loop (the production orchestrator's bootstrap) never
consults it at all — the loop was already chosen by whatever called
``asyncio.run()`` first. This is that resolver for those call sites.
"""
if loop != "uvloop":
return None
# importlib (not a top-level `import uvloop`): uvloop rides in via
# uvicorn[standard], not a direct dependency, and this keeps PLC0415 happy.
uvloop = importlib.import_module("uvloop")
factory: Callable[[], asyncio.AbstractEventLoop] = uvloop.new_event_loop
return factory
@lru_cache
def get_settings() -> Settings:
"""Get cached settings instance."""
+6 -2
View File
@@ -80,7 +80,9 @@ class _GrokHost(Protocol):
import cycle) and is trivially mockable in tests.
"""
async def _remove_container(self, container_name: str) -> None: ...
async def _remove_container(
self, container_name: str, *, stop_reason: str | None = None
) -> None: ...
def _ensure_grok_usage_dir(self, agent_id: str) -> None: ...
@@ -120,7 +122,9 @@ class GrokCliProvider(AgentProvider):
)
container_name = _container_name(config.agent_id)
await self._host._remove_container(container_name)
await self._host._remove_container(
container_name, stop_reason="pre_spawn_stale_clear"
)
# Pre-create the per-agent data dir (world-writable) before the bind
# mount so the non-root agent can write the usage file (else EACCES).
self._host._ensure_grok_usage_dir(config.agent_id)
+191 -24
View File
@@ -121,6 +121,11 @@ _DOCKER_EXEC_TIMEOUT_SECONDS = 30.0
# legitimate slow write under load commits rather than being dropped (the
# exact data-loss tail the durable tracker exists to prevent).
_SHUTDOWN_DRAIN_TIMEOUT_SECONDS = 5.0
# Attribution breadcrumbs for orchestrator-initiated container stops (see
# _record_expected_stop). A breadcrumb older than this is treated as unrelated
# to whatever exit the monitor is now looking at, rather than mis-attributed.
_EXPECTED_STOP_FRESH_SECONDS = 120.0
_EXPECTED_STOP_MAX_ENTRIES = 200
_HTTP_TOO_MANY_REQUESTS = 429
_HTTP_OK = 200
_HTTP_MULTIPLE_CHOICES = 300 # first non-2xx status; 2xx == [_HTTP_OK, this)
@@ -811,6 +816,11 @@ class AgentOrchestrator:
# a broken-but-alive agent (see _maybe_recover_broken_gateway).
self._gateway_broken_since: dict[str, datetime] = {}
self._waiting_records: dict[str, WaitingRecord] = {}
# Diagnostics only, in-memory: agent_id -> (reason, monotonic ts) for
# the most recent orchestrator-initiated stop/kill, so the exit
# monitor can tell an attributed stop from a truly unexplained one
# (see _record_expected_stop / _consume_expected_stop).
self._expected_stops: dict[str, tuple[str, float]] = {}
# #71: a resumed agent's WaitingRecord is torn down only once liveness is
# confirmed (not on a bare launch) — a container that launches then dies
# immediately would otherwise strand its task until the reaper's TTL.
@@ -1159,7 +1169,9 @@ class AgentOrchestrator:
# the next start instead of waiting for the reaper's TTL. A
# provider-parked agent is skipped inside stop_agent so its
# claim survives for the probe-resume loop across the restart.
await self.stop_agent(agent_id, release_claim=True)
await self.stop_agent(
agent_id, release_claim=True, stop_reason="orchestrator_shutdown"
)
except Exception:
logger.exception(
"stop_agent raised during shutdown; continuing to drain",
@@ -3006,7 +3018,9 @@ class AgentOrchestrator:
# teardown_sandbox=False: this spawn's sandbox was provisioned moments
# ago in _build_agent_config — the stale-clear must not destroy it.
# Stale sandboxes from a prior crash are cleared by provision() itself.
await self._remove_container(container_name, teardown_sandbox=False)
await self._remove_container(
container_name, teardown_sandbox=False, stop_reason="pre_spawn_stale_clear"
)
if not config.mcp_config_path:
raise RuntimeError("MCP config path not set")
@@ -3033,8 +3047,85 @@ class AgentOrchestrator:
return stdout.decode().strip()
def _record_expected_stop(self, agent_id: str, reason: str) -> None:
"""Breadcrumb an orchestrator-initiated stop/kill for ``agent_id``.
Diagnostics only (in-memory, no DB): lets the exit monitor tell an
attributed stop from a genuinely unexplained one instead of logging
every death as "unexpectedly". Bounded: past a size threshold, stale
entries are dropped opportunistically rather than growing forever.
``getattr`` defaults the registry so a ``__new__``-constructed test
instance (no ``__init__``) doesn't need to know about it either.
"""
stops: dict[str, tuple[str, float]] | None = getattr(
self, "_expected_stops", None
)
if stops is None:
stops = self._expected_stops = {}
if len(stops) > _EXPECTED_STOP_MAX_ENTRIES:
cutoff = time.monotonic() - _EXPECTED_STOP_FRESH_SECONDS
stops = self._expected_stops = {
k: v for k, v in stops.items() if v[1] >= cutoff
}
stops[agent_id] = (reason, time.monotonic())
def _consume_expected_stop(self, agent_id: str) -> str:
"""Pop and return the breadcrumb reason for ``agent_id``, else "none_recorded".
A breadcrumb older than ``_EXPECTED_STOP_FRESH_SECONDS`` is treated as
stale (not fresh enough to attribute to *this* exit) and reported the
same as no breadcrumb at all. Defensive on a missing registry, like
``_record_expected_stop``.
"""
stops: dict[str, tuple[str, float]] | None = getattr(
self, "_expected_stops", None
)
entry = stops.pop(agent_id, None) if stops else None
if entry is None:
return "none_recorded"
reason, recorded_at = entry
if time.monotonic() - recorded_at > _EXPECTED_STOP_FRESH_SECONDS:
return "none_recorded"
return reason
@staticmethod
async def _inspect_exit_diagnostics(container_name: str) -> dict[str, Any]:
"""Best-effort extra `docker inspect` fields for a dead container's log line.
Cheap (one more inspect the monitor already does one of) and never
raises any failure/timeout yields {} so the caller's log line still
emits with whatever fields it already had.
"""
try:
proc = await asyncio.create_subprocess_exec(
"docker",
"inspect",
"-f",
"{{.State.OOMKilled}}|{{.State.StartedAt}}|{{.State.FinishedAt}}|"
"{{.State.Error}}",
container_name,
stdout=asyncio.subprocess.PIPE,
stderr=asyncio.subprocess.DEVNULL,
)
stdout, _ = await asyncio.wait_for(
proc.communicate(), timeout=_DOCKER_INSPECT_TIMEOUT_SECONDS
)
oom, started, finished, error = stdout.decode().strip().split("|")
except Exception:
return {}
return {
"oom_killed": oom == "true",
"started_at": started or None,
"finished_at": finished or None,
"state_error": error or None,
}
async def _remove_container(
self, container_name: str, *, teardown_sandbox: bool = True
self,
container_name: str,
*,
teardown_sandbox: bool = True,
stop_reason: str | None = None,
) -> None:
"""Remove a container if it exists, dumping its logs to disk first.
@@ -3045,7 +3136,17 @@ class AgentOrchestrator:
``teardown_sandbox=False`` is passed only by the pre-spawn stale-clear,
whose spawn has already provisioned the sandbox it is about to use.
``stop_reason``, when given, breadcrumbs this removal so the exit
monitor can attribute the death instead of flagging it unexplained.
``None`` (the default) skips it used by callers (``stop_agent``)
that already recorded their own breadcrumb earlier, before their
docker stop/kill, so this call doesn't clobber it with "unknown".
"""
if stop_reason is not None:
self._record_expected_stop(
container_name.removeprefix("roboco-agent-"), stop_reason
)
# Check the container actually exists before trying to dump logs;
# _remove_container is routinely called pre-spawn to clear stale
# containers, and on first spawn there's nothing to dump.
@@ -4217,7 +4318,11 @@ class AgentOrchestrator:
async with self._intake_spawn_lock:
# Single live session: reap any prior intake container before spawning.
if INTAKE_AGENT_ID in self._instances:
await self.stop_agent(INTAKE_AGENT_ID, graceful=False)
await self.stop_agent(
INTAKE_AGENT_ID,
graceful=False,
stop_reason="intake_respawn_guard",
)
from roboco.models.base import ModelProvider
@@ -4251,7 +4356,9 @@ class AgentOrchestrator:
else:
await self._ensure_agent_image(INTAKE_AGENT_ID)
container_name = f"roboco-agent-{INTAKE_AGENT_ID}"
await self._remove_container(container_name)
await self._remove_container(
container_name, stop_reason="pre_spawn_stale_clear"
)
cmd = self._build_intake_run_cmd(
_IntakeRunSpec(
@@ -4277,7 +4384,9 @@ class AgentOrchestrator:
# now would land a live container nothing tears down (the orphan). The
# stop() drain awaits this coroutine, so the abort surfaces cleanly.
if not self._running:
await self._remove_container(container_name)
await self._remove_container(
container_name, stop_reason="spawn_aborted_shutdown"
)
raise _SpawnAbortedDuringShutdown(INTAKE_AGENT_ID)
config = AgentConfig(
@@ -4336,7 +4445,9 @@ class AgentOrchestrator:
from roboco.services.prompter_live import get_live_registry
get_live_registry().close(session_id)
await self.stop_agent(INTAKE_AGENT_ID, graceful=True)
await self.stop_agent(
INTAKE_AGENT_ID, graceful=True, stop_reason="intake_session_reaped"
)
logger.info("Intake session reaped", session_id=session_id)
# ------------------------------------------------------------------ #
@@ -4417,7 +4528,11 @@ class AgentOrchestrator:
from roboco.models.base import ModelProvider
if SECRETARY_AGENT_ID in self._instances:
await self.stop_agent(SECRETARY_AGENT_ID, graceful=False)
await self.stop_agent(
SECRETARY_AGENT_ID,
graceful=False,
stop_reason="secretary_respawn_guard",
)
prompt_path = self._generate_composed_prompt(SECRETARY_AGENT_ID)
route = await self._resolve_agent_route(SECRETARY_AGENT_ID)
@@ -4440,7 +4555,9 @@ class AgentOrchestrator:
else:
await self._ensure_agent_image(SECRETARY_AGENT_ID)
container_name = f"roboco-agent-{SECRETARY_AGENT_ID}"
await self._remove_container(container_name)
await self._remove_container(
container_name, stop_reason="pre_spawn_stale_clear"
)
agent_uuid = str(AGENTS[SECRETARY_AGENT_ID].uuid)
cmd = self._build_secretary_run_cmd(
@@ -4471,7 +4588,9 @@ class AgentOrchestrator:
# just-started container and abort WITHOUT registering, so it isn't
# orphaned by a stop() that has already iterated _instances.
if not self._running:
await self._remove_container(container_name)
await self._remove_container(
container_name, stop_reason="spawn_aborted_shutdown"
)
raise _SpawnAbortedDuringShutdown(SECRETARY_AGENT_ID)
config = AgentConfig(
@@ -4517,7 +4636,9 @@ class AgentOrchestrator:
from roboco.services.prompter_live import get_live_registry
get_live_registry().close(session_id)
await self.stop_agent(SECRETARY_AGENT_ID, graceful=True)
await self.stop_agent(
SECRETARY_AGENT_ID, graceful=True, stop_reason="secretary_session_reaped"
)
logger.info("Secretary session reaped", session_id=session_id)
async def _reap_idle_interactive_sessions(self) -> None:
@@ -4900,6 +5021,7 @@ class AgentOrchestrator:
graceful: bool = True,
exit_reason: str = "stopped",
release_claim: bool = False,
stop_reason: str = "stop_agent",
) -> None:
"""Stop an agent container.
@@ -4919,6 +5041,12 @@ class AgentOrchestrator:
loop. A provider-parked agent (``rate_limit_lifted`` WaitingRecord) is
always skipped even when a caller opts in its claim must survive so
probe-success revives the same agent on the same task.
``stop_reason`` breadcrumbs the container as an expected stop (see
``_record_expected_stop``) BEFORE the docker stop/kill is issued
``_check_health`` polls without holding ``self._lock``, so it can
observe the container already gone while this call is still mid-flight;
recording early (not just at ``_remove_container``) closes that race.
"""
# Finalize the spawn-session row before the container is removed so we
# can still query the SDK's /usage/status endpoint. This must happen
@@ -4942,6 +5070,7 @@ class AgentOrchestrator:
instance = self._instances[agent_id]
if instance.container_id:
self._record_expected_stop(agent_id, stop_reason)
instance.state = AgentState.STOPPING
container_name = f"roboco-agent-{agent_id}"
@@ -5077,7 +5206,7 @@ class AgentOrchestrator:
await self._persist_waiting_record(record)
# Stop the agent
await self.stop_agent(agent_id)
await self.stop_agent(agent_id, stop_reason=f"waiting_long_{waiting_for}")
# Update state
if agent_id in self._instances:
@@ -5486,7 +5615,9 @@ class AgentOrchestrator:
if cost <= cap:
continue
try:
await self._remove_container(f"roboco-agent-{agent_id}")
await self._remove_container(
f"roboco-agent-{agent_id}", stop_reason="grok_cost_cap"
)
except Exception as exc:
logger.error(
"grok cost-cap kill failed; will retry next tick",
@@ -6986,7 +7117,12 @@ Start by:
# for cost overruns and will not continue its task, so hand
# the claim back to the pool now instead of waiting for the
# reaper's TTL.
await self.stop_agent(agent_id, graceful=True, release_claim=True)
await self.stop_agent(
agent_id,
graceful=True,
release_claim=True,
stop_reason="budget_sweep",
)
except Exception as e:
logger.warning(
"Failed to stop budget-exceeded agent",
@@ -7186,12 +7322,7 @@ Start by:
exit_code=exit_code,
)
else:
logger.warning(
"Agent container stopped unexpectedly",
agent_id=agent_id,
container_id=cid,
exit_code=exit_code,
)
await self._log_stopped_container(agent_id, cid, exit_code)
# The agent self-exited (a graceful i_am_idle shutdown, or a crash), so
# stop_agent() — which normally finalizes — was never called. Finalize
# here to capture token usage from the transcript; otherwise the
@@ -7206,6 +7337,32 @@ Start by:
return
await self._crash_retry_or_escalate(agent_id, instance)
async def _log_stopped_container(
self, agent_id: str, container_id: str | None, exit_code: int | None
) -> None:
"""Log a non-graceful exit, attributed via the expected-stop breadcrumb.
A fresh breadcrumb (recorded by an orchestrator-initiated stop/kill
path see ``_record_expected_stop``) means this death is explained:
log it at info as "(expected)" so the warning line stays meaningful
for genuinely unattributed SIGTERMs/crashes. Inspect diagnostics are
best-effort and never block the log line.
"""
reason = self._consume_expected_stop(agent_id)
diagnostics = await self._inspect_exit_diagnostics(f"roboco-agent-{agent_id}")
expected = reason != "none_recorded"
log = logger.info if expected else logger.warning
log(
"Agent container stopped (expected)"
if expected
else "Agent container stopped unexpectedly",
agent_id=agent_id,
container_id=container_id,
exit_code=exit_code,
expected_stop_reason=reason,
**diagnostics,
)
async def _crash_retry_or_escalate(self, agent_id: str, instance: Any) -> None:
"""A crashed (non-graceful) agent: auto-restart up to a cap, then escalate.
@@ -10060,7 +10217,11 @@ Start now: evidence(task_id="{task_id}")
"will re-spawn it with a freshly signed token",
slug=slug,
)
await self._remove_container(f"roboco-agent-{slug}", teardown_sandbox=False)
await self._remove_container(
f"roboco-agent-{slug}",
teardown_sandbox=False,
stop_reason="stale_token_heal",
)
killed += 1
if killed:
logger.info("Healed stale agent tokens at startup", count=killed)
@@ -10207,7 +10368,9 @@ Start now: evidence(task_id="{task_id}")
if slug is None:
return False
try:
await self._remove_container(f"roboco-agent-{slug}")
await self._remove_container(
f"roboco-agent-{slug}", stop_reason="reaper_wedged_grok"
)
except Exception as exc:
logger.error(
"wedged-grok kill failed; will retry next tick",
@@ -10271,7 +10434,9 @@ Start now: evidence(task_id="{task_id}")
if slug is None:
return False
try:
await self._remove_container(f"roboco-agent-{slug}")
await self._remove_container(
f"roboco-agent-{slug}", stop_reason="reaper_stuck_claude"
)
except Exception as exc:
logger.error(
"stuck-claude kill failed; will retry next tick",
@@ -10309,7 +10474,9 @@ Start now: evidence(task_id="{task_id}")
if not await self._gateway_broken_past_grace(slug):
return False
try:
await self._remove_container(f"roboco-agent-{slug}")
await self._remove_container(
f"roboco-agent-{slug}", stop_reason="gateway_health_recovery"
)
except Exception as exc:
logger.error(
"broken-gateway kill failed; will retry next tick",
+11 -1
View File
@@ -369,8 +369,18 @@ def build_e2e_stack(
mp.setattr(settings, "github_api_base_url", f"{base_url}/_github")
app = _build_app(gh)
# loop=settings.uvicorn_loop ("asyncio" by default): uvicorn auto-selects
# uvloop when installed, and this in-thread server has crashed CI with a
# uvloop/asyncpg segfault (uvloop 0.22 + asyncpg 0.31 + Python 3.13) —
# mirror the production default instead of picking up uvloop implicitly.
server = uvicorn.Server(
uvicorn.Config(app, host="127.0.0.1", port=port, log_level="warning")
uvicorn.Config(
app,
host="127.0.0.1",
port=port,
log_level="warning",
loop=settings.uvicorn_loop,
)
)
thread = threading.Thread(target=server.run, daemon=True)
thread.start()
+99 -3
View File
@@ -662,7 +662,46 @@ class _CancelableCommitSession:
self._txn = False
async def invalidate(self) -> None:
self._order.append("invalidate")
# Mirrors real SQLAlchemy Session.invalidate(): a no-op past the
# first call (no open transaction left to touch) — both
# _commit_shielded and get_db's own cancel handler call this for the
# same cancelled request, and only the first should count.
if self._txn:
self._order.append("invalidate")
self._txn = False
class _SlowButFinishingCommitSession:
"""get_db-style fake session whose ``commit()`` outlives the server-side
timeout but finishes well within the shield's grace period — proving a
cancelled-mid-commit request still lets the commit land instead of
severing it on the spot."""
def __init__(self, order: list[str], delay: float) -> None:
self._order = order
self._delay = delay
self._txn = True
def in_transaction(self) -> bool:
return self._txn
async def commit(self) -> None:
self._order.append("commit_start")
await asyncio.sleep(self._delay)
self._order.append("commit_end")
self._txn = False
async def rollback(self) -> None:
self._order.append("rollback")
self._txn = False
async def invalidate(self) -> None:
# Mirrors real SQLAlchemy Session.invalidate(): a no-op once the
# transaction is already gone (a successful commit clears it) — the
# cancel-completes-successfully test relies on this, exactly like the
# double-invalidate case above.
if self._txn:
self._order.append("invalidate")
self._txn = False
@@ -701,8 +740,9 @@ def _make_cancel_during_commit_app(order: list[str]) -> FastAPI:
def test_cancellation_mid_commit_invalidates_not_rollback(monkeypatch: Any) -> None:
"""A flow-verb request that blows its server-side timeout WHILE
DbCommitMiddleware's commit is in flight must: propagate CancelledError
cleanly to a 504 (not hang, not a raw 500), discard the session via
DbCommitMiddleware's commit is in flight, and the commit is STILL stuck
past the shield's grace period, must: propagate CancelledError cleanly
to a 504 (not hang, not a raw 500), discard the session via
``invalidate()`` — NOT ``rollback()`` (SQLAlchemy's own docs: rolling
back a cancelled/timed-out operation risks issuing another command over
a connection whose wire-protocol state is now undefined, which is what
@@ -710,6 +750,7 @@ def test_cancellation_mid_commit_invalidates_not_rollback(monkeypatch: Any) -> N
and never resume/complete the cancelled commit.
"""
monkeypatch.setattr(settings, "flow_verb_timeout_seconds", 0.05)
monkeypatch.setattr(settings, "db_commit_cancel_grace_seconds", 0.05)
order: list[str] = []
app = _make_cancel_during_commit_app(order)
@@ -719,3 +760,58 @@ def test_cancellation_mid_commit_invalidates_not_rollback(monkeypatch: Any) -> N
assert response.status_code == HTTPStatus.GATEWAY_TIMEOUT
assert response.json()["error"] == "gateway_timeout"
assert order == ["route_body", "commit_start", "invalidate"], order
async def _fake_get_db_slow_commit(request: Request) -> Any:
"""Module-level for the same reason as ``_fake_get_db_cancel_safe`` above —
a local closure isn't resolvable as a FastAPI dependency under this file's
``from __future__ import annotations``."""
order: list[str] = request.app.state.db_commit_order
delay: float = request.app.state.db_commit_delay
session = _SlowButFinishingCommitSession(order, delay)
request.state.db_session = session
try:
yield session
await session.commit()
except asyncio.CancelledError:
await _discard_on_cancel(cast("AsyncSession", session))
raise
except Exception:
await session.rollback()
raise
def _make_slow_commit_app(order: list[str], delay: float) -> FastAPI:
app = FastAPI()
app.state.db_commit_order = order
app.state.db_commit_delay = delay
@app.post("/api/v1/flow/developer/give_me_work")
async def _write(_db: Annotated[Any, Depends(_fake_get_db_slow_commit)]) -> Any:
order.append("route_body")
return {"status": "ok"}
setup_middleware(app)
return app
def test_cancellation_mid_commit_lets_commit_finish_within_grace(
monkeypatch: Any,
) -> None:
"""A commit already in flight when the server-side timeout fires, but
that finishes on its own well within the shield's grace period, must be
allowed to land — never severed on the spot. No rollback, no invalidate
(nothing to undo — the data is durably committed), and the timeout's own
CancelledError still propagates to the client as a clean 504 (the
client's retry is idempotent-safe regardless)."""
monkeypatch.setattr(settings, "flow_verb_timeout_seconds", 0.05)
monkeypatch.setattr(settings, "db_commit_cancel_grace_seconds", 2.0)
order: list[str] = []
app = _make_slow_commit_app(order, delay=0.15)
client = TestClient(app)
response = client.post("/api/v1/flow/developer/give_me_work")
assert response.status_code == HTTPStatus.GATEWAY_TIMEOUT
assert response.json()["error"] == "gateway_timeout"
assert order == ["route_body", "commit_start", "commit_end"], order
+6 -1
View File
@@ -62,6 +62,7 @@ class _FakeHost:
def __init__(self) -> None:
self.removed: list[str] = []
self.remove_stop_reasons: list[str | None] = []
self.spawn_args: tuple[object, ...] | None = None
self.mount_config: OrchestratorAgentConfig | None = None
self.data_dirs_ensured: list[str] = []
@@ -75,8 +76,11 @@ class _FakeHost:
self.spawn_args = (config, initial_prompt, agent_settings_path)
return "container-id-abc123"
async def _remove_container(self, container_name: str) -> None:
async def _remove_container(
self, container_name: str, *, stop_reason: str | None = None
) -> None:
self.removed.append(container_name)
self.remove_stop_reasons.append(stop_reason)
def _ensure_grok_usage_dir(self, agent_id: str) -> None:
self.data_dirs_ensured.append(agent_id)
@@ -227,6 +231,7 @@ async def test_grok_spawn_wires_gateway_env_and_image_last() -> None:
# The image is the final docker-run argument.
assert cmd[-1] == "roboco-agent-grok:test"
assert host.removed == ["roboco-agent-be-dev-1"]
assert host.remove_stop_reasons == ["pre_spawn_stale_clear"]
assert result == SpawnResult(
instance_id="roboco-agent-be-dev-1",
extra={"container_id": "cid", "model": "grok-build"},
@@ -0,0 +1,199 @@
"""Expected-stop breadcrumb registry.
Production containers can exit 143 (SIGTERM) with the orchestrator's exit
monitor logging only "Agent container stopped unexpectedly" — no line
identifies who stopped it, and containers are gone by the time anyone looks
(docker events empty). Every orchestrator-initiated stop/kill path now
breadcrumbs the agent_id (_record_expected_stop) before it acts; the monitor
consumes it (_consume_expected_stop) when the container turns up dead and
downgrades an attributed death to an info "(expected)" line, keeping the
warning meaningful for genuinely unexplained SIGTERMs/crashes.
"""
from __future__ import annotations
import time
from unittest.mock import AsyncMock, MagicMock, patch
import pytest
from roboco.runtime.orchestrator import AgentOrchestrator, AgentState
from structlog.testing import capture_logs
def _make_orchestrator() -> AgentOrchestrator:
with patch.object(AgentOrchestrator, "__init__", return_value=None):
orch = AgentOrchestrator.__new__(AgentOrchestrator)
orch._instances = {}
orch._lock = MagicMock()
return orch
def _instance() -> MagicMock:
inst = MagicMock()
inst.state = AgentState.ACTIVE
inst.container_id = "deadbeef1234"
inst.current_task_id = None
inst.error_count = 0
inst.config = MagicMock(git_context=None)
return inst
# ---------------------------------------------------------------------------
# _record_expected_stop / _consume_expected_stop
# ---------------------------------------------------------------------------
def test_record_then_consume_returns_the_reason() -> None:
orch = _make_orchestrator()
orch._record_expected_stop("be-dev-1", "budget_sweep")
assert orch._consume_expected_stop("be-dev-1") == "budget_sweep"
def test_consume_pops_the_entry() -> None:
"""A second consume for the same agent finds nothing — one-shot breadcrumb."""
orch = _make_orchestrator()
orch._record_expected_stop("be-dev-1", "budget_sweep")
orch._consume_expected_stop("be-dev-1")
assert orch._consume_expected_stop("be-dev-1") == "none_recorded"
def test_no_breadcrumb_is_none_recorded() -> None:
orch = _make_orchestrator()
assert orch._consume_expected_stop("be-dev-1") == "none_recorded"
def test_stale_breadcrumb_is_ignored() -> None:
"""A breadcrumb older than the freshness window can't attribute a later,
unrelated exit — treated the same as never having been recorded."""
orch = _make_orchestrator()
orch._record_expected_stop("be-dev-1", "budget_sweep")
reason, _ts = orch._expected_stops["be-dev-1"]
orch._expected_stops["be-dev-1"] = (reason, time.monotonic() - 121.0)
assert orch._consume_expected_stop("be-dev-1") == "none_recorded"
def test_registry_defensive_on_bare_new_instance() -> None:
"""A __new__-constructed instance (many existing test fixtures across the
suite bypass __init__ this way) has no _expected_stops attribute until
first use — both helpers must self-heal it rather than raise
AttributeError."""
orch = AgentOrchestrator.__new__(AgentOrchestrator)
assert orch._consume_expected_stop("be-dev-1") == "none_recorded"
orch._record_expected_stop("be-dev-1", "stop_agent_api")
assert orch._consume_expected_stop("be-dev-1") == "stop_agent_api"
# ---------------------------------------------------------------------------
# _check_health / _handle_stopped_container attribution
# ---------------------------------------------------------------------------
@pytest.mark.asyncio
async def test_kill_path_breadcrumb_downgrades_the_monitor_log() -> None:
"""A kill path (e.g. the budget sweep) records a breadcrumb; when the
monitor later observes the same container gone, it logs "(expected)" at
info with the recorded reason instead of "unexpectedly" at warning."""
orch = _make_orchestrator()
orch._instances["be-dev-1"] = _instance()
# The exact call a kill path makes (_sweep_budget_exceeded -> stop_agent)
# before it issues its own docker stop/kill.
orch._record_expected_stop("be-dev-1", "budget_sweep")
proc = MagicMock()
proc.communicate = AsyncMock(return_value=(b"false 137\n", b""))
with (
patch.object(orch, "spawn_agent", new=AsyncMock()),
patch("asyncio.create_subprocess_exec", AsyncMock(return_value=proc)),
capture_logs() as logs,
):
await orch._check_health()
expected = [e for e in logs if e["event"] == "Agent container stopped (expected)"]
assert expected, logs
assert expected[0]["log_level"] == "info"
assert expected[0]["expected_stop_reason"] == "budget_sweep"
assert not [e for e in logs if e["event"] == "Agent container stopped unexpectedly"]
@pytest.mark.asyncio
async def test_no_breadcrumb_stays_a_warning() -> None:
"""No breadcrumb recorded: the death is genuinely unattributed, so the
line stays a warning carrying expected_stop_reason="none_recorded"."""
orch = _make_orchestrator()
orch._instances["be-dev-1"] = _instance()
proc = MagicMock()
proc.communicate = AsyncMock(return_value=(b"false 137\n", b""))
with (
patch.object(orch, "spawn_agent", new=AsyncMock()),
patch("asyncio.create_subprocess_exec", AsyncMock(return_value=proc)),
capture_logs() as logs,
):
await orch._check_health()
unexpected = [
e for e in logs if e["event"] == "Agent container stopped unexpectedly"
]
assert unexpected, logs
assert unexpected[0]["log_level"] == "warning"
assert unexpected[0]["expected_stop_reason"] == "none_recorded"
@pytest.mark.asyncio
async def test_stale_breadcrumb_does_not_suppress_the_warning() -> None:
"""A breadcrumb from a much older stop must not attribute an unrelated,
later exit — the warning line still fires with none_recorded."""
orch = _make_orchestrator()
orch._instances["be-dev-1"] = _instance()
orch._record_expected_stop("be-dev-1", "budget_sweep")
orch._expected_stops["be-dev-1"] = ("budget_sweep", time.monotonic() - 121.0)
proc = MagicMock()
proc.communicate = AsyncMock(return_value=(b"false 137\n", b""))
with (
patch.object(orch, "spawn_agent", new=AsyncMock()),
patch("asyncio.create_subprocess_exec", AsyncMock(return_value=proc)),
capture_logs() as logs,
):
await orch._check_health()
unexpected = [
e for e in logs if e["event"] == "Agent container stopped unexpectedly"
]
assert unexpected, logs
assert unexpected[0]["expected_stop_reason"] == "none_recorded"
@pytest.mark.asyncio
async def test_inspect_diagnostics_failure_is_tolerated() -> None:
"""A failed/timed-out extra `docker inspect` for OOMKilled/StartedAt/etc
must not break the monitor — the log line still emits, just without
those fields (best-effort, never blocks the log)."""
orch = _make_orchestrator()
orch._instances["be-dev-1"] = _instance()
async def _create_subprocess_exec(*args: object, **_kw: object) -> MagicMock:
if any(isinstance(a, str) and "OOMKilled" in a for a in args):
raise RuntimeError("docker daemon unreachable")
proc = MagicMock()
proc.communicate = AsyncMock(return_value=(b"false 137\n", b""))
return proc
with (
patch.object(orch, "spawn_agent", new=AsyncMock()),
patch(
"asyncio.create_subprocess_exec",
AsyncMock(side_effect=_create_subprocess_exec),
),
capture_logs() as logs,
):
await orch._check_health()
unexpected = [
e for e in logs if e["event"] == "Agent container stopped unexpectedly"
]
assert unexpected, logs
assert "oom_killed" not in unexpected[0]
+3 -1
View File
@@ -121,7 +121,9 @@ async def test_broken_past_grace_is_killed(monkeypatch: pytest.MonkeyPatch) -> N
monkeypatch.setattr(orch, "_remove_container", remove)
monkeypatch.setattr(orch, "_probe_gateway_health", AsyncMock(return_value=False))
assert await orch._maybe_recover_broken_gateway(_task()) is True
remove.assert_awaited_once_with("roboco-agent-be-dev-1")
remove.assert_awaited_once_with(
"roboco-agent-be-dev-1", stop_reason="gateway_health_recovery"
)
assert "be-dev-1" not in orch._instances # evicted
+6 -2
View File
@@ -52,7 +52,9 @@ async def test_cost_over_cap_kills_and_evicts(monkeypatch: pytest.MonkeyPatch) -
await orch._enforce_grok_cost_budget()
remove_mock.assert_awaited_once_with("roboco-agent-be-dev-1")
remove_mock.assert_awaited_once_with(
"roboco-agent-be-dev-1", stop_reason="grok_cost_cap"
)
assert "be-dev-1" not in orch._instances
@@ -140,7 +142,9 @@ async def test_interactive_kill_closes_the_relay(
await orch._enforce_grok_cost_budget()
remove_mock.assert_awaited_once_with(f"roboco-agent-{INTAKE_AGENT_ID}")
remove_mock.assert_awaited_once_with(
f"roboco-agent-{INTAKE_AGENT_ID}", stop_reason="grok_cost_cap"
)
assert INTAKE_AGENT_ID not in orch._instances
assert len(registry.calls) == 1
assert registry.calls[0][0] == INTAKE_AGENT_ID
+2 -2
View File
@@ -1040,7 +1040,7 @@ class TestSpawnIntakeShutdownNoOrphan:
_wire_spawn_mocks(monkeypatch, orch, run_calls)
removed: list[str] = []
async def _remove(name: str) -> None:
async def _remove(name: str, **_kw: Any) -> None:
removed.append(name)
async def _run(cmd: list[str]) -> str:
@@ -1097,7 +1097,7 @@ class TestSpawnIntakeShutdownNoOrphan:
# _wire_spawn_mocks' _remove_container is a no-op; override to record.
removed: list[str] = []
async def _remove(name: str) -> None:
async def _remove(name: str, **_kw: Any) -> None:
removed.append(name)
monkeypatch.setattr(orch, "_remove_container", _remove)
+5 -1
View File
@@ -188,4 +188,8 @@ async def test_spawn_container_stale_clear_spares_fresh_sandbox(
)
await orch._spawn_container(_config(info))
remove.assert_awaited_once_with("roboco-agent-dev-1", teardown_sandbox=False)
remove.assert_awaited_once_with(
"roboco-agent-dev-1",
teardown_sandbox=False,
stop_reason="pre_spawn_stale_clear",
)
@@ -64,7 +64,7 @@ def _wire_secretary_spawn_mocks(
orch._running = False
return "containerid0123456789"
async def _remove(name: str) -> None:
async def _remove(name: str, **_kw: Any) -> None:
removed.append(name)
monkeypatch.setattr(
@@ -206,7 +206,9 @@ async def test_reaper_kills_and_releases_wedged_grok_container(
await orch._reap_with_service(svc)
remove_mock.assert_awaited_once_with("roboco-agent-be-dev-1")
remove_mock.assert_awaited_once_with(
"roboco-agent-be-dev-1", stop_reason="reaper_wedged_grok"
)
assert "be-dev-1" not in orch._instances # evicted
svc.unclaim_for_reaper.assert_awaited_once_with(task_id) # released
@@ -338,7 +340,9 @@ async def test_reaper_kills_stuck_claude_past_stuck_ttl(
await orch._reap_with_service(svc)
remove_mock.assert_awaited_once_with("roboco-agent-be-dev-1")
remove_mock.assert_awaited_once_with(
"roboco-agent-be-dev-1", stop_reason="reaper_stuck_claude"
)
assert "be-dev-1" not in orch._instances # evicted
svc.unclaim_for_reaper.assert_awaited_once_with(stuck.id) # released
+42 -1
View File
@@ -2,9 +2,11 @@
from __future__ import annotations
import importlib
import pytest
from pydantic import ValidationError
from roboco.config import Settings
from roboco.config import Settings, resolve_uvicorn_loop_factory
def test_internal_api_url_uses_api_url_when_set() -> None:
@@ -126,3 +128,42 @@ def test_local_llm_base_url_public_rejected() -> None:
def test_local_llm_base_url_missing_host_rejected() -> None:
with pytest.raises(ValidationError):
Settings(local_llm_base_url="http://")
# ---------------------------------------------------------------------------
# uvicorn_loop — default asyncio, uvloop opt-in (CI segfault fix)
# ---------------------------------------------------------------------------
def test_uvicorn_loop_defaults_to_asyncio() -> None:
assert Settings().uvicorn_loop == "asyncio"
def test_uvicorn_loop_honors_constructor_override() -> None:
assert Settings(uvicorn_loop="uvloop").uvicorn_loop == "uvloop"
def test_uvicorn_loop_honors_env_override(monkeypatch: pytest.MonkeyPatch) -> None:
monkeypatch.setenv("ROBOCO_UVICORN_LOOP", "uvloop")
assert Settings().uvicorn_loop == "uvloop"
def test_uvicorn_loop_rejects_unknown_value() -> None:
with pytest.raises(ValidationError):
Settings(uvicorn_loop="unknown") # type: ignore[arg-type]
def test_resolve_uvicorn_loop_factory_asyncio_is_none() -> None:
"""The default: no override, so asyncio.run() picks its own stock loop."""
assert resolve_uvicorn_loop_factory("asyncio") is None
def test_resolve_uvicorn_loop_factory_uvloop_returns_new_event_loop() -> None:
factory = resolve_uvicorn_loop_factory("uvloop")
assert factory is not None
loop = factory()
try:
uvloop = importlib.import_module("uvloop")
assert isinstance(loop, uvloop.Loop)
finally:
loop.close()