46764b841b
Trial-4 ran the controller past ANALYZING for the first time. One
critical regression surfaced live (T4-1 — scheduler dup-attempt
enqueue), and a parallel agent-driven code review found 8 more bugs
across "races + error paths + agent quality" classes. Batch S
addresses 11 of those.
LIVE-OBSERVED REGRESSION (trial-4 2026-05-19 00:49):
T4-1 — Scheduler enqueues duplicate estimator after workflow advanced
File: tools/controller/master/scheduler.py
The "already pending" check filtered on
``status IN ('pending', 'in_progress')`` — missing the brief window
where the prior attempt is ``status='complete'`` but tick hasn't yet
processed its outcome. Result: scheduler enqueues a 2nd estimator/etc.;
when its outcome fires from a now-advanced state, IllegalTransition
→ STUCK. Hit wf=1 in trial-4. Fix: also skip when an unprocessed
``complete`` attempt exists (finished_at > w.last_transition_at).
E-5 — IllegalTransition over-aggressive STUCKing
File: tools/controller/master/tick.py
Companion fix to T4-1. Even if T4-1 escapes in some other path (or
a worker delays writing outcome past tick), a stale-outcome
(workflow already advanced via parallel path like ci_status_poll or
reconciliation) shouldn't STUCK. New ``_is_stale_role_outcome``
helper recognizes "this role's outcome arrived after the workflow
moved past its origin state" → consume the attempt, bump
last_transition_at, continue. Only genuine state corruption → STUCK.
E-3 — Corrupted output_payload silently wedges workflow
File: tools/controller/master/tick.py
Pre-fix _decode_output_payload swallowed json.JSONDecodeError →
mapper returned None → tick bumped last_transition_at but workflow
never moved. Operator had no signal. Now raises
``CorruptedOutputPayload`` → tick routes to STUCK with reason.
E-1 — Contract-violation routed to STUCK on first attempt
File: tools/controller/master/outcomes.py + tick.py
v9 spec promised retry-once-with-corrective-prompt for
contract-violation; the column ``strict_parse_retries`` existed but
nothing read/incremented it. _map_failed_outcome now takes
``prior_contract_violations`` count (queried in tick.py); STUCKs
only when count ≥ _CONTRACT_VIOLATION_RETRY_LIMIT (2). First two
violations re-enqueue.
R-1 — Reconciliation flipped workflow state mid-attempt
File: tools/controller/master/reconciliation.py
Worker holding a lock + heartbeating; reconciliation flipped current_state
to MERGED/ABANDONED based on Forgejo; tick.py then skipped the
worker's eventual write (terminal-state exclusion). Worker's output
lost. Fix: _apply_transition first checks for in_progress attempts
on the same workflow and defers if any exist.
R-2 + R-8 — _apply_transition lacks current_state guard
Files: reconciliation.py + merging.py
Same pattern as ci_status_poll's existing TOCTOU defense. UPDATE now
filters ``WHERE current_state = :from_state``; on rowcount=0, skip
the event row. Prevents racing ticks from over-writing each other.
R-4 — Reaper UPDATE didn't re-check heartbeat freshness
File: tools/controller/reaper.py
A worker's healthy heartbeat between reaper's SELECT and UPDATE
would be silently overwritten; the worker's later _write_outcome
(filtered on locked_by_instance) returned rowcount=0 → output lost.
UPDATE now includes the same freshness filter as the SELECT, so
fresh heartbeats protect the row.
E-8 — merging_retry_count not reset on STUCK/abandoned paths
File: tools/controller/master/merging.py
Pre-fix, only 200/409/422 paths reset the counter. 403 (branch
protection), 404 (externally closed → ABANDONED), retry-exhausted
(STUCK) leaked stale counts. If operator unsticks a STUCK workflow
back through MERGING, the stale count made it STUCK again sooner
than expected. All terminal-state-changing paths now reset.
A-1 — commit_shas validation accepted any ≥7-char string
File: tools/controller/mcp/implementer_builder.py
Tightened to ``re.fullmatch(r"[0-9a-f]{7,40}")``. Pre-fix an agent
could pass any 7+ char string; head_sha_advanced accepted the
hallucination; CI poll then 404'd on the fake SHA forever (until
2h ci_poll_exhaustion).
A-2 — merging-409 → IMPLEMENTING(tier=NULL) trap
File: tools/controller/master/merging.py
On 409 the handler routes to IMPLEMENTING(tier=tier_last_succeeded);
if that's NULL (e.g., metadata-only → REVIEWING → approve → 409 path
where implementer_pushed never fired), the MCP rejects tier=NULL →
contract-violation → STUCK. Fix: default to current_tier when
tier_last_succeeded is NULL.
A-9 — Reviewer cross-field check: verdict ↔ suggested_next_action
File: tools/controller/mcp/reviewer_builder.py
Agent could set verdict=approve + suggested_next_action=abandon; the
master fired reviewer_approve regardless. New _VERDICT_ACTION_COMPAT
map enforces compatible pairs at finalize.
TESTS:
- New file ``test_batch_s_fixes.py`` with 13 regression tests, one
per fix class.
- Updated test_master_outcomes.py for the new contract-violation
retry behavior.
- Updated test_master_prefetch.py fixture to bump last_transition_at
past the seeded attempts (the new T4-1 filter would otherwise
correctly identify the pre-seeded attempts as unprocessed).
Total: 819 → 832 tests, 0 regressions.
DEFERRED to a follow-up batch (per PENDING_FIXES.md):
- 8 MEDIUM items (error UX, dead fields, signal-loss in error paths)
- 5 LOW items (agent quality polish)
- 4 CONFIRMED-CLEAN (no fix needed)
Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
173 lines
6.6 KiB
Python
173 lines
6.6 KiB
Python
"""Master-side reaper: reset stale-heartbeat workflow_attempts to
|
|
pending so another worker can re-acquire.
|
|
|
|
Per plan v9 simplified: TTL-only reaper. No JOIN-with-workflows
|
|
superseded check (deferred — orphan re-attempts no-op cheaply against
|
|
terminal workflows when the next worker tries to advance them).
|
|
|
|
Runs on the master's tick loop every ``CONTROLLER_REAPER_INTERVAL_S``
|
|
(default 60s). The reaper:
|
|
- Selects ``workflow_attempts WHERE status='in_progress' AND
|
|
lock_heartbeat_at < NOW() - lock_ttl_seconds``
|
|
- For each: status → 'pending'; clear locked_by_instance / locked_at /
|
|
lock_heartbeat_at; insert a ``controller_events`` row with
|
|
reason='lock-ttl-expired'.
|
|
|
|
The reset BUMPS ``pickup_count`` (each reap = one failed-pickup).
|
|
The master's separate pickup-guard catches
|
|
``pickup_count >= MAX_PICKUPS`` and STUCKs the workflow. Bumping on
|
|
reap (rather than on dequeue) means a healthy worker that simply
|
|
acquires an attempt doesn't burn a pickup — only crashes /
|
|
stale-heartbeat resets do.
|
|
"""
|
|
from __future__ import annotations
|
|
|
|
import logging
|
|
from dataclasses import dataclass, field
|
|
from datetime import datetime, timezone
|
|
|
|
from sqlalchemy import text
|
|
from sqlalchemy.engine import Engine
|
|
|
|
from .db.session import session_scope
|
|
|
|
logger = logging.getLogger(__name__)
|
|
|
|
|
|
@dataclass
|
|
class ReaperReport:
|
|
"""Per-sweep summary; emitted to structured logs + Prometheus."""
|
|
|
|
rows_reaped: int = 0
|
|
reaped_attempts: list[tuple[int, str | None]] = field(default_factory=list)
|
|
# Each entry: (attempt_id, locked_by_instance) — useful for
|
|
# operator forensics ("which machine's worker died?")
|
|
|
|
|
|
def reap_stale_attempts(engine: Engine) -> ReaperReport:
|
|
"""Reset stale-heartbeat in_progress attempts to pending.
|
|
|
|
The TTL is per-row (``lock_ttl_seconds``) — different roles can
|
|
have different TTLs (estimator ~180s; reviewer ~720s; tier-2
|
|
implementer ~2160s). The WHERE clause uses the per-row column.
|
|
"""
|
|
report = ReaperReport()
|
|
now = datetime.now(timezone.utc)
|
|
# Two-step approach for portability:
|
|
# 1. SELECT the candidates (so we can log them).
|
|
# 2. UPDATE them.
|
|
# We could do this in one statement on Postgres (RETURNING) and
|
|
# SQLite (RETURNING is supported in 3.35+). Splitting for
|
|
# observability — the reaper isn't a hot path.
|
|
with session_scope(engine) as session:
|
|
dialect = session.bind.dialect.name if session.bind else "sqlite"
|
|
if dialect == "postgresql":
|
|
select_sql = text(
|
|
"SELECT attempt_id, locked_by_instance, lock_heartbeat_at "
|
|
"FROM workflow_attempts "
|
|
"WHERE status = 'in_progress' "
|
|
" AND lock_heartbeat_at IS NOT NULL "
|
|
" AND lock_heartbeat_at + (lock_ttl_seconds || ' seconds')::interval < :now"
|
|
)
|
|
else:
|
|
# SQLite: TIMESTAMP arithmetic via julianday().
|
|
select_sql = text(
|
|
"SELECT attempt_id, locked_by_instance, lock_heartbeat_at "
|
|
"FROM workflow_attempts "
|
|
"WHERE status = 'in_progress' "
|
|
" AND lock_heartbeat_at IS NOT NULL "
|
|
" AND (julianday(:now) - julianday(lock_heartbeat_at)) "
|
|
" * 86400 > lock_ttl_seconds"
|
|
)
|
|
rows = session.execute(select_sql, {"now": now}).all()
|
|
if not rows:
|
|
return report
|
|
|
|
# 2. UPDATE — use IN-clause with the candidate ids.
|
|
#
|
|
# R-4 fix (2026-05-19): re-check freshness in the WHERE clause
|
|
# so a worker's healthy heartbeat between SELECT and UPDATE
|
|
# protects the row. Pre-fix the UPDATE was unconditional on
|
|
# attempt_id; a heartbeat that succeeded in the gap would be
|
|
# silently overwritten, the worker's subsequent _write_outcome
|
|
# (filtered on locked_by_instance) would rowcount=0, and the
|
|
# worker's output would be lost without operator signal.
|
|
ids = [r.attempt_id for r in rows]
|
|
# SQLAlchemy's expanding bindparam handles IN over a list.
|
|
from sqlalchemy import bindparam
|
|
update_sql = text(
|
|
"UPDATE workflow_attempts SET "
|
|
" status = 'pending', "
|
|
" locked_by_instance = NULL, "
|
|
" locked_at = NULL, "
|
|
" lock_heartbeat_at = NULL, "
|
|
" pickup_count = pickup_count + 1 "
|
|
"WHERE attempt_id IN :ids "
|
|
" AND status = 'in_progress' "
|
|
" AND lock_heartbeat_at IS NOT NULL "
|
|
" AND (julianday(:now) - julianday(lock_heartbeat_at)) "
|
|
" * 86400 > lock_ttl_seconds"
|
|
).bindparams(bindparam("ids", expanding=True))
|
|
result = session.execute(update_sql, {"ids": ids, "now": now})
|
|
report.rows_reaped = result.rowcount
|
|
|
|
# 3. Log + record controller_events.
|
|
events_sql = text(
|
|
"INSERT INTO controller_events "
|
|
"(workflow_id, ts, event_type, payload, forgejo_write_pending, replay_attempts) "
|
|
"VALUES ("
|
|
" (SELECT workflow_id FROM workflow_attempts WHERE attempt_id = :attempt_id), "
|
|
" :ts, 'lock-ttl-expired', :payload, 0, 0"
|
|
")"
|
|
)
|
|
for r in rows:
|
|
report.reaped_attempts.append(
|
|
(r.attempt_id, r.locked_by_instance)
|
|
)
|
|
session.execute(events_sql, {
|
|
"attempt_id": r.attempt_id,
|
|
"ts": now,
|
|
"payload": _payload_for_event(
|
|
r.attempt_id, r.locked_by_instance,
|
|
r.lock_heartbeat_at, now,
|
|
),
|
|
})
|
|
|
|
if report.rows_reaped:
|
|
logger.warning(
|
|
"reaper reset %d stale in_progress attempt(s): %s",
|
|
report.rows_reaped,
|
|
[(aid, inst) for (aid, inst) in report.reaped_attempts],
|
|
)
|
|
return report
|
|
|
|
|
|
def _payload_for_event(
|
|
attempt_id: int,
|
|
locked_by_instance: str | None,
|
|
heartbeat_at: datetime | None,
|
|
now: datetime,
|
|
) -> str:
|
|
"""Build a JSON string payload for the controller_events row."""
|
|
import json
|
|
age_s: float | None = None
|
|
if heartbeat_at is not None:
|
|
try:
|
|
# heartbeat_at may be naive depending on the DB; normalise.
|
|
if heartbeat_at.tzinfo is None:
|
|
from datetime import timezone as _tz
|
|
hb = heartbeat_at.replace(tzinfo=_tz.utc)
|
|
else:
|
|
hb = heartbeat_at
|
|
age_s = (now - hb).total_seconds()
|
|
except Exception:
|
|
age_s = None
|
|
return json.dumps({
|
|
"reaped_attempt_id": attempt_id,
|
|
"previously_locked_by": locked_by_instance,
|
|
"heartbeat_age_s": age_s,
|
|
})
|
|
|
|
|
|
__all__ = ["ReaperReport", "reap_stale_attempts"]
|