Skip to content

bug: startup execution recovery races with concurrent in-flight /internal/execute_task calls #748

Closed

Description

@obasilakis

Summary

recover_orphaned_executions (run on backend startup, main.py:462) marks SQL execution rows as failed when their agent:slots:{name} ZSET membership is missing, with no coordination against /internal/execute_task requests still in-flight from the scheduler. The result is a leaked Redis slot — a slot ZADDed for an execution that was already marked failed ms earlier.

Context

Caught locally on 2026-05-09 when the canary harness (Issue #411) S-01 invariant fired three consecutive cycles on canary-fleet-burst. Reconstructed timeline for execution RxbyJHq9Kx9QLfwwr7fcsQ:

20:38:59.x   Backend Python process shutting down (uvicorn auto-reload, dev mode)
20:39:00.007 Scheduler INSERTs execution row (status=running)
             Scheduler HTTP POST → backend /internal/execute_task (queued, backend down)
20:39:00.405 Backend startup begins (event_bus, OTel, services)
20:39:00.509 startup recovery flips row to FAILED
             error="Execution orphaned — recovered on backend restart"
             capacity.release() ZREM is no-op (slot didn't exist yet)
20:39:00.534 Now-late /internal/execute_task handler runs
             capacity.acquire() ZADDs slot for the execution that
             was failed 25ms ago  ← LEAK BORN HERE
20:39:00.542 task_execution_service starts agent /api/task call
20:39:04.88  Backend restarts AGAIN (second uvicorn reload)
             In-flight handler dies, finally-block ZREM never runs
20:39:06.17  Backend restarts third time. Recovery scan sees no running rows
             (already terminal) → does nothing. Slot still in Redis.

The slot persists until 1200s TTL or until the next acquire on this agent triggers _cleanup_stale_slots_for_agent (which only runs at acquire time).

Acceptance Criteria

  • No leaked Redis slot is left behind when a /internal/execute_task request is delivered while startup recovery is running for the same execution_id.
  • Reproduction: hold /internal/execute_task mid-flight (e.g. via fault-injection), trigger startup recovery on the same row, complete the in-flight call. Final Redis state has zero slots for that execution_id and SQL row is failed with the orphan error.
  • No regression in startup recovery for genuinely orphaned rows (slots present in Redis but no in-flight handler).
  • Canary S-01 stays clean for ≥1 cycle after a backend restart on a stack with active scheduled load (e.g. canary-fleet-burst).

Technical Notes

Three fix shapes (pick one — author's preference for the second):

  1. CAS guard in _recover_execution (cleanup_service.py:792-805): only mark the row failed if started_at is older than a grace window (e.g. 10s). Symmetric with the in-process watchdog at cleanup_service.py:427 (WATCHDOG_MIN_AGE_SECONDS). Cheap; closes the most common timing.
  2. "Warming up" gate: backend returns 503 from /internal/execute_task until recover_orphaned_executions has finished. Scheduler already retries on transient backend errors, so this is mostly an ordering primitive. Closes the race definitively.
  3. Status re-check before ZADD: task_execution_service.execute_task re-reads execution status with CAS just before capacity.acquire(); aborts with no slot if already terminal. Belt-and-braces; doesn't help if the recovery hasn't happened yet but the request was started before the row was created.

Files touching the seam:

  • src/backend/services/cleanup_service.py:792-805 (_recover_execution)
  • src/backend/main.py:459-473 (startup hook)
  • src/backend/services/task_execution_service.py:281-329 (execute_task SQL/Redis ordering)

Companion bug (slot leak when backend dies after ZADD but before finally): see follow-up issue.

Reported by canary watcher rows #26/#27/#28 in canary_violations.

Activity

  1. self-assigned this
    on May 12, 2026
  2. dolho commented on May 12, 2026

    @dolho
    Contributor

    PR #812 ships both fixes from the technical notes: (1) CAS grace window in recover_orphaned_executions (mirrors WATCHDOG_MIN_AGE_SECONDS pattern) and (2) warming-up 503 gate on /internal/execute-task. 12 unit tests covering grace boundary, fresh/old/mixed batches, flag semantics, and static gate-wiring check — all green. Acceptance criterion 4 (canary S-01 stays clean) needs staging verification.

  3. vybe commented on May 12, 2026

    @vybe
    Contributor

    Fixed in #812 (merged to dev). Two defenses shipped: startup grace window () and warming-up 503 gate on .

  4. added a commit that references this issue on Oct 20, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

complexity-lowComplexity: low (board points 1-3)

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions