diff --git a/packages/codex-session-relay/docs/invariants.md b/packages/codex-session-relay/docs/invariants.md index 2bcd421..04976a6 100644 --- a/packages/codex-session-relay/docs/invariants.md +++ b/packages/codex-session-relay/docs/invariants.md @@ -100,6 +100,11 @@ status. Every row below is implemented and carries a test; the suite is the proo | I-62 | No notification flood | a per-recipient minimum interval and hourly cap | implemented | | I-63 | Unchanged states stay quiet | a tick that changes nothing writes no journal rows | implemented | | I-64 | An unbounded daemon loop is not constructible | `run` requires a tick count, a deadline or a stop signal | implemented | +| I-65 | A supervisor is bounded by the owner's intent, not by a timer | it re-reads `service.json` and the stop request between segments; `RelayDaemon.run` is unchanged, so every worker it launches is still bounded by I-64 | implemented | +| I-66 | The current generation cannot be starved by history | candidates are filtered before the per-tick budget, the current anchor is reserved, and the remainder rotates through a persisted cursor | implemented | +| I-67 | One parent's backlog cannot consume another parent's opportunity | selection asks which parents are eligible before asking how many rows each has, then deals a bounded share one at a time | implemented | +| I-68 | A delivery whose generation has moved on cannot be claimed | the claim statement refuses it, so the decision cannot be overtaken between checking and acting | implemented | +| I-69 | An outstanding send is never rewritten as terminal | suppression annotates it instead, because reconciliation refuses to promote a terminal superseded aggregate and a lost response would become unresolvable | implemented | ## Work reports and the CXC report contract @@ -169,6 +174,11 @@ status. Every row below is implemented and carries a test; the suite is the proo | Inode ownership is not proven | a hardlink or bind mount can expose the same bytes under another authorized path, which the contract permits because it authorizes paths | | The JSON date-time format is unvalidated | the available validator has no working format checker, so timestamp format is unverified rather than implied | | Terminal turns are polled, not subscribed | the transport cannot subscribe, so automatic invocation is a bounded poll that then dispatches | +| Scheduler fairness is not transport concurrency | the adapter serialises on one worker, so a stalled call still blocks the one behind it; what is guaranteed is that a struggling parent stops being handed the rest of the budget | +| A live process is not a working one | health is computed from staged age, anchor poll freshness and backlog; liveness is reported separately and never counted | | Archive state can be unknown | an inconclusive listing withholds rather than guessing, and a later observation releases it | | A head commit is not observable from here | the relay cannot watch a forge, so `assert_current` enforces generation on the delivery path and takes `head_sha` only from a caller that already knows the current head. A push that changes the declared manifest is structurally a new event, because the revision hash and therefore the event id change with it; a push that changes nothing declared is not, and `_check_resubmission` is what stops an old report standing for it silently | | `work_reports` ships with its composite key | the schema is applied with `CREATE TABLE IF NOT EXISTS`, which never reshapes an existing table, so a store created from an intermediate revision of this change that used an event-only key cannot hold a second submission. No released version has this table, so there is nothing to migrate; a store built from such a revision is recreated rather than upgraded. The write itself no longer names a conflict target, so it does not depend on which revision created the table | +| A store is matched to its socket by provenance, not arithmetic | a hash cannot be inverted, so a store created under a spelling we cannot guess is findable only because it recorded which socket it serves. Stores record that from now on and selection asks them before creating a canonical database. A store created before that existed says nothing and is reported under `siblingStores` rather than adopted on a guess, because adopting the wrong store is worse than reporting an ambiguity | +| Ownership decisions are taken under the lock, not beside it | probing the daemon lock and then acting on the result are two operations, and a supervisor can start between them. `stop` and `disable` hold the lock across the decision: holding it is the proof that nothing is running and nothing can start, and failing to take it is the answer that someone is there. What this does NOT give is mutual exclusion with a supervisor that is already running - that is ownership, decided from the record | +| These are forward fixes | per-assignment settlement does not restore claims a previous global settlement already suppressed, and capped-state annotation does not reach deliveries whose generation advanced before it existed. Historical repair is separate work with its own evidence | diff --git a/packages/codex-session-relay/docs/operations.md b/packages/codex-session-relay/docs/operations.md index d2f92ec..7d2f5d7 100644 --- a/packages/codex-session-relay/docs/operations.md +++ b/packages/codex-session-relay/docs/operations.md @@ -124,22 +124,127 @@ transport call. | Phase | Meaning | |---|---| | `awaiting_receipt` | the child has not produced a completion receipt yet | +| `awaiting_send` | the receipt is collected and accepted; this relay has not reached the recipient yet | +| `in_flight` | a send was claimed and its outcome is not yet settled | | `parent_busy` | the parent is mid-turn; it is never interrupted | | `settings_rejected` | the host would not confirm the authorized execution settings | +| `withheld:` | refused before any transport call, naming the operation that refused | | `turn_accepted` | the transport started a turn | | `awaiting_ack` | delivered, acknowledgement outstanding | +| `awaiting_child_receipt` | a revision request was delivered; contract v1 defines no acknowledgement for that direction, so the child answers with its next completion receipt | | `channel_closed` | the push channel itself is unavailable; stored, not woken | | `superseded` | a newer generation or revision replaced this one | +| `superseded:` | an outstanding send a newer generation or revision replaced; its state is left alone so a lost response stays reconcilable | Each carries the most recent failed operation, its concrete error, the exact settings difference where there is one, and the next retry time. +`status` also reports `pendingIntents`: events whose delivery was wanted and refused before a +delivery row could exist, which a paused or unauthorized assignment produces. They have no +phase in the table above because they have no delivery; they carry the refusal, the attempt +count and the next retry instead. Without them the most stuck state in the system was the one +status could not show. + Health is separate from liveness. A running process with a growing observation backlog is reported as stalled: staged event age, when each current anchor was last successfully polled, and the backlog per assignment are all exposed, and a live pid is never counted as -working. - -Status: planned in PR-B. +working. An anchor whose turn is terminal with nothing staged behind it is reported as +settled and excluded from freshness: the scheduler deliberately stops reading it, so its +last poll cannot advance, and ageing it out would report every quiet assignment as stalled. +New staged work on that turn makes it eligible again. + +Settlement is recorded per assignment. Two assignments can legitimately watch the same child +turn, and the `observations` table is keyed by the turn alone, so it can only ever name whichever +assignment settled it first. `assignment_settlements` carries the per-assignment fact, which is +what the observation scheduler and this health block ask. Without it every other assignment +on a shared turn looked permanently unsettled, was re-polled on every round and spent +observation budget forever. + +So is the work itself. Staged claims are selected and settled per assignment, because a child +thread can serve several and a claim on one of its turns belongs to exactly one of them. +Selecting by thread alone put a paused assignment's claim into an active assignment's ring, +and settling by turn alone let whichever assignment polled first suppress the owner's claim +while producing no receipt of its own - so the owner's parent waited on an outcome that had +already been discarded. An inactive assignment's staged claim is left untouched until it is +resumed, and is excluded from backlog for the same reason: the scheduler will not process it. + +Each parent's delivery window rotates. The parent order decides who goes first; a persistent +per-parent cursor decides where that parent's own window starts, and it advances only by what +was actually attempted. Without it the window was always a parent's oldest rows, so a delivery +that fails before changing its own state stays eligible, stays oldest and blocks every later +delivery for that parent indefinitely. + +A delivery that has reached its busy or pre-send attempt cap is annotated when its generation +advances. Once a cap sets a hold, `attempt` returns before the pre-send supersession check, so +that is the only occasion on which such a row can ever be told its generation has moved on. + +Status: implemented. `status` reports the phase, the most recent failed operation with its +error code and, for a settings rejection, the exact fields the host disagreed on, plus the +next retry time. The field-level difference is read from the raw receipt, because the +transport classification keeps only a code. + +Observation health is reported beside it: staged event ages, when each current anchor was +last successfully polled, and the backlog per assignment. A failed read updates the attempt +time and never the success time, so an anchor whose first read failed reads as never polled +rather than fresh. Process liveness is reported separately and is never counted as health. + +## What one tick guarantees + +The loop is bounded, so the interesting question is not what it does but what it cannot +starve or lose. + +**No anchor is left behind.** A revision can reach `dispatched` by several routes, and binding +used to happen on only one of them, which left the generation unbound and made every later +receipt for it refused. Binding is now a recovery over state that runs first in each tick, so +whichever route dispatched it, the next tick repairs it and a receipt arriving in that same +tick is accepted. + +**A refused queue is remembered, not lost.** Finalizing a claim, recording the observation +that finalized it and queuing what it produced are one commit. A refusal that may not last - +a paused relationship, a recipient not yet authorized - records a delivery intent, and +recovery retries that intent with an exponential backoff so one permanently unqueueable event +cannot hold a slot. Anything else rolls the whole thing back, and the next tick re-observes. + +Absence of a delivery row is deliberately NOT treated as evidence that delivery was wanted: a +receipt emitted with `--no-enqueue` and an event stranded by an old generation look exactly +the same from outside, and neither should be sent. + +**The current generation is always reachable.** Observation reads are capped per tick. Within +that cap the tick serves a rotating subset of relationships rather than promising every one +of them a read, because that promise stops being possible once the relationship count passes +the budget. Each served relationship gets its current anchor first and then a rotating slice +of the rest, from a cursor persisted in the database so a restart resumes the rotation. + +| | anchor revisit | full backlog coverage | +|---|---|---| +| share of two or more | every service round | `ceil(R / served) * ceil(N / (share - 1))` ticks | +| share of one | every two service rounds | `ceil(R / served) * 2N` ticks | + +A candidate with nothing left to learn is dropped before the budget rather than after it, +which is what the old prefix got wrong: past eight generations the slice was permanently the +first eight, every one already observed, and the generation actually running was never +selected again. + +An observation is also no longer treated as the end of a turn. A receipt written just after +the completion was seen still has to be resolved, so a turn is skipped only when it has been +observed and has no unresolved staged claim. + +Status: implemented. + +**Every parent gets a turn.** Selection asks which parents have anything to send before it +asks how much each of them has, then takes a bounded share from each, dealt one at a time. +A single oldest-first window let one parent's backlog take every slot. Reconciliation is +selected the same way. A parent whose send errors or defers is skipped for the rest of that +tick only; it reserves no capacity and creates no hold. + +This is scheduler fairness, not transport concurrency. The adapter serialises on one worker, +so a stalled call still blocks the one behind it. + +**A stale event is stopped before the send.** A generation that has moved on invalidates +every outcome of the previous one, whether or not the new generation has produced a revision +yet, and the claim statement itself refuses one. An outstanding send is annotated rather than +rewritten, so reconciliation can still settle it, and an already delivered copy keeps its +history without being read as verification of the current head. ## What a restart preserves diff --git a/packages/codex-session-relay/src/codex_session_relay/ack.py b/packages/codex-session-relay/src/codex_session_relay/ack.py index 5a406b5..a068b02 100644 --- a/packages/codex-session-relay/src/codex_session_relay/ack.py +++ b/packages/codex-session-relay/src/codex_session_relay/ack.py @@ -23,7 +23,7 @@ currency_of, ) from .delivery import COMPLETION, REVISION -from .errors import AckRefused, RefusalReason +from .errors import AckRefused, RefusalReason, RelayError from .identity import ( ack_proof as derive_ack_proof, revision_request_event_id, @@ -592,6 +592,42 @@ def bind_dispatched_revision(self, revision_event_id: str): dispatch_turn_id=row["dispatch_turn_id"], source="dispatch_receipt", ) + def bind_pending_anchors(self, *, limit: int = 50) -> list: + """Bind every generation still anchor_pending whose revision actually dispatched. + + Binding used to be a hook on ONE path - the daemon's own new dispatch - so a revision + that reached dispatched any other way left its generation unbound, and by I-06 every + later receipt for that generation was refused. The routes that missed it are ordinary: + the deliver command, either reconcile promotion, and a dispatch committed in the last + tick before a shutdown. + + Recovery over state covers all of them at once, and it repairs a generation that was + left pending before this existed rather than only preventing new ones. bind_anchor is + idempotent for the same turn and refuses a conflicting rebind (I-05), so this can + never move an anchor that is already bound. + """ + rows = self.store.all( + "SELECT d.event_id FROM deliveries d" + " JOIN events e ON e.event_id = d.event_id" + " JOIN generations g ON g.relationship_id = e.relationship_id" + " AND g.execution_generation = e.execution_generation" + " WHERE d.kind = ? AND d.state IN (?,?) AND d.dispatch_turn_id IS NOT NULL" + " AND g.anchor_state = ?" + " ORDER BY d.updated_at LIMIT ?", + (REVISION, DISPATCHED, ACKNOWLEDGED, "anchor_pending", limit), + ) + bound = [] + for row in rows: + try: + result = self.bind_dispatched_revision(row["event_id"]) + except RelayError: + # A conflicting rebind stays refused and stays reportable; it is not this + # pass's business to resolve, and swallowing the others would hide them. + continue + if result is not None: + bound.append(row["event_id"]) + return bound + # The host reports a turn's start as WHOLE SECONDS, while we record the send with microsecond # precision. A reported start of N therefore means the turn really began somewhere in diff --git a/packages/codex-session-relay/src/codex_session_relay/cli.py b/packages/codex-session-relay/src/codex_session_relay/cli.py index 00352cd..bbbd922 100644 --- a/packages/codex-session-relay/src/codex_session_relay/cli.py +++ b/packages/codex-session-relay/src/codex_session_relay/cli.py @@ -381,8 +381,18 @@ def cmd_emit(services, args) -> dict: result = {"receipt": contract_record(stored), "stage": stored.get("_stage"), "duplicate": stored.get("_duplicate"), "terminalProof": proof, "observedTurnStatus": observed_status} - if stored.get("_stage") == "final" and not args.no_enqueue: - result["delivery"] = dict(services.delivery.enqueue(event)) + if stored.get("_stage") == "final": + # Whatever this event replaces stops being current the moment this one is final, and + # that is true whether or not anyone asked to deliver THIS one. --no-enqueue skips + # the queue, and the annotation used to ride on it, so a predecessor already in + # flight kept being reported as the current delivery. + services.delivery.annotate_predecessors(event) + # Only when there is no delivery row yet. Acceptance and enqueue are separate + # transactions here, so a receipt whose enqueue failed is retried to reach this line - + # and a receipt that was already queued must not be queued twice for having been + # re-emitted. + if not args.no_enqueue and services.delivery.find(event) is None: + result["delivery"] = dict(services.delivery.enqueue(event)) return result @@ -423,21 +433,36 @@ def cmd_deliver(services, args) -> dict: _require_adapter(services) if args.event: record = services.delivery.attempt(args.event, services.adapter) + # Every route to dispatched binds its anchor, not only the daemon's own. + services.ack.bind_pending_anchors() return {"attempt": record} out = [] - for row in services.delivery.eligible(now=services.clock.now(), limit=args.limit): + # per_parent_limit is the TICK's fairness share, and an operator asking for --limit 20 is + # not running a tick: capping each parent at two made a bulk deliver quietly send two. + # The share still governs the daemon. Fairness across parents is unaffected, because + # eligible() deals the rows one parent at a time whatever the per-parent window is. + for row in services.delivery.eligible( + now=services.clock.now(), limit=args.limit, per_parent_limit=args.limit, + ): out.append(services.delivery.attempt(row["event_id"], services.adapter)) + # The bulk path dispatches revisions too, so it binds for exactly the same reason the + # single-event path does. + services.ack.bind_pending_anchors() return {"attempts": out} def cmd_reconcile(services, args) -> dict: _require_adapter(services) - return services.reconciler.reconcile_attempt(args.request_id, services.adapter) + outcome = services.reconciler.reconcile_attempt(args.request_id, services.adapter) + services.ack.bind_pending_anchors() + return outcome def cmd_recover(services, args) -> dict: _require_adapter(services) - return services.reconciler.recover_on_start(services.adapter) + outcome = services.reconciler.recover_on_start(services.adapter) + outcome["anchorsBound"] = services.ack.bind_pending_anchors() + return outcome def cmd_claim(services, args) -> dict: @@ -661,7 +686,13 @@ def cmd_show(services, args) -> dict: def cmd_status(services, args) -> dict: - return services.delivery.snapshot(relationship_id=args.relationship) + payload = services.delivery.snapshot(relationship_id=args.relationship) + # Scoped with the deliveries. A global health block beside a filtered list invites + # reading another assignment's backlog as this one's. + payload["observation"] = services.delivery.observation_health( + relationship_id=args.relationship, + ) + return payload def _scheduler_wait(clock, deadline, sleeper=None): diff --git a/packages/codex-session-relay/src/codex_session_relay/daemon.py b/packages/codex-session-relay/src/codex_session_relay/daemon.py index 4a45cb7..9c6bdbe 100644 --- a/packages/codex-session-relay/src/codex_session_relay/daemon.py +++ b/packages/codex-session-relay/src/codex_session_relay/daemon.py @@ -16,10 +16,14 @@ from pathlib import Path from .delivery import COMPLETION +from .errors import ( + DeliveryRefused, RefusalReason, RegistrationError, RelayError, ScopeError, +) from .models import TurnRef from .policy import RetryPolicy from .receipts import ObservationOutcome, classify_observation -from .transport import DISPATCHED, HELD_UNCERTAIN +from .scope import assert_assignment_delivery +from .transport import DEFERRED_BUSY, DISPATCHED, HELD_UNCERTAIN, WITHHELD_PRE_SEND @dataclass @@ -30,6 +34,8 @@ class TickReport: deferred: int = 0 skipped: int = 0 acksVerified: int = 0 + anchorsBound: int = 0 + requeued: int = 0 quiet: bool = True notes: list = field(default_factory=list) @@ -38,6 +44,8 @@ def as_dict(self) -> dict: "observed": self.observed, "reconciled": self.reconciled, "delivered": self.delivered, "deferred": self.deferred, "skipped": self.skipped, "acksVerified": self.acksVerified, + "anchorsBound": self.anchorsBound, + "requeued": self.requeued, "quiet": self.quiet, "notes": self.notes, } @@ -107,20 +115,79 @@ def __init__(self, store, registry, intake, delivery, ack, reconciler, adapter, self.policy = policy or RetryPolicy() self.clock = clock or delivery.clock self.log = log or (lambda _message: None) + self._last_refusal = None # ------------------------------------------------------------------ tick def tick(self, *, now=None) -> TickReport: now = self.clock.now() if now is None else now report = TickReport() + self._bind_anchors(report) self._observe(report, now) + self._requeue_missing(report, now) self._reconcile(report, now) + # Again, because reconciliation is what promotes a held_uncertain revision to + # dispatched, and binding ran before it. A revision promoted in this tick would + # otherwise stay anchor_pending until the next one, and a child that emits its + # completion in that interval has it refused as unbound_generation even though the + # dispatch evidence is already committed. + self._bind_anchors(report) self._verify_acks(report, now) self._deliver(report, now) report.quiet = not (report.observed or report.reconciled or report.delivered - or report.deferred or report.acksVerified) + or report.deferred or report.acksVerified or report.anchorsBound + or report.requeued) return report + def _bind_anchors(self, report) -> None: + """Repair any generation left anchor_pending by a dispatch this loop did not make. + + First in the tick on purpose: a receipt arriving during this same tick is then + accepted rather than refused as unbound. + """ + try: + # Added, not assigned. tick() runs this pass twice - once before reconciliation + # and once after the pass that can promote a revision - and assigning let the + # second pass erase what the first repaired, so a tick that bound a durable + # anchor reported anchorsBound 0 and even quiet. + report.anchorsBound += len(self.ack.bind_pending_anchors()) + except Exception as error: # noqa: BLE001 - a tick never dies on one pass + report.notes.append(f"anchor recovery failed: {error}") + + def _requeue_missing(self, report, now) -> None: + """Queue a final event that has no delivery row. + + A refusal at enqueue time can be perfectly legitimate - a relationship paused between + selection and queuing - and the observation that produced the event is still true. So + the obligation is derived from state and retried here, instead of the event being lost + because the turn it came from will never look new again. + """ + try: + candidates = self.delivery.pending_intents( + now=now, limit=self.policy.max_sends_per_tick, + ) + except Exception as error: # noqa: BLE001 + report.notes.append(f"requeue scan failed: {error}") + return + for row in candidates: + event_id = row["event_id"] + try: + self.delivery.enqueue( + event_id, kind=row["kind"], recipient_task_id=row["recipient_task_id"], + ) + except Exception as error: # noqa: BLE001 - still refused; back this one off so + # it cannot hold a recovery slot against events that would succeed. + report.notes.append(f"requeue refused for {event_id}: {error}") + with self.store.transaction() as db: + self.delivery.record_intent_in( + db, event_id, relationship_id=row["relationship_id"], + kind=row["kind"], recipient_task_id=row["recipient_task_id"], + error=error, now=now, + ) + continue + self.delivery.clear_intent(event_id) + report.requeued += 1 + def _verify_acks(self, report, now) -> None: """Complete acknowledgements a parent authored without a host. @@ -172,37 +239,207 @@ def run(self, *, max_ticks=None, deadline=None, stop=None, sleep=None) -> list: def _observe(self, report, now) -> None: """Detect terminal turns and settle what they decide, without re-reporting old news.""" - for relationship in self._active_relationships(): - for turn_id in self._turns_to_poll(relationship): - thread = relationship["child"]["taskId"] + relationships = self._active_relationships() + if not relationships: + return + budget = self.policy.max_turn_reads_per_tick + # How many relationships this tick can serve properly. Serving ALL of them would mean + # promising every current anchor a read, which stops being possible the moment the + # relationship count passes the budget. Rotating which ones are served keeps the + # promise finite instead of impossible. + served = max(1, min(len(relationships), + budget // max(1, self.policy.min_relationship_share))) + start = self._cursor("relationships", len(relationships)) + order = [relationships[(start + offset) % len(relationships)] + for offset in range(len(relationships))] + share = max(1, budget // served) + reads = 0 + for relationship in order[:served]: + thread = relationship["child"]["taskId"] + for turn_id in self._turns_to_poll(relationship, share): + if reads >= budget: + break + reads += 1 try: turn = self.adapter.read_turn(thread, turn_id) except Exception as error: report.notes.append(f"turn read failed for {turn_id}: {error}") + self._record_poll(relationship, turn_id, status=None, error=error) continue + self._record_poll( + relationship, turn_id, + status=turn.status if turn is not None else "absent", + # An absent turn is not a successful poll. Recording it as one refreshed + # last_polled_at on every tick, and observation_health reads only poll + # freshness and settlement - so an anchor the host says is gone, which can + # never settle, reported healthy forever. + error=None if turn is not None else "the host reports this turn absent", + ) if turn is None or turn.status not in ("completed", "failed", "interrupted"): continue reference = TurnRef(thread, turn.turn_id, turn.status) - if self._already_observed(reference): + # Already observed is not already finished. A receipt written just after the + # completion was seen still has to be resolved, so the observation alone is + # no longer enough to skip the turn. + if self._already_observed( + reference, relationship["relationshipId"], + ) and not self.intake.staged_events( + thread_id=thread, turn_id=turn_id, + relationship_id=relationship["relationshipId"], + ): continue self._settle_turn(relationship, reference, report) + # Advanced whether or not anything was read. Advancing only on a read would let a + # window of relationships with nothing to do pin the cursor, and every relationship + # behind them would wait forever - the same starvation one level up. + self._advance_cursor("relationships", served, len(relationships)) + + def _turns_to_poll(self, relationship, share: int) -> list: + """The current anchor, plus a rotating slice of everything else worth reading. + + The old version collected every anchor oldest-first, sliced to the budget, and left + _observe to discard the already-observed ones AFTER the slice. Past eight generations + that slice was permanently the first eight, all of them already observed, and the + current generation was never selected again - which is how a live daemon inside its + time bound delivered nothing for JUN-100 generation 11. + + So candidates are filtered BEFORE the budget, the current anchor is reserved, and the + rest rotate through a persistent cursor so a backlog larger than the share is covered + in a finite number of ticks rather than re-read from the same end every time. + """ + rid = relationship["relationshipId"] + thread = relationship["child"]["taskId"] + current = None + history = [] + for generation in relationship["generations"]: + turn_id = generation["dispatchTurnId"] + if not turn_id: + continue + if generation["executionGeneration"] == relationship["executionGeneration"]: + current = turn_id + else: + history.append(turn_id) + # Scoped to THIS assignment. A child thread can serve several, and collecting their + # staged turns together put a paused assignment's work into an active assignment's + # ring and let one assignment settle another's claim. + staged = [ + row["turn_id"] + for row in self.intake.staged_events(thread_id=thread, relationship_id=rid) + ] + ring = [ + turn_id for turn_id in dict.fromkeys(staged + history) + if turn_id != current and self._worth_polling(thread, turn_id, rid) + ] + selected = [] + if current and self._worth_polling(thread, current, rid): + selected.append(current) + remaining = share - len(selected) + if remaining <= 0 and ring and self._alternate(rid): + # A share of one cannot give the anchor and the ring a read in the same tick, so + # it alternates between them. Advancing the ring cursor without reading its + # candidate would be skipping work, not scheduling it. + selected, remaining = [], 1 + if remaining > 0 and ring: + taken = min(remaining, len(ring)) + start = self._cursor(f"ring:{rid}", len(ring)) + selected.extend(ring[(start + offset) % len(ring)] for offset in range(taken)) + self._advance_cursor(f"ring:{rid}", taken, len(ring)) + return selected + + def _record_poll(self, relationship, turn_id, *, status, error) -> None: + """That we LOOKED, which an observations row cannot tell anyone. + + observations records terminal turns only, so a healthy long-running anchor has + no entry there at all and would read as stale forever. A failed read updates the + attempt time but never the success time: an anchor whose first read failed has + never been polled, and saying otherwise is the one lie that matters here. + """ + now = self.clock.iso() + with self.store.transaction() as db: + db.execute( + "INSERT INTO poll_observations (relationship_id, execution_generation," + " turn_id, last_status, last_polled_at, last_attempt_at, last_error)" + " VALUES (?,?,?,?,?,?,?)" + " ON CONFLICT(relationship_id, execution_generation, turn_id) DO UPDATE" + " SET last_status = excluded.last_status," + " last_polled_at = COALESCE(excluded.last_polled_at," + " poll_observations.last_polled_at)," + " last_attempt_at = excluded.last_attempt_at," + " last_error = excluded.last_error", + (relationship["relationshipId"], relationship["executionGeneration"], + turn_id, status, None if error else now, now, + None if error is None else f"{type(error).__name__}: {error}"), + ) - def _turns_to_poll(self, relationship) -> list: - """The anchor, plus any turn carrying a staged claim. + def _worth_polling(self, thread, turn_id, relationship_id=None) -> bool: + """Is there anything left to learn from this turn, for THIS assignment? - Polling only the anchor would leave a claim staged on a later admitted turn unresolved - forever, which is exactly the multi-turn case a loop produces. + Scoped for the same reason _already_observed is: two assignments can share a child + turn, and asking globally meant one assignment's observation made the turn look + finished to the other, which then never settled it at all. """ - turns = [] - for generation in relationship["generations"]: - if generation["dispatchTurnId"]: - turns.append(generation["dispatchTurnId"]) - for row in self.intake.staged_events(thread_id=relationship["child"]["taskId"]): - if row["turn_id"] not in turns: - turns.append(row["turn_id"]) - return turns[: self.policy.max_reconciles_per_tick] - - def _already_observed(self, reference: TurnRef) -> bool: + if self.intake.staged_events( + thread_id=thread, turn_id=turn_id, relationship_id=relationship_id, + ): + return True + if relationship_id is not None: + return self.store.one( + "SELECT 1 FROM assignment_settlements WHERE thread_id = ? AND turn_id = ?" + " AND relationship_id = ?", + (thread, turn_id, relationship_id), + ) is None + return self.store.one( + "SELECT 1 FROM observations WHERE thread_id = ? AND turn_id = ?", + (thread, turn_id), + ) is None + + def _cursor(self, listing: str, size: int) -> int: + if size <= 0: + return 0 + row = self.store.one( + "SELECT cursor FROM discovery_cursors WHERE task_id = 'scheduler' AND listing = ?", + (listing,), + ) + try: + return int(row["cursor"]) % size if row and row["cursor"] is not None else 0 + except (TypeError, ValueError): + return 0 + + def _advance_cursor(self, listing: str, by: int, size: int) -> None: + """Persisted, so a restart resumes the rotation instead of starting from one end.""" + if size <= 0: + return + position = (self._cursor(listing, size) + max(1, by)) % size + with self.store.transaction() as db: + db.execute( + "INSERT INTO discovery_cursors (task_id, listing, cursor, updated_at)" + " VALUES ('scheduler',?,?,?)" + " ON CONFLICT(task_id, listing) DO UPDATE SET cursor = excluded.cursor," + " updated_at = excluded.updated_at", + (listing, str(position), self.clock.iso()), + ) + + def _alternate(self, rid: str) -> bool: + """Toggle whose turn it is when the share is one.""" + listing = f"alt:{rid}" + turn = self._cursor(listing, 2) + self._advance_cursor(listing, 1, 2) + return turn == 1 + + def _already_observed(self, reference: TurnRef, relationship_id=None) -> bool: + """Per assignment, because two assignments can legitimately share a child turn. + + Asking globally meant the first assignment's settlement closed the turn for every + other one: the second never reached _synthesize, so a failed shared turn left its + other parents with no terminal outcome at all. + """ + if relationship_id is not None: + return self.store.one( + "SELECT 1 FROM assignment_settlements WHERE thread_id = ? AND turn_id = ?" + " AND terminal_status = ? AND relationship_id = ?", + (reference.thread_id, reference.turn_id, reference.turn_status, + relationship_id), + ) is not None return self.store.one( "SELECT 1 FROM observations WHERE thread_id = ? AND turn_id = ?" " AND terminal_status = ?", @@ -210,38 +447,161 @@ def _already_observed(self, reference: TurnRef) -> bool: ) is not None def _settle_turn(self, relationship, reference, report) -> None: - resolved = self.intake.resolve_staged(reference) + """Finalize, record and queue as ONE commit, with a rule for each kind of failure. + + Recording the observation first and queuing after is what lost events: a refusal at + the queue left a final event with no delivery row, and the next tick skipped the turn + because it had already been observed. + + A DURABLE refusal - a paused relationship, an unauthorized recipient - is a legitimate + answer, so the observation stands and _requeue_missing picks the event up once the + refusal no longer applies. Anything else is transient and nothing is known, so the + whole transaction rolls back and the next tick re-observes cleanly. + """ outcome = classify_observation(reference.turn_status, None) - event_id = None - synthesized = None - if reference.turn_status in ("failed", "interrupted") and not resolved["finalized"]: - try: - receipt = self.intake.daemon_observation( - relationship["relationshipId"], reference - ) - event_id = receipt["eventId"] - synthesized = event_id - except Exception as error: - report.notes.append(f"daemon observation refused: {error}") - self.intake.record_observation( - reference, outcome, relationship_id=relationship["relationshipId"], event=event_id - ) - # Storing an execution-only receipt is not telling anyone. A parent that is waiting for - # a verdict has to learn that the child failed, so a synthesized observation is queued - # like any other event; persistence and notification are separate outcomes and are - # reported separately. - for queueable in list(resolved["finalized"]) + ([synthesized] if synthesized else []): - try: - self.delivery.enqueue(queueable) - except Exception as error: - report.notes.append(f"enqueue refused for {queueable}: {error}") + synthesized, failed = self._synthesize(relationship, reference, report) + if failed: + # Recording the observation now would bury the failure: the turn would never look + # new again, the staged claim would be suppressed, and nothing would be left for + # recovery to find. Leave the turn untouched and try again next tick. + return + try: + self._commit_settlement(relationship, reference, outcome, synthesized, queue=True) + except (DeliveryRefused, ScopeError, RegistrationError) as refusal: + report.notes.append(f"enqueue refused for {reference.turn_id}: {refusal}") + self._last_refusal = refusal + self._commit_settlement( + relationship, reference, outcome, synthesized, queue=False, + ) + except Exception as error: # noqa: BLE001 - transient: keep nothing, retry next tick + report.notes.append(f"settlement rolled back for {reference.turn_id}: {error}") + return report.observed += 1 + def _synthesize(self, relationship, reference, report): + """An execution-only receipt for a turn that failed with no claim of its own. + + Written before the settlement transaction because it is a durable fact in its own + right and opens its own writes. If queuing it then fails, _requeue_missing finds it, + which is why storing it separately does not lose it. + """ + if reference.turn_status not in ("failed", "interrupted"): + return None, False + # A staged claim on this turn is no reason to skip: a failed or interrupted ending + # SUPPRESSES that claim rather than finalizing it, so without a synthesized receipt + # the parent is left waiting on a verdict that can never arrive. + try: + return self.intake.daemon_observation( + relationship["relationshipId"], reference, + )["eventId"], False + except RelayError as refusal: + if refusal.reason == RefusalReason.RELATIONSHIP_NOT_ACTIVE: + # NOT a decision about this turn. The scheduler selected an active assignment + # and the relationship paused while the host read was in flight, so the pause + # says nothing about what the turn did. Recording a settlement here would + # retire the turn - _worth_polling drops it - while the only carrier of the + # outcome, this synthesized receipt, was never written. A resume would then + # find nothing left to observe and the parent would wait forever. So this is + # transient like any other: keep nothing and look again once it is active. + report.notes.append( + f"observation deferred, {relationship['relationshipId']} is not active:" + f" {refusal}" + ) + return None, True + # Any other refusal IS a decision - this daemon may not assert anything about that + # turn - so settlement proceeds and records what it did observe. + report.notes.append(f"daemon observation refused: {refusal}") + return None, False + except Exception as error: # noqa: BLE001 - transient: nothing is known yet + report.notes.append(f"daemon observation failed: {error}") + return None, True + + def _commit_settlement(self, relationship, reference, outcome, synthesized, *, queue): + with self.store.transaction() as db: + # This assignment's claims only. Settling every claim on a shared child's turn + # suppressed the other assignments' events without synthesizing their receipts. + resolved = self.intake.resolve_staged_in( + db, reference, relationship["relationshipId"], + ) + self.intake.record_observation_in( + db, reference, outcome, relationship_id=relationship["relationshipId"], + event=synthesized, + ) + queueable = list(resolved["finalized"]) + if synthesized: + queueable.append(synthesized) + for event_id in queueable: + # Ownership comes from the EVENT, never from the relationship we happened to + # be polling. Staged claims are selected by thread and turn, and two + # assignments can share a child, so assuming the polled relationship would + # queue B's event to A's parent. + owner = self.intake.row(event_id)["relationship_id"] + # This event has just become final, so anything of its generation that was + # already in flight is no longer what the generation stands on. Done in the + # same transaction that finalized it, so the two facts cannot disagree. + self.delivery.annotate_predecessors_in(db, event_id) + if not queue: + # Delivery WAS wanted here. Recording that is what lets recovery retry + # this event and only this event, instead of guessing from the absence + # of a delivery row. + self.delivery.record_intent_in( + db, event_id, relationship_id=owner, kind=COMPLETION, + recipient_task_id=self.registry.get(owner)["parent"]["taskId"], + error=self._last_refusal, now=self.clock.now(), + ) + continue + # enqueue_in does not validate and enqueue does, so the authorization the old + # path got for free has to be asked for here, inside the same transaction. + record = self.registry.require_active(owner) + recipient = record["parent"]["taskId"] + assert_assignment_delivery( + record, kind=COMPLETION, recipient_task_id=recipient, + event_relationship_id=owner, + ) + # Storing a receipt is not telling anyone. A parent waiting for a verdict has + # to learn that the child failed, so a synthesized observation is queued like + # any other event. + self.delivery.enqueue_in( + db, event_id, relationship_id=owner, kind=COMPLETION, + recipient_task_id=recipient, + ) + # ------------------------------------------------------------- reconcile def _reconcile(self, report, now) -> None: budget = self.policy.max_reconciles_per_tick - for attempt in self.reconciler.open_attempts()[:budget]: + parents = self.reconciler.open_parents() + if not parents: + return + # Same starvation, one layer over. Slicing a global prefix meant one parent's + # unchanged attempts occupied every reconciliation slot - and a gate skip still + # consumed its place - so another parent's revision never reached dispatched and its + # anchor never bound. + cursor = self._cursor("reconcile_parents", len(parents)) + order = parents[cursor:] + parents[:cursor] + self._advance_cursor("reconcile_parents", 1, len(parents)) + share = max(1, budget // len(order)) + queues = [list(self._attempts_for(parent, share)) for parent in order] + dealt = [] + while len(dealt) < budget and any(queues): + for queue in queues: + if len(dealt) >= budget: + break + if queue: + dealt.append(queue.pop(0)) + # Advanced by what was actually DEALT, never by what was merely selected. Advancing + # inside the selection moved a parent's cursor past attempts this tick then dropped + # on the budget, and with more parents than budget the parent rotation and the + # attempt cursors stepped over the same attempts together - permanently, which is + # the starvation the per-parent cursor was added to remove. + for parent in order: + taken = sum(1 for row in dealt if row["parent_task_id"] == parent) + if taken: + self._advance_cursor( + f"reconcile:{parent}", taken, + self.reconciler.open_attempt_count(parent), + ) + for attempt in dealt: request_id = attempt["request_id"] decision, fingerprint = self._gate(attempt) if not decision: @@ -260,6 +620,34 @@ def _reconcile(self, report, now) -> None: ) report.reconciled += 1 + def _attempts_for(self, parent, share) -> list: + """One parent's slice, taken from a rotating position rather than the head. + + The parent order already has a cursor; the attempts inside a parent did not. A + parent with more unresolved attempts than its share re-read the same leading ones + every tick, and because _gate skips an attempt whose fingerprint is unchanged while + it still holds its place, the ones behind them were never reconciled at all - so a + later revision could sit unresolved and its anchor never bind. + """ + total = self.reconciler.open_attempt_count(parent) + if not total: + return [] + want = min(share, total) + start = self._cursor(f"reconcile:{parent}", total) + taken = list(self.reconciler.open_attempts( + limit=want, parents=[parent], offset=start, + )) + if len(taken) < want: + # Wrapped past the end, so the remainder comes from the front. Without this a + # cursor near the end would return a short slice and waste the budget. + seen = {row["request_id"] for row in taken} + for row in self.reconciler.open_attempts(limit=want, parents=[parent]): + if len(taken) >= want: + break + if row["request_id"] not in seen: + taken.append(row) + return taken + @staticmethod def _reads_were_complete(outcome) -> bool: observation = outcome.get("operationObservation", "") @@ -313,23 +701,75 @@ def _mark_gate(self, request_id, fingerprint, *, retry, error) -> None: # ---------------------------------------------------------------- deliver def _deliver(self, report, now) -> None: - eligible = self.delivery.eligible(now=now, limit=self.policy.max_sends_per_tick) + parents = self.delivery.eligible_parents(now=now) + if not parents: + return + cursor = self._cursor("delivery_parents", len(parents)) + # Where each parent's own window STARTS. The parent rotation decides who goes first; + # without this the window inside a parent was always its oldest rows, so a delivery + # that raises before changing its own state - and therefore stays eligible and stays + # oldest - blocked every later delivery for that parent on every subsequent tick. + totals = {parent: self.delivery.eligible_count(parent, now=now) for parent in parents} + offsets = { + parent: self._cursor(f"deliver:{parent}", totals[parent]) + for parent in parents if totals[parent] + } + eligible = self.delivery.eligible( + now=now, limit=self.policy.max_sends_per_tick, cursor=cursor, offsets=offsets, + ) + # Moved on by ONE position after every window, whatever the outcomes were. Every + # eligible parent is dealt from, so the rotation is not about who is included - it + # decides who goes FIRST, and therefore who gets the odd slot when the budget does + # not divide evenly. Advancing by the parent count would wrap to the same head and + # hand that slot to the same parent forever. + self._advance_cursor("delivery_parents", 1, len(parents)) + struggling = set() + attempted = {} for row in eligible: + parent = row["parent_task_id"] + if parent in struggling: + # Skipped for the REST OF THIS TICK only. It reserves no capacity, opens no + # attempt and creates no hold, so the next tick reconsiders this parent + # normally; it simply cannot spend the whole budget failing. + report.skipped += 1 + continue + attempted[parent] = attempted.get(parent, 0) + 1 try: record = self.delivery.attempt(row["event_id"], self.adapter, now=now) except Exception as error: report.notes.append(f"delivery refused for {row['event_id']}: {error}") + struggling.add(parent) continue if record is None: + # A busy parent or a withheld send is a returned outcome, not an exception, + # and it is exactly the case that used to consume a whole tick. + struggling.add(parent) report.deferred += 1 continue - report.delivered += 1 + if record["deliveryState"] in (HELD_UNCERTAIN, DEFERRED_BUSY, WITHHELD_PRE_SEND): + struggling.add(parent) + if record.get("sendAttempted") == "no": + # Suppressed before any transport call. Counting it as delivered reports a + # delivery that never reached the recipient, which is the opposite of what + # this counter is read for. + report.skipped += 1 + else: + report.delivered += 1 if row["kind"] != COMPLETION and record["deliveryState"] == DISPATCHED: try: self.ack.bind_dispatched_revision(row["event_id"]) except Exception as error: report.notes.append(f"anchor binding failed: {error}") + # Advanced by what was ATTEMPTED, never by what was selected. A row the budget + # dropped, or one skipped because its parent was already struggling, was never looked + # at - moving the cursor past it is how the reconcile path previously skipped work + # permanently. Wrapping on the count taken before the tick keeps the window inside a + # parent moving without ever stepping over an unread row. + for parent, taken in attempted.items(): + if taken and totals.get(parent): + self._advance_cursor(f"deliver:{parent}", taken, totals[parent]) + # ----------------------------------------------------------------- state def _active_relationships(self) -> list: diff --git a/packages/codex-session-relay/src/codex_session_relay/delivery.py b/packages/codex-session-relay/src/codex_session_relay/delivery.py index 01b80af..d242f00 100644 --- a/packages/codex-session-relay/src/codex_session_relay/delivery.py +++ b/packages/codex-session-relay/src/codex_session_relay/delivery.py @@ -11,6 +11,9 @@ import json from .errors import DeliveryRefused, RefusalReason +from .currency import ( + STALE_GENERATION, SUPERSEDED as SUPERSEDED_REVISION, head_revision, +) from .identity import request_id as derive_request_id from .lifecycle import UNKNOWN as LIFECYCLE_UNKNOWN, hold_reason_for, observe, record as record_lifecycle from .policy import RetryPolicy @@ -32,6 +35,12 @@ COMPLETION = "completion_event" REVISION = "revision_request" +# What a CHILD reports when a generation ended without something to review. These are facts +# about how the execution finished, not candidates for the generation's revision head, so the +# same-generation head rule does not apply to them. Deliberately a list of outcomes rather +# than "everything that is not reviewable": a revision_request is not reviewable either, and +# it IS answered by the child's reply. +EXECUTION_ONLY_OUTCOMES = ("failed", "interrupted", "blocked_needs_input") CLAIMABLE = (QUEUED, DEFERRED_BUSY, WITHHELD_PRE_SEND) SENDING = "sending" MANIFEST_LINES = 10 @@ -110,6 +119,74 @@ def enqueue_in(self, db, event_id, *, relationship_id, kind, recipient_task_id) ), ) self.store.journal("delivery_queued", event_id, {"kind": kind}, at=now) + # Every route by which an event becomes deliverable passes through here, including a + # receipt the host already reports as terminal, which never touches the settlement + # path. So this is where a newly deliverable event announces what it replaces. + self.annotate_predecessors_in(db, event_id) + + def record_intent_in(self, db, event_id, *, relationship_id, kind, recipient_task_id, + error, now) -> None: + """Remember that delivery was wanted here and refused for a reason that may not last. + + Written in the SAME transaction as the observation that produced the event, so the two + facts cannot disagree. Deriving this instead - final event, no delivery row - would + also match an event emitted with --no-enqueue and one stranded by an old generation, + neither of which anyone asked to send. + + Each refusal backs the retry off, so a permanently unqueueable event cannot hold a + recovery slot against events that would succeed. + """ + row = db.execute( + "SELECT attempts FROM delivery_intent WHERE event_id = ?", (event_id,), + ).fetchone() + attempts = (row["attempts"] if row else 0) + 1 + delay = self._backoff(attempts) + db.execute( + "INSERT INTO delivery_intent (event_id, relationship_id, kind, recipient_task_id," + " attempts, next_retry_at, last_error, noted_at) VALUES (?,?,?,?,?,?,?,?)" + " ON CONFLICT(event_id) DO UPDATE SET attempts = excluded.attempts," + " next_retry_at = excluded.next_retry_at, last_error = excluded.last_error", + (event_id, relationship_id, kind, recipient_task_id, attempts, now + delay, + str(error), self.clock.iso()), + ) + + def _backoff(self, attempts: int) -> float: + """Bounded before the exponent is evaluated, not after. + + An intent that stays legitimately unqueueable - a relationship that stays paused - + has no cap on its attempt count. Computing base * 2 ** (attempts - 1) and then + clamping means the 1025th refusal builds an integer too large to convert to a float, + and the OverflowError escapes the refusal handler that was meant to absorb it. The + transaction rolls back with the intent still due, so every later tick fails the same + way. Once the ceiling is reached the exponent stops mattering, so stop there. + """ + base, ceiling = self.policy.presend_base_seconds, self.policy.presend_max_seconds + if base <= 0: + return ceiling + steps = max(0, attempts - 1) + # Derived from this policy's own ratio, not a fixed step count: a small base needs + # more doublings to reach its ceiling, and a constant would send such a policy + # straight to the cap while its backoff still had room. + import math + + if ceiling <= base or steps >= math.ceil(math.log2(ceiling / base)): + return ceiling + return min(ceiling, base * (2 ** steps)) + + def pending_intents(self, *, now: float, limit: int = 4) -> list: + """Events whose delivery was wanted, refused, and is due to be tried again.""" + return self.store.all( + "SELECT i.* FROM delivery_intent i" + " LEFT JOIN deliveries d ON d.event_id = i.event_id" + " WHERE d.event_id IS NULL" + " AND (i.next_retry_at IS NULL OR i.next_retry_at <= ?)" + " ORDER BY i.next_retry_at LIMIT ?", + (now, limit), + ) + + def clear_intent(self, event_id: str) -> None: + with self.store.transaction() as db: + db.execute("DELETE FROM delivery_intent WHERE event_id = ?", (event_id,)) def _render_for(self, row, record, request, report=None) -> str: """Deterministic, directional, and carrying no turn id belonging to the recipient. @@ -244,17 +321,97 @@ def _render_revision(self, row, record, request, report=None) -> str: ] return NEWLINE.join(lines) - def eligible(self, *, now: float, limit: int = 10) -> list: + ELIGIBLE_WHERE = ( + " WHERE d.state IN (?,?,?) AND d.hold_reason IS NULL" + " AND (d.next_eligible_at IS NULL OR d.next_eligible_at <= ?)" + " AND r.status = 'active' AND r.superseded_by IS NULL AND e.stage = 'final'" + ) + + def eligible_parents(self, *, now: float) -> list: + """Who has anything to send, decided independently of how much each of them has. + + This is the half that removes starvation. A single ORDER BY created_at LIMIT is a + global prefix: a parent with forty thousand older rows fills it by itself and a parent + with one newer row is never seen. Asking which PARENTS are eligible cannot be crowded + out by row counts. + """ + rows = self.store.all( + "SELECT DISTINCT r.parent_task_id AS parent_task_id FROM deliveries d" + " JOIN relationships r ON r.relationship_id = d.relationship_id" + " JOIN events e ON e.event_id = d.event_id" + + self.ELIGIBLE_WHERE + + " ORDER BY r.parent_task_id", + (QUEUED, DEFERRED_BUSY, WITHHELD_PRE_SEND, now), + ) + return [row["parent_task_id"] for row in rows] + + def eligible_for_parent(self, parent: str, *, now: float, limit: int, offset: int = 0): return self.store.all( - "SELECT d.* FROM deliveries d" + "SELECT d.*, r.parent_task_id AS parent_task_id FROM deliveries d" + " JOIN relationships r ON r.relationship_id = d.relationship_id" + " JOIN events e ON e.event_id = d.event_id" + + self.ELIGIBLE_WHERE + + " AND r.parent_task_id = ?" + " ORDER BY d.created_at LIMIT ? OFFSET ?", + (QUEUED, DEFERRED_BUSY, WITHHELD_PRE_SEND, now, parent, limit, offset), + ) + + def eligible_count(self, parent: str, *, now: float) -> int: + """How many eligible deliveries one parent has, so a cursor over them can wrap.""" + row = self.store.one( + "SELECT COUNT(*) AS c FROM deliveries d" " JOIN relationships r ON r.relationship_id = d.relationship_id" " JOIN events e ON e.event_id = d.event_id" - " WHERE d.state IN (?,?,?) AND d.hold_reason IS NULL" - " AND (d.next_eligible_at IS NULL OR d.next_eligible_at <= ?)" - " AND r.status = 'active' AND r.superseded_by IS NULL AND e.stage = 'final'" - " ORDER BY d.created_at LIMIT ?", - (QUEUED, DEFERRED_BUSY, WITHHELD_PRE_SEND, now, limit), + + self.ELIGIBLE_WHERE + + " AND r.parent_task_id = ?", + (QUEUED, DEFERRED_BUSY, WITHHELD_PRE_SEND, now, parent), ) + return row["c"] if row else 0 + + def eligible(self, *, now: float, limit: int = 10, per_parent_limit=None, cursor: int = 0, + offsets=None) -> list: + """A fair slice: every eligible parent, then a bounded share each, dealt one at a time. + + Dealt singly rather than in contiguous blocks, because a block allocation leaves the + last parent short whenever the budget is not a multiple of the share. + """ + parents = self.eligible_parents(now=now) + if not parents: + return [] + share = per_parent_limit or self.policy.max_sends_per_parent_per_tick + start = cursor % len(parents) + order = parents[start:] + parents[:start] + queues = { + parent: self._window_for( + parent, now=now, share=share, offset=(offsets or {}).get(parent, 0), + ) + for parent in order + } + selected = [] + while len(selected) < limit and any(queues[parent] for parent in order): + for parent in order: + if len(selected) >= limit: + break + if queues[parent]: + selected.append(queues[parent].pop(0)) + return selected + + def _window_for(self, parent, *, now, share, offset): + """One parent's share, taken from a rotating position and wrapped at the end. + + Without the wrap a cursor near the end of a parent's backlog returns a short window - + five rows at offset four yields one - so the rotation that exists to stop starvation + would quietly cost throughput every time it came round. + """ + taken = list(self.eligible_for_parent(parent, now=now, limit=share, offset=offset)) + if len(taken) < share and offset: + seen = {row["event_id"] for row in taken} + for row in self.eligible_for_parent(parent, now=now, limit=share, offset=0): + if len(taken) >= share: + break + if row["event_id"] not in seen: + taken.append(row) + return taken # ---------------------------------------------------------------- claim @@ -272,7 +429,21 @@ def _claim(self, event_id: str, *, now: float, owner: str, recipient: str): reconciliation searches the recipient for the token the message actually carried. Allocation, token and bytes now commit together or not at all. """ + # Decided and recorded BEFORE the claim, in its own committed transaction: a + # suppression written inside the claim would be rolled back by the refusal that + # follows it. The claim below then refuses a stale generation atomically anyway, + # so the gap between the two cannot let one through. + superseded = self._suppress_if_superseded(event_id) + if superseded: + raise _Superseded(superseded) with self.store.transaction() as db: + # Re-read inside the write. The generation predicate below catches an + # advanced generation, but a newer FINAL revision of the SAME generation + # can be committed between the check above and this statement, and that + # would claim and send an event something had already replaced. + late = self._supersession_reason(db, event_id) + if late: + raise _LateSupersession(late) cursor = db.execute( "UPDATE deliveries" " SET state = ?, lease_owner = ?, lease_until = ?," @@ -285,7 +456,15 @@ def _claim(self, event_id: str, *, now: float, owner: str, recipient: str): " WHERE r.relationship_id = deliveries.relationship_id" " AND r.status = 'active' AND r.superseded_by IS NULL)" " AND EXISTS (SELECT 1 FROM events e" - " WHERE e.event_id = deliveries.event_id AND e.stage = 'final')", + " WHERE e.event_id = deliveries.event_id AND e.stage = 'final')" + # A generation that has moved on cannot be claimed at all. Checked here + # rather than only before, because the generation can advance while the + # host reads are in flight. + " AND NOT EXISTS (SELECT 1 FROM events ev" + " JOIN relationships rr" + " ON rr.relationship_id = ev.relationship_id" + " WHERE ev.event_id = deliveries.event_id" + " AND ev.execution_generation < rr.execution_generation)", ( SENDING, owner, now + self.policy.lease_seconds, self.clock.iso(), event_id, QUEUED, DEFERRED_BUSY, WITHHELD_PRE_SEND, now, @@ -362,7 +541,9 @@ def attempt(self, event_id: str, adapter, *, now=None, owner: str = "relay"): assert_assignment_delivery( relationship, kind=row["kind"], recipient_task_id=recipient, recipient_thread_id=row["recipient_thread_id"], - event_relationship_id=row["relationship_id"], + # From the EVENT, not the delivery row. Comparing the delivery row against itself + # is a tautology and would pass a row pointed at another assignment. + event_relationship_id=(self.intake.row(event_id) or {})["relationship_id"], manifest_paths=_manifest_paths(self.intake.row(event_id)), ) if self._rate_limited(recipient, now): @@ -394,7 +575,8 @@ def attempt(self, event_id: str, adapter, *, now=None, owner: str = "relay"): try: settings = self._settings_for(recipient) except DeliveryRefused as refusal: - self._withhold_settings(event_id, now, refusal, attempts=row["attempt_count"]) + self._withhold_settings(event_id, now, refusal, attempts=row["attempt_count"], + row=row) return None known_turns = set(adapter.list_turn_ids(row["recipient_thread_id"], limit=25)) @@ -404,6 +586,17 @@ def attempt(self, event_id: str, adapter, *, now=None, owner: str = "relay"): ) except _NotClaimable: return None + except _LateSupersession as late: + # The transaction rolled back, so nothing is recorded yet. Record it now, + # through the same path the pre-claim check uses, and report it identically. + self._suppress_if_superseded(event_id) + return {"deliveryState": SUPERSEDED, "supersededReason": late.reason, + "eventId": event_id, "sendAttempted": "no"} + except _Superseded as superseded: + # No transport call at all: suppression writes state and journals and nothing + # else, so a stale event cannot wake the parent or open a generation. + return {"deliveryState": SUPERSEDED, "supersededReason": superseded.reason, + "eventId": event_id, "sendAttempted": "no"} try: receipt = adapter.send_message( @@ -416,6 +609,23 @@ def attempt(self, event_id: str, adapter, *, now=None, owner: str = "relay"): "error": f"{type(error).__name__}: {error}", } facts = classify_operation_receipt(receipt) + # Read from the RAW receipt: the host reports a settings rejection as a failed + # receipt carrying settingsFindings, and classification keeps only the code. By the + # time _settle sees it the field-level difference is already gone. + findings = receipt.get("settingsFindings") if isinstance(receipt, dict) else None + if facts.failed_operation or facts.delivery_state in ( + WITHHELD_PRE_SEND, INBOX_ONLY, HELD_UNCERTAIN, + ): + self.record_failure( + event_id, + "settings_check" if findings else (facts.failed_operation or "transport"), + detail=facts.error_text or facts.delivery_state, + relationship_id=row["relationship_id"], + parent_task_id=relationship["parent"]["taskId"], + error_code=facts.rpc_error_code, + difference=_render_findings(findings), + retry_safe=facts.retry_safe, + ) # Membership in the pre-send snapshot proves this start steered a turn we had already # seen. Absence proves nothing: another client can open a turn after the snapshot, and # our start can then steer THAT one. So an unmatched id is 'not previously observed', @@ -453,7 +663,8 @@ def _settings_for(self, task_id: str): settings.require_usable() return settings - def _withhold_settings(self, event_id: str, now: float, refusal, *, attempts: int) -> None: + def _withhold_settings(self, event_id: str, now: float, refusal, *, attempts: int, + row=None) -> None: """Withheld before any transport call, naming what is missing. Not a permanent hold: settings that were never recorded can be recorded, and the next @@ -475,6 +686,17 @@ def _withhold_settings(self, event_id: str, now: float, refusal, *, attempts: in "detail": refusal.detail}, at=self.clock.iso(), ) + # Outside the transaction above, and recorded because there is no attempt to read it + # from. Every other cause reaches an operator through the attempt record; this one + # refused before one existed, so status reported the generic awaiting_receipt and + # said nothing about the settings that are actually missing. + self.record_failure( + event_id, "settings_check", + detail=refusal.detail, + relationship_id=row["relationship_id"] if row is not None else None, + error_code=refusal.reason.value if refusal.reason else "settings_unavailable", + retry_safe=True, next_retry_at=when, + ) def record_settings_violation(self, request_id: str, event_id: str, findings) -> dict: """Annotate a dispatch that already reached a turn. It stays a dispatch. @@ -549,6 +771,11 @@ def _defer_busy(self, event_id: str, row, now: float) -> None: hold = None if attempts >= self.policy.busy_max_attempts: hold = self.policy.cap_reason("busy") + self.record_failure( + event_id, "parent_busy", detail="the recipient is mid-turn and is never interrupted", + relationship_id=row["relationship_id"], + next_retry_at=now + self.policy.delay_for(attempts + 1, "busy"), + ) with self.store.transaction() as db: db.execute( "UPDATE deliveries SET state = ?, next_eligible_at = ?, hold_reason = ?," @@ -568,6 +795,11 @@ def _withhold(self, event_id: str, observation, now: float, *, attempts: int) -> # into a delivery that never happens. The reason is recorded in recipient_lifecycle # and the journal, and the next observation decides again. when = now + self.policy.lifecycle_recheck_seconds + self.record_failure( + event_id, "lifecycle_read", + detail=observation.detail or observation.withhold_reason or "not deliverable", + error_code=observation.withhold_reason, next_retry_at=when, + ) with self.store.transaction() as db: db.execute( "UPDATE deliveries SET state = ?, next_eligible_at = ?, updated_at = ?" @@ -626,17 +858,353 @@ def _settle(self, event_id, request_id, record, facts, previously_observed, now) ) def mark_superseded(self, event_id: str, *, reason: str = SUPERSEDED_HOLD) -> None: - row = self.find(event_id) - if row is None or row["state"] in (DISPATCHED, "acknowledged"): - # A delivery the recipient may already be acting on is never withdrawn. - return + """Withdraw a delivery the recipient cannot already be acting on. + + The guard is part of the UPDATE rather than a preflight read: a concurrent dispatch + between the check and the write would otherwise be overwritten. + """ with self.store.transaction() as db: - db.execute( + cursor = db.execute( + "UPDATE deliveries SET state = ?, hold_reason = ?, updated_at = ?" + " WHERE event_id = ? AND state IN (?,?,?) AND hold_reason IS NULL", + (SUPERSEDED, reason, self.clock.iso(), event_id, + QUEUED, DEFERRED_BUSY, WITHHELD_PRE_SEND), + ) + if cursor.rowcount == 1: + self.store.journal( + "delivery_superseded", event_id, {"reason": reason}, at=self.clock.iso(), + ) + else: + self._annotate_supersession_in(db, event_id, reason) + + def _suppress_if_superseded(self, event_id: str): + """Record that this delivery is no longer current, and say so. Commits. + + An outstanding send is annotated rather than rewritten: reconciliation refuses to + promote a terminal superseded aggregate, so rewriting one would make a lost + response permanently unresolvable. + """ + with self.store.transaction() as db: + reason = self._supersession_reason(db, event_id) + if not reason: + return None + cursor = db.execute( "UPDATE deliveries SET state = ?, hold_reason = ?, updated_at = ?" - " WHERE event_id = ?", - (SUPERSEDED, reason, self.clock.iso(), event_id), + " WHERE event_id = ? AND state IN (?,?,?) AND hold_reason IS NULL", + (SUPERSEDED, reason, self.clock.iso(), event_id, + QUEUED, DEFERRED_BUSY, WITHHELD_PRE_SEND), + ) + if cursor.rowcount == 1: + self.store.journal( + "delivery_superseded", event_id, {"reason": reason}, + at=self.clock.iso(), + ) + else: + self._annotate_supersession_in(db, event_id, reason) + return reason + + + def _last_failure(self, event_id): + rows = self.failures_for(event_id) + return rows[0] if rows else None + + def _supersession_note(self, event_id): + row = self.store.one( + "SELECT reason, noted_at FROM delivery_supersession WHERE event_id = ?", + (event_id,), + ) + return dict(row) if row else None + + def observation_health(self, *, now=None, stale_after=900.0, relationship_id=None) -> dict: + """Whether the loop is actually looking, which a live process does not answer. + + The JUN-100 and JUN-101 incident had a live pid, inside its time bound, polling + nothing useful and delivering nothing. Liveness is reported separately and is + never counted here. + """ + from datetime import datetime + + def age(stamp): + if not stamp: + return None + try: + seen = datetime.fromisoformat(stamp.replace("Z", "+00:00")) + except ValueError: + return None + return max(0.0, (now or self.clock.now()) - seen.timestamp()) + + staged = [ + {"eventId": row["event_id"], "turnId": row["turn_id"], + "ageSeconds": age(row["staged_at"] or row["first_seen_at"])} + for row in self.store.all( + # Joined through relationships with the same active predicate the anchors + # use. A paused, cancelled or superseded assignment is no longer settled by + # the scheduler, so its staged event would age forever and hold the whole + # health block at degraded while every active assignment was fine. + "SELECT e.event_id, e.turn_id, e.staged_at, e.first_seen_at FROM events e" + " JOIN relationships r ON r.relationship_id = e.relationship_id" + " WHERE e.stage = 'staged'" + " AND r.status = 'active' AND r.superseded_by IS NULL" + + (" AND e.relationship_id = ?" if relationship_id else "") + + " ORDER BY e.first_seen_at", + (relationship_id,) if relationship_id else (), + ) + ] + anchors, backlog = {}, {} + # Built from the ACTIVE current generations and left-joined to their polls, not from + # poll_observations. Starting from the poll table omits an anchor that has never been + # read at all - which is exactly the relationship a rotating scheduler has not reached + # yet - so the aggregate could report healthy while some current anchor was untouched. + for row in self.store.all( + "SELECT g.relationship_id, g.dispatch_turn_id, p.last_polled_at, p.last_error" + " , r.child_task_id" + " , (SELECT COUNT(*) FROM assignment_settlements o" + " WHERE o.thread_id = r.child_task_id" + " AND o.turn_id = g.dispatch_turn_id" + # Per assignment, like the scheduler's own check. Two assignments can share a + # child turn, and asking globally let one assignment's observation mark the + # other settled - excluding an assignment whose own settlement was still + # outstanding from the very freshness check that would have shown it. + # assignment_settlements is the per-assignment fact; observations is keyed by + # the turn alone and can only ever name whoever settled it first. + " AND o.relationship_id = r.relationship_id) AS observed" + " , (SELECT COUNT(*) FROM events e" + " WHERE e.turn_thread_id = r.child_task_id" + " AND e.turn_id = g.dispatch_turn_id" + # Per assignment, like the observation beside it. A staged claim belonging to + # another assignment on a shared child turn is not this one's outstanding work, + # and counting it unsettled a settled assignment into a false stall. + " AND e.relationship_id = r.relationship_id" + " AND e.stage = 'staged') AS staged_here" + " FROM relationships r" + " JOIN generations g ON g.relationship_id = r.relationship_id" + " AND g.execution_generation = r.execution_generation" + " LEFT JOIN poll_observations p" + " ON p.relationship_id = g.relationship_id" + " AND p.execution_generation = g.execution_generation" + " AND p.turn_id = g.dispatch_turn_id" + " WHERE r.status = 'active' AND r.superseded_by IS NULL" + + (" AND r.relationship_id = ?" if relationship_id else ""), + (relationship_id,) if relationship_id else (), + ): + if row["dispatch_turn_id"] is None: + # A generation whose anchor is still pending has no turn to poll. That is a + # delivery phase, not a scheduler that stopped looking, and counting it as + # never polled reported stalled for a relay behaving exactly as designed. + anchors[row["relationship_id"]] = { + "turnId": None, "lastPolledAt": None, "ageSeconds": None, + "lastError": None, "settled": False, "anchorPending": True, + } + continue + # The scheduler deliberately stops reading a turn once it is terminal and nothing + # is staged behind it, so its last poll can never advance again. Ageing that out + # marked every quiet, fully observed assignment stalled forever, which is the + # opposite of the signal this exists to give. + settled = bool(row["observed"]) and not row["staged_here"] + anchors[row["relationship_id"]] = { + "turnId": row["dispatch_turn_id"], "lastPolledAt": row["last_polled_at"], + "ageSeconds": age(row["last_polled_at"]), "lastError": row["last_error"], + "settled": settled, "anchorPending": False, + } + for row in self.store.all( + # Joined through relationships with the same predicate stagedEvents uses. Reading + # events directly made the two fields disagree the moment an assignment was + # paused or cancelled: stagedEvents went empty while backlog still reported work + # the scheduler will never process. + "SELECT e.relationship_id AS relationship_id, COUNT(*) AS n FROM events e" + " JOIN relationships r ON r.relationship_id = e.relationship_id" + " WHERE e.stage = 'staged'" + " AND r.status = 'active' AND r.superseded_by IS NULL" + + (" AND e.relationship_id = ?" if relationship_id else "") + + " GROUP BY e.relationship_id", + (relationship_id,) if relationship_id else (), + ): + backlog[row["relationship_id"]] = row["n"] + oldest = max([s["ageSeconds"] or 0.0 for s in staged], default=0.0) + never = [rid for rid, a in anchors.items() + if a["lastPolledAt"] is None and not a["settled"] + and not a["anchorPending"]] + stale = [rid for rid, a in anchors.items() + if not a["settled"] and not a["anchorPending"] + and a["ageSeconds"] is not None + and a["ageSeconds"] > stale_after] + if never or stale: + health, reason = "stalled", ( + f"{len(never)} anchors never successfully polled," + f" {len(stale)} not polled for over {stale_after:.0f}s" + ) + elif oldest > stale_after: + health, reason = "degraded", f"a staged event has waited {oldest:.0f}s" + else: + health, reason = "healthy", "" + return {"stagedEvents": staged, "oldestStagedAgeSeconds": oldest, + "anchors": anchors, "backlog": backlog, + "health": health, "reason": reason, + "note": "process liveness is reported separately and is not health"} + + def record_failure(self, scope_key, operation, *, detail, relationship_id=None, + parent_task_id=None, error_code=None, difference=None, + retry_safe=None, next_retry_at=None) -> None: + """The most recent cause for one subject and one operation. + + Fed from RETURNED failure values as well as exceptions. The settings rejection that + matters most in practice never raises: the host answers with a failed receipt and the + transport classification keeps only a code, dropping the field-level findings. + """ + with self.store.transaction() as db: + db.execute( + "INSERT INTO failed_operations (scope_key, operation, relationship_id," + " parent_task_id, detail, error_code, difference, retry_safe, occurred_at," + " next_retry_at) VALUES (?,?,?,?,?,?,?,?,?,?)" + " ON CONFLICT(scope_key, operation) DO UPDATE SET detail=excluded.detail," + " error_code=excluded.error_code, difference=excluded.difference," + " retry_safe=excluded.retry_safe, occurred_at=excluded.occurred_at," + " next_retry_at=excluded.next_retry_at", + (scope_key, operation, relationship_id, parent_task_id, str(detail), + error_code, difference, None if retry_safe is None else int(retry_safe), + self.clock.iso(), next_retry_at), ) - self.store.journal("delivery_superseded", event_id, {"reason": reason}, at=self.clock.iso()) + + def failures_for(self, scope_key): + rows = self.store.all( + "SELECT * FROM failed_operations WHERE scope_key = ? ORDER BY occurred_at DESC", + (scope_key,), + ) + return [dict(row) for row in rows] + + def _supersession_reason(self, db, event_id: str): + """Is this still the thing the assignment stands on? Read inside the caller's write. + + Two rules, and the first is the one the 2026-09-16 reproduction needs: a generation + that has moved on invalidates every outcome of the previous one - ready, blocked, + failed, manifest or not - whether or not the new generation has produced a revision + yet. JUN-119 g2 events delivered after g3 opened and JUN-100 g5 delivered after g7 + were all rejected downstream as stale_generation; suppressing before the send is the + fix, and a new generation having nothing in it yet is not a reason to send the old. + """ + event = db.execute( + "SELECT relationship_id, execution_generation, outcome, event_id FROM events" + " WHERE event_id = ?", (event_id,), + ).fetchone() + if event is None: + return None + relationship = db.execute( + "SELECT execution_generation FROM relationships WHERE relationship_id = ?", + (event["relationship_id"],), + ).fetchone() + if relationship is None: + return None + if event["execution_generation"] < relationship["execution_generation"]: + return STALE_GENERATION + if event["outcome"] == REVISION: + # Relay-owned, and answered by whatever the child sends back for this generation - + # reviewable or not. head_revision considers only ready_for_review receipts, so + # routing a request through it left one answered by a failed, interrupted or + # blocked reply reported as awaiting_child_receipt forever, even though the + # completion it asked for had already arrived. + # Any final event of that generation, not only a child-authored one. A revision + # turn can fail or be interrupted without the child ever writing a receipt, and + # the relay then records the outcome itself through daemon_observation - which is + # exactly the answer the request was waiting for, and is what the parent receives. + # Requiring producer = 'child' left the request current after that had happened. + answered = db.execute( + "SELECT 1 FROM events" + " WHERE relationship_id = ? AND execution_generation = ?" + " AND stage = 'final' AND suppressed_reason IS NULL AND event_id != ?", + (event["relationship_id"], event["execution_generation"], event_id), + ).fetchone() + return SUPERSEDED_REVISION if answered is not None else None + # The head rule is one REVISION replacing another, and head_revision only ever + # considers reviewable events. A child's EXECUTION-ONLY outcome is not competing for + # that head: it is a different kind of fact about the same generation, and a later + # one. Measuring it against a head that is already final suppressed it before any + # transport call, so a generation that ended badly after producing a reviewable + # revision never told the parent it had ended, while the generation was still current + # and the event declared no supersession of its own. The generation rule above still + # covers these, because a generation that has moved on invalidates every outcome of + # the previous one whatever its shape. + # + # Named rather than expressed as "not reviewable". A revision_request is relay-owned + # and is not reviewable either, but it IS answered by the child's reply - exempting it + # left the relay's own ask reported as awaiting_child_receipt after the receipt it + # asked for had arrived. + if event["outcome"] in EXECUTION_ONLY_OUTCOMES: + return None + head = head_revision( + db, event["relationship_id"], event["execution_generation"], + ) + if not head["eventId"] or head["eventId"] == event_id: + # A null head means the generation has no single reviewable revision this one + # stands behind, which is what an execution-only failure looks like in its OWN + # current generation. That is not evidence anything replaced it. Ambiguous + # lineage also lands here and is deliberately NOT read as supersession: it is + # arbitrated at acknowledgement by revision_currency, and suppressing on it + # here would destroy the delivery chance of every independent revision in a + # generation that simply never declared a chain. + return None + successor = db.execute( + "SELECT stage FROM events WHERE event_id = ?", (head["eventId"],), + ).fetchone() + # A STAGED successor is a claim, not a replacement. If it later fails it is + # suppressed, and destroying this event's only delivery chance on the strength of it + # would be permanent. + if successor is None or successor["stage"] != "final": + return None + return SUPERSEDED_REVISION + + def _annotate_supersession_in(self, db, event_id: str, reason: str) -> None: + db.execute( + "INSERT INTO delivery_supersession (event_id, reason, noted_at, applied)" + " VALUES (?,?,?,0) ON CONFLICT(event_id) DO NOTHING", + (event_id, reason, self.clock.iso()), + ) + + def annotate_predecessors_in(self, db, event_id: str) -> None: + """Mark outstanding deliveries this newly final event replaces within its generation. + + The pre-send check cannot reach them: attempt() returns early for a non-claimable + state, so a revision that was already sending, held_uncertain or dispatched when its + successor arrived left no supersession row at all. Reconciliation could then promote + it to dispatched and status would present it as the current delivery. + + Annotation only. Rewriting an outstanding send would make a lost response + permanently unresolvable, which is worse than the confusion it fixes. + """ + event = db.execute( + "SELECT relationship_id, execution_generation FROM events WHERE event_id = ?", + (event_id,), + ).fetchone() + if event is None: + return + others = db.execute( + "SELECT d.event_id FROM deliveries d" + " JOIN events e ON e.event_id = d.event_id" + " WHERE e.relationship_id = ? AND e.execution_generation = ?" + " AND d.event_id != ?" + # inbox_only is terminal and attempt() cannot revisit it, so a predecessor that + # settled there would stay reported as channel_closed with no supersession note + # even though acknowledgement currency already rejects it. + # A predecessor capped in deferred_busy or withheld_pre_send is in the same + # position: its hold makes attempt() return early, so this is its only chance. + # queued belongs with them: _claim does suppress a stale queued predecessor, but + # attempt() returns before _claim for a rate limit, a busy recipient or unreadable + # settings - and a recipient that is never free means _claim is never reached at + # all, so the predecessor keeps retrying and keeps reporting as current. + " AND d.state IN ('queued','sending','held_uncertain','dispatched','inbox_only'," + " 'deferred_busy','withheld_pre_send')", + (event["relationship_id"], event["execution_generation"], event_id), + ).fetchall() + for row in others: + # Asked per candidate rather than assumed: the successor may not in fact replace + # it, and _supersession_reason is the one place that rule lives. + reason = self._supersession_reason(db, row["event_id"]) + if reason: + self._annotate_supersession_in(db, row["event_id"], reason) + + def annotate_predecessors(self, event_id: str) -> None: + """The same annotation in its own transaction, for a caller that has none.""" + with self.store.transaction() as db: + self.annotate_predecessors_in(db, event_id) # -------------------------------------------------------- observability @@ -687,7 +1255,7 @@ def snapshot(self, *, relationship_id=None) -> dict: for row in rows: attempts = self.store.all( "SELECT request_id, attempt_no, internal_state, state, affirmative_evidence," - " operation_observation, recipient_scan FROM attempts WHERE event_id = ?" + " operation_observation, recipient_scan, record FROM attempts WHERE event_id = ?" " ORDER BY attempt_no", (row["event_id"],), ) @@ -695,6 +1263,8 @@ def snapshot(self, *, relationship_id=None) -> dict: verdict = self.store.one( "SELECT verdict FROM verdicts WHERE event_id = ?", (row["event_id"],) ) + failure = self._last_failure(row["event_id"]) + superseded = self._supersession_note(row["event_id"]) items.append({ "eventId": row["event_id"], "kind": row["kind"], @@ -709,8 +1279,31 @@ def snapshot(self, *, relationship_id=None) -> dict: "ackVerified": ack["verified"] if ack else None, "verdict": verdict["verdict"] if verdict else None, "attemptDetail": [dict(a) for a in attempts], + "phase": _phase(row, attempts, ack, failure, superseded), + "lastFailedOperation": failure, + "nextRetryAt": row["next_eligible_at"], + "supersededNote": superseded, }) - return {"deliveries": items} + # Events whose delivery was wanted and refused have no deliveries row at all, so a + # permanently paused or unauthorized assignment had no status entry, no phase and no + # retry time while the daemon went on retrying it. The most stuck state in the system + # was the one status could not show. + intents = [ + {"eventId": row["event_id"], "relationshipId": row["relationship_id"], + "kind": row["kind"], "recipient": row["recipient_task_id"], + "phase": "refused_pre_queue", "attempts": row["attempts"], + "nextRetryAt": row["next_retry_at"], "lastError": row["last_error"], + "notedAt": row["noted_at"]} + for row in self.store.all( + "SELECT i.* FROM delivery_intent i" + " LEFT JOIN deliveries d ON d.event_id = i.event_id" + " WHERE d.event_id IS NULL" + + (" AND i.relationship_id = ?" if relationship_id else "") + + " ORDER BY i.noted_at", + (relationship_id,) if relationship_id else (), + ) + ] + return {"deliveries": items, "pendingIntents": intents} def _message_status(row, record) -> str: @@ -764,6 +1357,36 @@ class _NotClaimable(Exception): pass +def _render_findings(findings): + """The exact fields the host disagreed on, not just that it disagreed.""" + if not findings: + return None + parts = [] + for finding in findings: + if not isinstance(finding, dict): + continue + field = finding.get("field", finding.get("code", "?")) + parts.append(f"{field}: expected {finding.get('expected')!r}," + f" host {finding.get('returned')!r}") + return "; ".join(parts) or None + + +class _LateSupersession(Exception): + """Discovered inside the claim, after the pre-claim check had already passed.""" + + def __init__(self, reason): + super().__init__(reason) + self.reason = reason + + +class _Superseded(Exception): + """This delivery is no longer current, decided inside the claim.""" + + def __init__(self, reason): + super().__init__(reason) + self.reason = reason + + def _manifest_paths(event_row): """The declared paths a receipt carries, or none. The manifest lives inside the receipt JSON rather than in a column of its own.""" @@ -778,3 +1401,90 @@ def _manifest_paths(event_row): entry["path"] for entry in entries if isinstance(entry, dict) and isinstance(entry.get("path"), str) ) + + + +def _phase(row, attempts, ack, failure=None, superseded=None) -> str: + """Which stage a delivery is actually at, without inventing certainty. + + withheld_pre_send used to mean five different things at once, and the cause is the only + part that suggests an action. But the cure must not overclaim either: held_uncertain + means the transport gave no usable answer, which is NOT the same as a turn having been + accepted, and a settled withheld_pre_send can be an ordinary thread/read failure rather + than a settings mismatch. Both are read from the attempt record, not from the state word. + """ + if ack is not None and ack["verified"] == "verified": + # A verified REJECTION is just as settled as a verified acceptance: the receipt was + # delivered and the parent answered. Recognising only the accepted case let a + # rejection fall past every later branch to awaiting_receipt, which says the child + # has produced nothing - the opposite of what happened. + if ack["accepted"]: + return "acknowledged" + return "rejected" + if row["state"] == SUPERSEDED: + return "superseded" + if superseded is not None: + # An outstanding send that a newer generation or revision has replaced. Its state is + # deliberately left alone so a lost response stays reconcilable, but reporting it as + # awaiting_ack or outcome_unknown describes an obligation nothing can now meet. + return f"superseded:{superseded['reason']}" + if row["state"] == INBOX_ONLY or row["hold_reason"] == PUSH_CHANNEL_CLOSED: + return "channel_closed" + if row["state"] == DISPATCHED: + # Only the child-to-parent direction has an acknowledgement in contract v1. A + # revision request is answered by the child's next completion receipt, and + # AckService refuses to acknowledge one, so calling this awaiting_ack left every + # dispatched revision looking permanently stuck on an obligation nothing can meet. + if row["kind"] == REVISION: + return "awaiting_child_receipt" + return "awaiting_ack" + if row["state"] == DEFERRED_BUSY: + return "parent_busy" + settled = [a for a in attempts if a["internal_state"] == "settled"] + latest = settled[-1] if settled else None + operation = latest["operation_observation"] if latest else None + record = {} + if latest is not None and latest["record"]: + try: + record = json.loads(latest["record"]) + except ValueError: + record = {} + failed = record.get("failedOperation") + if row["state"] == HELD_UNCERTAIN: + # A turn id is the only affirmative evidence that a turn exists. A failed turn/start + # with no id means the call was REFUSED, not that its answer was lost, and reporting + # turn_accepted for it claimed a turn on no evidence at all. + if record.get("turnId"): + return "turn_accepted" + return "outcome_unknown" + if row["state"] == WITHHELD_PRE_SEND and latest is not None: + # thread/resume fails for ordinary connectivity and internal reasons too, and the + # generic branch records the same operation for all of them. Naming those a settings + # rejection hands an operator a remediation that cannot work. + # The recorded failure is the discriminator: _settle writes settings_check only when + # the receipt actually carried field-level findings. + if failed == "thread/resume" and failure is not None \ + and failure["operation"] == "settings_check": + return "settings_rejected" + if failed: + return f"withheld:{failed}" + return "withheld_pre_send" + if row["state"] == WITHHELD_PRE_SEND: + # Refused before any attempt existed - missing or unusable authorized settings - so + # there is no attempt record to read the cause from. The persisted failure is. + if failure is not None: + return f"withheld:{failure['operation']}" + return "withheld_pre_send" + if row["hold_reason"]: + return f"held:{row['hold_reason']}" + del operation + if row["state"] == SENDING: + # The claim committed and the process stopped, or is stopping. There IS an attempt, + # and it may already need reconciliation, so awaiting_receipt would point at the + # child when the open question is about a send this relay made. + return "in_flight" + if row["state"] == QUEUED: + # A delivery row exists, so the receipt was already collected and accepted. What is + # outstanding is this relay reaching the recipient, not the child producing anything. + return "awaiting_send" + return "awaiting_receipt" diff --git a/packages/codex-session-relay/src/codex_session_relay/policy.py b/packages/codex-session-relay/src/codex_session_relay/policy.py index 329caaf..4e65537 100644 --- a/packages/codex-session-relay/src/codex_session_relay/policy.py +++ b/packages/codex-session-relay/src/codex_session_relay/policy.py @@ -29,6 +29,11 @@ class RetryPolicy: poll_interval_seconds: float = 20.0 max_sends_per_tick: int = 4 max_reconciles_per_tick: int = 8 + # Turn reads are the scarce thing in an observation pass, so they are capped directly + # rather than implied by a per-relationship slice that grows with the relationship count. + max_turn_reads_per_tick: int = 8 + min_relationship_share: int = 2 + max_sends_per_parent_per_tick: int = 2 # Supervision cadence. A worker is bounded by segment_seconds; the supervisor replaces it, # which is what carries an assignment past any single process lifetime. segment_seconds: float = 3600.0 diff --git a/packages/codex-session-relay/src/codex_session_relay/receipts.py b/packages/codex-session-relay/src/codex_session_relay/receipts.py index a2a6dca..62e3a33 100644 --- a/packages/codex-session-relay/src/codex_session_relay/receipts.py +++ b/packages/codex-session-relay/src/codex_session_relay/receipts.py @@ -491,6 +491,12 @@ def _store_event(self, payload: dict, event: str, binding_mode, self.store.journal("event_reobserved", event, at=now) stored = json.loads(existing["receipt"]) stored["_duplicate"] = True + # The stage travels with it. Without it a retry of a receipt whose first enqueue + # failed takes this path reporting no stage at all, so the caller's "if this is + # final, enqueue it" never runs and an accepted final event stays permanently + # without a delivery row - which is the one state nothing else recovers from, + # because the requeue pass looks for events that HAVE a recorded intent. + stored["_stage"] = existing["stage"] return stored record = dict(payload) record["eventId"] = event @@ -536,7 +542,7 @@ def _store_event(self, payload: dict, event: str, binding_mode, # ------------------------------------------------------------- staging - def staged_events(self, *, thread_id=None, turn_id=None): + def staged_events(self, *, thread_id=None, turn_id=None, relationship_id=None): sql = "SELECT * FROM events WHERE stage = ?" params = [STAGED] if thread_id is not None: @@ -545,6 +551,12 @@ def staged_events(self, *, thread_id=None, turn_id=None): if turn_id is not None: sql += " AND turn_id = ?" params.append(turn_id) + if relationship_id is not None: + # A child thread can serve several assignments, so a staged claim on one of its + # turns belongs to exactly one of them. Asking by thread alone hands another + # assignment's work to whoever polls first. + sql += " AND relationship_id = ?" + params.append(relationship_id) return self.store.all(sql + " ORDER BY first_seen_at", tuple(params)) def resolve_staged(self, turn: TurnRef) -> dict: @@ -558,12 +570,35 @@ def resolve_staged(self, turn: TurnRef) -> dict: """ if turn.turn_status not in TERMINAL: return {"finalized": [], "suppressed": [], "pending": True} - finalized, suppressed = [], [] - now = self.clock.iso() rows = self.staged_events(thread_id=turn.thread_id, turn_id=turn.turn_id) if not rows: return {"finalized": [], "suppressed": [], "pending": False} with self.store.transaction() as db: + return self.resolve_staged_in(db, turn) + + def resolve_staged_in(self, db, turn: TurnRef, relationship_id=None) -> dict: + """The same settlement inside a caller's transaction. + + Exists so that finalizing a claim, recording the observation that finalized it, and + queuing what it produced can be ONE commit. Split across three, a failure in the third + leaves a final event nobody will ever look at again. + + Scoped to one assignment when the caller names it. A turn belonging to a shared child + can carry claims from several assignments, and settling all of them on behalf of + whichever one happened to poll first suppressed the others without ever synthesizing + their receipts - so their parents waited on an outcome that had already been thrown + away. Each assignment settles its own. + """ + if turn.turn_status not in TERMINAL: + return {"finalized": [], "suppressed": [], "pending": True} + finalized, suppressed = [], [] + now = self.clock.iso() + rows = self.staged_events( + thread_id=turn.thread_id, turn_id=turn.turn_id, relationship_id=relationship_id, + ) + if not rows: + return {"finalized": [], "suppressed": [], "pending": False} + if True: for row in rows: if turn.turn_status == "completed": db.execute( @@ -631,16 +666,31 @@ def daemon_observation(self, relationship_id: str, turn: TurnRef) -> dict: def record_observation(self, turn: TurnRef, classification, *, relationship_id=None, event=None): """The daemon's own key, (thread, turn, terminal status), deduplicating its stream.""" - now = self.clock.iso() with self.store.transaction() as db: + self.record_observation_in( + db, turn, classification, relationship_id=relationship_id, event=event, + ) + + def record_observation_in(self, db, turn: TurnRef, classification, *, relationship_id=None, + event=None): + now = self.clock.iso() + db.execute( + "INSERT OR IGNORE INTO observations (thread_id, turn_id, terminal_status," + " relationship_id, classification, event_id, observed_at) VALUES (?,?,?,?,?,?,?)", + ( + turn.thread_id, turn.turn_id, turn.turn_status, relationship_id, + classification.value if hasattr(classification, "value") else str(classification), + event, now, + ), + ) + if relationship_id is not None: + # observations is keyed by the turn alone, so the row above belongs to whichever + # assignment settled it first. This is the per-assignment fact, and it is what + # the scheduler and the health block ask. db.execute( - "INSERT OR IGNORE INTO observations (thread_id, turn_id, terminal_status," - " relationship_id, classification, event_id, observed_at) VALUES (?,?,?,?,?,?,?)", - ( - turn.thread_id, turn.turn_id, turn.turn_status, relationship_id, - classification.value if hasattr(classification, "value") else str(classification), - event, now, - ), + "INSERT OR IGNORE INTO assignment_settlements (relationship_id, thread_id," + " turn_id, terminal_status, settled_at) VALUES (?,?,?,?,?)", + (relationship_id, turn.thread_id, turn.turn_id, turn.turn_status, now), ) diff --git a/packages/codex-session-relay/src/codex_session_relay/reconcile.py b/packages/codex-session-relay/src/codex_session_relay/reconcile.py index 76e93d7..8dd4673 100644 --- a/packages/codex-session-relay/src/codex_session_relay/reconcile.py +++ b/packages/codex-session-relay/src/codex_session_relay/reconcile.py @@ -12,7 +12,7 @@ import json from enum import Enum -from .delivery import COMPLETION, SENDING +from .delivery import COMPLETION, REVISION, SENDING from .transport import ( DEFERRED_BUSY, DISPATCHED, @@ -26,6 +26,17 @@ SCAN_LIMIT = 200 +def _with_anchor(outcome: dict, anchor) -> dict: + """Carry the binding outcome out with the settlement, so a conflict is not only journalled. + + Absent when there was nothing to bind, which is every completion and every settlement that + promoted nothing. + """ + if anchor is not None: + outcome["anchor"] = anchor + return outcome + + class Evidence(str, Enum): TURN_FOUND = "turn_found" RECEIPT_TURN_ID = "receipt_turn_id" @@ -41,15 +52,67 @@ def __init__(self, store, registry, delivery, clock, *, policy=None): self.clock = clock self.policy = policy or delivery.policy - def open_attempts(self) -> list: - """Everything a restart has to look at: in-flight sends and unresolved attempts.""" - return self.store.all( - "SELECT a.* FROM attempts a JOIN deliveries d ON d.event_id = a.event_id" - " WHERE a.internal_state = 'in_flight'" - " OR (a.state = ? AND d.state IN (?, ?))" - " ORDER BY a.observed_at", + UNRESOLVED = ( + " WHERE (a.internal_state = 'in_flight'" + " OR (a.state = ? AND d.state IN (?, ?)))" + ) + + def open_attempts(self, *, limit=None, parents=None, offset=0) -> list: + """Everything a restart has to look at: in-flight sends and unresolved attempts. + + With no arguments this stays exhaustive, because recover_on_start has to see all of + it. The bounded, parent-filtered form is what a tick uses, so one parent's backlog of + unchanged attempts cannot hide another parent's actionable one. Deliberately NOT + filtered on active status: an unresolved send belonging to a cancelled assignment + still needs its evidence settled. + + offset is what keeps the bounded form from being a fixed prefix. Attempts whose + fingerprint has not changed are skipped by the caller's gate but still occupy their + place, so without it a parent with more unresolved attempts than its share would + re-read the same leading ones on every tick and never reach the rest. + """ + sql = ( + "SELECT a.*, r.parent_task_id AS parent_task_id FROM attempts a" + " JOIN deliveries d ON d.event_id = a.event_id" + " JOIN relationships r ON r.relationship_id = d.relationship_id" + + self.UNRESOLVED + ) + params = [HELD_UNCERTAIN, HELD_UNCERTAIN, SENDING] + if parents: + sql += " AND r.parent_task_id IN (" + ",".join("?" * len(parents)) + ")" + params.extend(parents) + sql += " ORDER BY a.observed_at" + if limit is not None: + sql += " LIMIT ?" + params.append(limit) + if offset: + sql += " OFFSET ?" + params.append(offset) + return self.store.all(sql, tuple(params)) + + def open_attempt_count(self, parent) -> int: + """How many unresolved attempts one parent has, so a cursor over them can wrap.""" + row = self.store.one( + "SELECT COUNT(*) AS c FROM attempts a" + " JOIN deliveries d ON d.event_id = a.event_id" + " JOIN relationships r ON r.relationship_id = d.relationship_id" + + self.UNRESOLVED + + " AND r.parent_task_id = ?", + (HELD_UNCERTAIN, HELD_UNCERTAIN, SENDING, parent), + ) + return row["c"] if row else 0 + + def open_parents(self) -> list: + """Which parents have unresolved work, independent of how much each of them has.""" + rows = self.store.all( + "SELECT DISTINCT r.parent_task_id AS parent_task_id FROM attempts a" + " JOIN deliveries d ON d.event_id = a.event_id" + " JOIN relationships r ON r.relationship_id = d.relationship_id" + + self.UNRESOLVED + + " ORDER BY r.parent_task_id", (HELD_UNCERTAIN, HELD_UNCERTAIN, SENDING), ) + return [row["parent_task_id"] for row in rows] def reconcile_attempt(self, request_id: str, adapter, *, now=None) -> dict: now = self.clock.now() if now is None else now @@ -136,13 +199,16 @@ def _settle_from_receipt(self, attempt, delivery, facts, evidence, observation, if attempt["attempt_no"] >= self.policy.cap_for(reason): hold = self.policy.cap_reason(reason) next_eligible = None - self._write( + anchor = self._write( attempt, delivery, record, facts.delivery_state, evidence, observation, "not scanned", next_eligible, hold=hold, dispatch_evidence="transport_accepted" if facts.delivery_state == DISPATCHED else None, dispatch_turn_id=facts.turn_id, ) - return {"evidence": evidence.value, "state": facts.delivery_state, "record": record} + return _with_anchor( + {"evidence": evidence.value, "state": facts.delivery_state, "record": record}, + anchor, + ) def _settle_from_scan(self, attempt, delivery, scan, observation, scan_detail, now) -> dict: """The token is in the recipient's items, but the transport never confirmed. @@ -161,12 +227,15 @@ def _settle_from_scan(self, attempt, delivery, scan, observation, scan_detail, n "affirmativeEvidence": Evidence.TURN_FOUND.value, "checkedAt": self.clock.iso(), } - self._write( + anchor = self._write( attempt, delivery, record, record["deliveryState"], Evidence.TURN_FOUND, observation, scan_detail, None, aggregate=DISPATCHED, dispatch_evidence="turn_found", dispatch_turn_id=scan.turn_id, ) - return {"evidence": Evidence.TURN_FOUND.value, "state": DISPATCHED, "record": record} + return _with_anchor( + {"evidence": Evidence.TURN_FOUND.value, "state": DISPATCHED, "record": record}, + anchor, + ) def _stay_held(self, attempt, delivery, observation, scan_detail, now) -> dict: record = json.loads(attempt["record"]) if attempt["record"] else _unfinished_record( @@ -199,6 +268,7 @@ def _write(self, attempt, delivery, record, state, evidence, observation, scan_d hold=None): now_iso = self.clock.iso() current = self._is_current(attempt, delivery) + anchor = None with self.store.transaction() as db: db.execute( "UPDATE attempts SET internal_state = 'settled', state = ?, record = ?," @@ -210,7 +280,7 @@ def _write(self, attempt, delivery, record, state, evidence, observation, scan_d ), ) if current: - db.execute( + promoted = db.execute( "UPDATE deliveries SET state = ?, next_eligible_at = ?, hold_reason = ?," " dispatch_evidence = ?," " dispatch_turn_id = COALESCE(?, dispatch_turn_id), lease_owner = NULL," @@ -221,11 +291,47 @@ def _write(self, attempt, delivery, record, state, evidence, observation, scan_d dispatch_evidence or delivery["dispatch_evidence"], dispatch_turn_id, now_iso, attempt["event_id"], attempt["attempt_no"], DISPATCHED, ), - ) + ).rowcount + # The guarded UPDATE is the authoritative race check, not the snapshot + # _is_current read before this transaction opened. If another worker settled + # this delivery and dispatched a later attempt in between, it matches no rows + # - and binding there would hand the generation the obsolete attempt's turn, + # after which the turn the real dispatch reached can never bind. + if promoted == 1 and (aggregate or state) == DISPATCHED: + anchor = self._bind_promoted_anchor(db, attempt, delivery, dispatch_turn_id) self.store.journal( "reconciled", attempt["request_id"], {"evidence": evidence.value, "state": aggregate or state}, at=now_iso, ) + return anchor + + def _bind_promoted_anchor(self, db, attempt, delivery, dispatch_turn_id): + """Bind the revision's generation in the transaction that just promoted it. + + Reconciliation is one of the routes that reaches dispatched without going through the + daemon's own dispatch, and the tick's repair pass runs in a DIFFERENT transaction. A + child in a third process that emits between the two commits has its completion refused + as unbound_generation even though the dispatch evidence is already durable. The turn id + arrived with the receipt or the recipient scan, before this transaction opened, so + closing that interval costs nothing. + + Only a revision anchors a generation, which is the same condition the repair pass uses. + """ + if delivery["kind"] != REVISION: + return None + turn_id = dispatch_turn_id or delivery["dispatch_turn_id"] + if not turn_id: + return None + event = db.execute( + "SELECT relationship_id, execution_generation FROM events WHERE event_id = ?", + (attempt["event_id"],), + ).fetchone() + if event is None: + return None + return self.registry.bind_anchor_in( + db, event["relationship_id"], event["execution_generation"], + dispatch_turn_id=turn_id, source="dispatch_receipt", + ) # ---------------------------------------------------------------- restart diff --git a/packages/codex-session-relay/src/codex_session_relay/registry.py b/packages/codex-session-relay/src/codex_session_relay/registry.py index 43a003f..916cb3f 100644 --- a/packages/codex-session-relay/src/codex_session_relay/registry.py +++ b/packages/codex-session-relay/src/codex_session_relay/registry.py @@ -250,6 +250,38 @@ def open_generation_in(self, db, rid, *, dispatch_request_id, reason, dispatch_t (number, now, rid), ) self.store.journal("generation_opened", rid, {"generation": number, "reason": reason}, at=now) + # Anything still outstanding for an earlier generation is history from this moment on. + # It is ANNOTATED, never rewritten: a send whose response was lost still has to be + # reconciled, and a terminal superseded aggregate cannot be. Without this a delivery + # that was sending or held_uncertain when the generation advanced reconciled to + # dispatched with no note at all, and status presented it as an ordinary current one. + db.execute( + "INSERT INTO delivery_supersession (event_id, reason, noted_at, applied)" + " SELECT d.event_id, 'stale_generation', ?, 0 FROM deliveries d" + " JOIN events e ON e.event_id = d.event_id" + " WHERE d.relationship_id = ? AND e.execution_generation < ?" + # dispatched belongs here too: its acknowledgement will be refused as + # stale_generation, so leaving it unannotated meant status showed awaiting_ack + # for an obligation that can no longer be met. Annotating does not rewrite the + # delivery, so the history of what was actually sent is untouched. + # deferred_busy and withheld_pre_send belong here for a stronger reason: once + # either has reached its attempt cap, hold_reason is set and attempt() returns + # before the pre-send supersession check, so generation advance is the ONLY + # occasion on which they can ever be annotated. Without them a capped delivery + # reports a current-looking cap forever. + # inbox_only belongs with them: it is terminal, attempt() cannot revisit it, and + # its acknowledgement is refused as stale - so without this it reports + # channel_closed as though it were still current. + # queued belongs here for a reason of the same shape: _claim does suppress a stale + # queued row, but attempt() can return BEFORE _claim - rate limiting, a busy + # recipient, an unavailable host - and a recipient that is never free means _claim + # is never reached at all. Generation advance already knows the row is stale, so + # leaving it unannotated let it keep retrying while reporting as current. + " AND d.state IN ('queued','sending','held_uncertain','dispatched'," + " 'deferred_busy','withheld_pre_send','inbox_only')" + " ON CONFLICT(event_id) DO NOTHING", + (now, rid, number), + ) return number def bind_anchor(self, rid: str, number: int, *, dispatch_turn_id: str, source: str) -> dict: @@ -285,6 +317,60 @@ def bind_anchor(self, rid: str, number: int, *, dispatch_turn_id: str, source: s self.store.journal("anchor_bound", rid, {"generation": number}, at=now) return self.generation(rid, number) + def bind_anchor_in(self, db, rid: str, number: int, *, dispatch_turn_id, source) -> str: + """The same binding, against a transaction the caller already owns. + + This exists for the writer that PROMOTES a revision to dispatched. Binding in a + separate transaction afterwards leaves an interval in which the dispatch evidence is + durable and the generation is still anchor_pending, and a child emitting from another + process inside that interval has a perfectly valid completion refused as + unbound_generation. Nothing about the binding needs a transport call - the turn id is + already in hand before the transaction opens - so there is no reason for it to travel + separately. + + It returns an outcome instead of raising, because raising here would roll back the + promotion it travelled with over a disagreement about a DIFFERENT fact: + + bound the generation was pending and now names this turn + unchanged it already names this turn + conflict it names another turn, and is left exactly as it is + ineligible nothing to bind from, or no such generation + + A conflict is journalled HERE rather than left for the repair pass. That pass selects + anchor_pending generations only, so a generation that is already bound is never + looked at again and the disagreement would simply disappear. + """ + if source != "dispatch_receipt" or validated_turn_id(dispatch_turn_id) is None: + return "ineligible" + # Read INSIDE the caller's transaction, so the decision and the write cannot be + # separated by another writer, and so the outcome comes from the row rather than from + # an update count. + current = db.execute( + "SELECT anchor_state, dispatch_turn_id FROM generations" + " WHERE relationship_id = ? AND execution_generation = ?", + (rid, number), + ).fetchone() + if current is None: + return "ineligible" + now = self.clock.iso() + if current["anchor_state"] == ANCHOR_BOUND: + if current["dispatch_turn_id"] == dispatch_turn_id: + return "unchanged" + self.store.journal( + "anchor_conflict", rid, + {"generation": number, "boundTo": current["dispatch_turn_id"], + "offered": dispatch_turn_id}, + at=now, + ) + return "conflict" + db.execute( + "UPDATE generations SET anchor_state = ?, dispatch_turn_id = ?, bound_at = ?" + " WHERE relationship_id = ? AND execution_generation = ?", + (ANCHOR_BOUND, dispatch_turn_id, now, rid, number), + ) + self.store.journal("anchor_bound", rid, {"generation": number}, at=now) + return "bound" + def set_status(self, rid: str, status: str, *, actor: str) -> dict: """Deactivation only. diff --git a/packages/codex-session-relay/src/codex_session_relay/store.py b/packages/codex-session-relay/src/codex_session_relay/store.py index 16d95c7..b6d6cd4 100644 --- a/packages/codex-session-relay/src/codex_session_relay/store.py +++ b/packages/codex-session-relay/src/codex_session_relay/store.py @@ -98,6 +98,20 @@ PRIMARY KEY (thread_id, turn_id, terminal_status) ); +-- Which ASSIGNMENT has settled a turn, which observations cannot answer: its key is the +-- turn alone, so when two assignments share a child turn only the first records a row and +-- every other one looks permanently unsettled. Kept as a separate table rather than by +-- re-keying observations, because this store has no migration path and an existing database +-- would silently keep the old key. New databases and old ones both gain this on open. +CREATE TABLE IF NOT EXISTS assignment_settlements ( + relationship_id TEXT NOT NULL, + thread_id TEXT NOT NULL, + turn_id TEXT NOT NULL, + terminal_status TEXT NOT NULL, + settled_at TEXT NOT NULL, + PRIMARY KEY (relationship_id, thread_id, turn_id, terminal_status) +); + CREATE TABLE IF NOT EXISTS refusals ( id INTEGER PRIMARY KEY AUTOINCREMENT, at TEXT NOT NULL, @@ -468,7 +482,66 @@ written_at TEXT NOT NULL ); +-- Delivery was WANTED for this event and refused for a reason that may not last. Absence of +-- a delivery row cannot carry that meaning: an event emitted with --no-enqueue and an event +-- stranded by an old generation look identical to one whose queuing was refused. +CREATE TABLE IF NOT EXISTS delivery_intent ( + event_id TEXT PRIMARY KEY, + relationship_id TEXT NOT NULL, + kind TEXT NOT NULL, + recipient_task_id TEXT NOT NULL, + attempts INTEGER NOT NULL DEFAULT 0, + next_retry_at REAL, + last_error TEXT, + noted_at TEXT NOT NULL +); + +-- This delivery is no longer what the assignment stands on. Kept separate from the delivery +-- state on purpose: an outstanding send must keep its state so reconciliation can still +-- settle it, and an already dispatched one must keep its history. +CREATE TABLE IF NOT EXISTS delivery_supersession ( + event_id TEXT PRIMARY KEY, + reason TEXT NOT NULL, + noted_at TEXT NOT NULL, + applied INTEGER NOT NULL DEFAULT 0 +); + +-- The most recent failure per (subject, operation), so an operator reads a cause rather +-- than a state word. Keyed, not appended, so it cannot grow without bound. +CREATE TABLE IF NOT EXISTS failed_operations ( + scope_key TEXT NOT NULL, + operation TEXT NOT NULL, + relationship_id TEXT, + parent_task_id TEXT, + detail TEXT NOT NULL, + error_code TEXT, + difference TEXT, + retry_safe INTEGER, + occurred_at TEXT NOT NULL, + next_retry_at REAL, + PRIMARY KEY (scope_key, operation) +); + +-- Whether we have actually LOOKED at an anchor lately, which an observations row cannot +-- answer: that table records terminal turns only, so a healthy long-running anchor has no +-- entry at all. last_polled_at stays NULL until a poll genuinely succeeds. +CREATE TABLE IF NOT EXISTS poll_observations ( + relationship_id TEXT NOT NULL, + execution_generation INTEGER NOT NULL, + turn_id TEXT NOT NULL, + last_status TEXT, + last_polled_at TEXT, + last_attempt_at TEXT NOT NULL, + last_error TEXT, + PRIMARY KEY (relationship_id, execution_generation, turn_id) +); + CREATE INDEX IF NOT EXISTS deliveries_state ON deliveries (state, next_eligible_at); +-- Per-parent selection reads one parent's oldest eligible rows at a time, which is a +-- different access pattern from deliveries_state. Declaring it is not proof it is used: +-- the query plan is inspected in the fairness tests rather than assumed. +CREATE INDEX IF NOT EXISTS deliveries_relationship_created ON deliveries + (relationship_id, created_at); CREATE INDEX IF NOT EXISTS attempts_open ON attempts (internal_state); CREATE INDEX IF NOT EXISTS events_relationship ON events (relationship_id, execution_generation); CREATE INDEX IF NOT EXISTS events_stage ON events (stage, turn_id); @@ -733,6 +806,19 @@ def __init__(self, path, socket_path=None): self.db.execute( "INSERT OR IGNORE INTO schema_meta VALUES ('store_created_at', ?)", (_now_iso(),) ) + # An existing store already holds terminal observations, and the scheduler and the + # health block ask assignment_settlements instead. Leaving it empty on upgrade would + # make every historical turn look unsettled, so a current turn that can no longer be + # read would leave a previously settled assignment stalled forever and spending + # polling budget. Backfilled from the rows that name their relationship; rows written + # before that column existed name nobody and cannot be attributed to one. + self.db.execute( + "INSERT OR IGNORE INTO assignment_settlements (relationship_id, thread_id," + " turn_id, terminal_status, settled_at)" + " SELECT relationship_id, thread_id, turn_id, terminal_status, observed_at" + " FROM observations WHERE relationship_id IS NOT NULL" + ) + if socket_path: # Provenance, so this store is findable by the socket it serves rather than only # by the hash of whichever spelling created it. INSERT OR IGNORE: the first diff --git a/packages/codex-session-relay/tests/test_anchor_binding.py b/packages/codex-session-relay/tests/test_anchor_binding.py new file mode 100644 index 0000000..fd340cb --- /dev/null +++ b/packages/codex-session-relay/tests/test_anchor_binding.py @@ -0,0 +1,376 @@ +"""JUN-167 P1: an anchor must bind on EVERY route to dispatched, not just one. + +The only automatic binding hook ran after the daemon's new-dispatch branch. A revision that +reached dispatched any other way - the deliver command, either reconcile promotion, a dispatch +committed in the last tick before shutdown - left its generation anchor_pending, and by I-06 +every later receipt for that generation was refused as unbound. + +The existing suite missed it because its one binding test calls bind_dispatched_revision by +hand (test_ack_reconcile.py). These tests never help the code along. +""" + +from unittest import mock + +from codex_session_relay import identity +from codex_session_relay.delivery import REVISION +from codex_session_relay.errors import RefusalReason +from codex_session_relay.registry import ANCHOR_PENDING +from codex_session_relay.transport import HELD_UNCERTAIN + +from .support import CHILD, PARENT, DeliveryTestCase +from .test_daemon import DaemonTestCase + + +class AnchorBinding(DeliveryTestCase): + def revision_pending(self): + """Acknowledge a completion, record needs_changes, and return the queued revision.""" + _relationship, event_id = self.queued_event(recipients=[PARENT, CHILD]) + self.attempt(event_id) + self.clock.advance(5) + turn = self.adapter.start_turn(PARENT, turn_id="ack-turn", status="inProgress") + self.ack.acknowledge( + event_id, ack_turn_id=turn.turn_id, + ack_proof=identity.ack_proof(event_id, turn.turn_id), accepted=True, + adapter=self.adapter, + ) + self.ack.record_verdict(event_id, verdict="needs_changes", verdict_turn_id="verdict-1") + revision = self.store.one("SELECT * FROM deliveries WHERE kind = ?", (REVISION,)) + return revision["event_id"] + + def generation_two(self): + return self.registry.generation(self._rid, 2) + + def child_receipt_for_generation_two(self): + """What the child sends next. Under an unbound anchor it is refused (I-06).""" + relationship = self.registry.get(self._rid) + path = self.artifact("fixed.txt", "the correction") + anchor = self.generation_two()["dispatchTurnId"] + turn = self.assigned_turn(thread=CHILD, turn=anchor or "turn-unbound") + payload = self.ready_payload(relationship, [path], generation=2, turn=turn) + return self.accept(payload) + + def daemon(self): + from codex_session_relay.daemon import RelayDaemon + + return RelayDaemon( + self.store, self.registry, self.intake, self.delivery, self.ack, + self.reconciler, self.adapter, clock=self.clock, + ) + + def test_a_later_tick_binds_an_anchor_an_earlier_send_left_pending(self): + """The defect itself, through real entry points and with no test-side binding. + + The revision is dispatched by the deliver path. A daemon tick afterwards finds nothing + eligible to send - it is already dispatched - so on the unfixed source its only + binding hook never runs, the generation stays anchor_pending, and the child's next + receipt is refused as unbound. + """ + revision = self.revision_pending() + self.clock.advance(3600) + record = self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.assertEqual(record["deliveryState"], "dispatched") + self.assertEqual(self.generation_two()["anchorState"], ANCHOR_PENDING) + + self.daemon().tick(now=self.clock.now()) + + self.assertNotEqual( + self.generation_two()["anchorState"], ANCHOR_PENDING, + "a tick left a dispatched revision's generation unbound, so every receipt for it" + " is refused", + ) + accepted = self.child_receipt_for_generation_two() + self.assertEqual(accepted["executionGeneration"], 2) + + def test_an_unbound_generation_really_does_refuse_the_childs_receipt(self): + """Why the binding matters: I-06 is what turns a pending anchor into lost work.""" + revision = self.revision_pending() + self.clock.advance(3600) + self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.assertEqual(self.generation_two()["anchorState"], ANCHOR_PENDING) + self.assertRefused( + RefusalReason.UNBOUND_GENERATION, self.child_receipt_for_generation_two, + ) + + def test_the_recovery_binds_a_dispatched_revision(self): + """The helper itself. Route integration is proved by the tick test above, which + calls nothing but tick.""" + revision = self.revision_pending() + self.clock.advance(3600) + record = self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.assertEqual(record["deliveryState"], "dispatched") + + self.ack.bind_pending_anchors() + + generation = self.generation_two() + self.assertNotEqual( + generation["anchorState"], ANCHOR_PENDING, + "a dispatched revision left its generation unbound, so every later receipt for it" + " is refused as unbound", + ) + self.assertEqual(generation["dispatchTurnId"], record["turnId"]) + accepted = self.child_receipt_for_generation_two() + self.assertEqual(accepted["executionGeneration"], 2) + + def test_a_reconcile_promotion_binds_the_anchor_too(self): + revision = self.revision_pending() + self.clock.advance(3600) + # The response is lost, so the send settles uncertain and only reconciliation can + # later establish that it actually reached a turn. + self.adapter.script("transport_unknown") + record = self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.assertEqual(record["deliveryState"], HELD_UNCERTAIN) + self.assertEqual(self.generation_two()["anchorState"], ANCHOR_PENDING) + + promoted = self.reconciler.recover_on_start(self.adapter) + self.assertTrue(promoted["reconciled"]) + self.ack.bind_pending_anchors() + + delivery = self.delivery.get(revision) + if delivery["state"] == "dispatched": + self.assertNotEqual(self.generation_two()["anchorState"], ANCHOR_PENDING) + + def lost_settle_write(self): + """A revision the transport really accepted, whose settle write was lost. + + The same shape RestartRecovery uses: the send is held uncertain, and only re-reading + the operation receipt establishes afterwards that it reached a turn. + """ + revision = self.revision_pending() + self.clock.advance(3600) + self.adapter.script("in_progress") + record = self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.assertEqual(record["deliveryState"], HELD_UNCERTAIN) + self.assertEqual(self.generation_two()["anchorState"], ANCHOR_PENDING) + turn = self.adapter.start_turn(CHILD, status="inProgress") + self.adapter.ledger[record["requestId"]] = { + "requestId": record["requestId"], "status": "accepted", + "resumed": {"approvalPolicy": "never"}, "turnId": turn.turn_id, + } + return revision, turn.turn_id + + def test_a_reconciled_promotion_binds_before_any_repair_pass_runs(self): + """The interval the second binding pass narrowed but could not close. + + _write commits the promotion to dispatched and the repair pass commits the binding in + a LATER transaction. A child emitting from another process in between has a valid + completion refused as unbound_generation even though the dispatch evidence is already + durable. So the binding travels in the transaction that promotes - and this test never + calls a binding pass, because the whole point is that it no longer has to. + """ + revision, turn_id = self.lost_settle_write() + + self.reconciler.recover_on_start(self.adapter) + + self.assertEqual(self.delivery.get(revision)["state"], "dispatched") + self.assertNotEqual( + self.generation_two()["anchorState"], ANCHOR_PENDING, + "the promotion committed without its binding, so a receipt arriving before the" + " next repair pass is refused as unbound", + ) + self.assertEqual(self.generation_two()["dispatchTurnId"], turn_id) + self.assertEqual(self.child_receipt_for_generation_two()["executionGeneration"], 2) + + def test_a_promotion_disagreeing_with_a_bound_anchor_is_recorded_not_swallowed(self): + """A conflict the repair pass would never see, because it reads pending ones only. + + Deferring it to that pass was the first correction I proposed, and it was wrong: the + generation is already bound, so bind_pending_anchors never selects it again and the + disagreement would simply vanish. The bound anchor is still never overwritten. + """ + _revision, _turn_id = self.lost_settle_write() + self.registry.bind_anchor( + self._rid, 2, dispatch_turn_id="a-different-turn", source="dispatch_receipt", + ) + + self.reconciler.recover_on_start(self.adapter) + + self.assertEqual( + self.generation_two()["dispatchTurnId"], "a-different-turn", + "a promotion must never move an anchor that is already bound", + ) + recorded = self.store.all( + "SELECT detail FROM journal WHERE kind = ?", ("anchor_conflict",), + ) + self.assertTrue(recorded, "the disagreement was neither reported nor recorded") + self.assertIn("a-different-turn", recorded[0]["detail"]) + + def test_a_stale_reconciliation_does_not_bind_the_obsolete_attempts_turn(self): + """The guarded UPDATE is the race check, not the snapshot _is_current read. + + _is_current answers from a delivery row fetched before the transaction opened. If + another worker settles that delivery and dispatches a later attempt in between, the + guarded UPDATE matches no rows - and binding anyway would hand the generation this + obsolete attempt's turn, after which the turn the real dispatch reached can never + bind and its receipts are refused. + """ + revision, _turn_id = self.lost_settle_write() + # Another worker settles this delivery and dispatches a later attempt while our + # reconciliation is still reading. The guarded UPDATE will now match nothing. + self.store.db.execute( + "UPDATE deliveries SET attempt_count = attempt_count + 1 WHERE event_id = ?", + (revision,), + ) + + with mock.patch.object(self.reconciler, "_is_current", return_value=True): + self.reconciler.recover_on_start(self.adapter) + + self.assertEqual( + self.generation_two()["anchorState"], ANCHOR_PENDING, + "a stale attempt bound the generation to a turn the real dispatch never used", + ) + + def test_a_revision_request_is_not_exempt_from_supersession(self): + """The execution-only exemption must not cover the relay's own ask. + + A revision_request is not reviewable either, but it IS answered the moment the child + emits the receipt it asked for. Exempting it left the request reported as current - + awaiting_child_receipt - after that receipt had already arrived. + """ + revision = self.revision_pending() + self.clock.advance(3600) + self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.ack.bind_pending_anchors() + accepted = self.child_receipt_for_generation_two() + self.assertEqual(accepted["executionGeneration"], 2) + + with self.store.transaction() as db: + reason = self.delivery._supersession_reason(db, revision) + + self.assertEqual( + reason, "superseded_revision", + "the relay's own revision request outlived the reply it asked for", + ) + + def test_a_revision_request_answered_by_a_failure_is_still_retired(self): + """head_revision considers only ready_for_review receipts. + + Routing a relay-owned request through it left one answered by a failed, interrupted + or blocked reply reported as awaiting_child_receipt forever - the child had supplied + exactly the completion receipt that was asked for, and the ask stayed current. + """ + revision = self.revision_pending() + self.clock.advance(3600) + self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.ack.bind_pending_anchors() + relationship = self.registry.get(self._rid) + turn = self.assigned_turn( + thread=CHILD, turn=self.generation_two()["dispatchTurnId"], + ) + payload = self.execution_payload(relationship, "failed", generation=2, turn=turn) + self.accept(payload) + + with self.store.transaction() as db: + reason = self.delivery._supersession_reason(db, revision) + + self.assertEqual( + reason, "superseded_revision", + "the request outlived the completion receipt it asked for", + ) + + def test_a_revision_request_answered_only_by_the_daemon_is_still_retired(self): + """A revision turn can fail without the child ever writing a receipt. + + The relay records that outcome itself through daemon_observation, and that IS the + answer the request was waiting for - it is what the parent receives. Requiring a + child-authored reply left the request reported as awaiting_child_receipt after the + failure had already been delivered. + """ + revision = self.revision_pending() + self.clock.advance(3600) + self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.ack.bind_pending_anchors() + from codex_session_relay.models import TurnRef + + anchor = self.generation_two()["dispatchTurnId"] + self.adapter.start_turn(CHILD, turn_id=anchor, status="failed") + self.intake.daemon_observation(self._rid, TurnRef(CHILD, anchor, "failed")) + self.assertIsNotNone( + self.store.one( + "SELECT 1 FROM events WHERE producer = ? AND execution_generation = 2", + ("daemon_observation",), + ), + "the fixture did not produce the daemon-authored outcome this test is about", + ) + + with self.store.transaction() as db: + reason = self.delivery._supersession_reason(db, revision) + + self.assertEqual( + reason, "superseded_revision", + "the request outlived the failure the parent was already told about", + ) + + def test_binding_is_idempotent_and_never_rebinds_a_bound_anchor(self): + + revision = self.revision_pending() + self.clock.advance(3600) + record = self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + first = self.ack.bind_pending_anchors() + again = self.ack.bind_pending_anchors() + self.assertEqual(len(first), 1) + self.assertEqual(again, [], "an already bound anchor is not rebound") + self.assertEqual(self.generation_two()["dispatchTurnId"], record["turnId"]) + + def test_nothing_is_bound_from_a_delivery_that_never_dispatched(self): + revision = self.revision_pending() + self.clock.advance(3600) + self.adapter.script("busy") + self.delivery.attempt(revision, self.adapter, now=self.clock.now()) + self.assertEqual(self.ack.bind_pending_anchors(), []) + self.assertEqual(self.generation_two()["anchorState"], ANCHOR_PENDING) + + +class BindingAfterReconciliation(DaemonTestCase): + """Reconciliation is what promotes a lost send to dispatched, and binding ran before it.""" + + def test_a_revision_promoted_by_reconciliation_binds_in_the_same_tick(self): + """Otherwise the generation stays anchor_pending until the NEXT tick. + + A child that emits its completion in that interval has it refused as + unbound_generation even though the dispatch evidence is already committed. + """ + order = [] + original_bind = self.daemon._bind_anchors + original_reconcile = self.daemon._reconcile + + def bind(report): + order.append("bind") + return original_bind(report) + + def reconcile(report, now): + order.append("reconcile") + return original_reconcile(report, now) + + self.daemon._bind_anchors = bind + self.daemon._reconcile = reconcile + try: + self.daemon.tick(now=self.clock.now()) + finally: + self.daemon._bind_anchors = original_bind + self.daemon._reconcile = original_reconcile + + self.assertEqual( + order, ["bind", "reconcile", "bind"], + "binding has to run again after the pass that can promote a revision", + ) + + def test_both_binding_passes_are_counted(self): + """Assigning let the second pass erase what the first repaired. + + A tick that bound a durable anchor then reported anchorsBound 0 and even quiet, which + is the opposite of what happened. + """ + from codex_session_relay.daemon import TickReport + + report = TickReport() + calls = {"n": 0} + + def two_then_none(): + calls["n"] += 1 + return ["a", "b"] if calls["n"] == 1 else [] + + self.daemon.ack.bind_pending_anchors = two_then_none + self.daemon._bind_anchors(report) + self.daemon._bind_anchors(report) + + self.assertEqual(report.anchorsBound, 2, "the second pass must not erase the first") diff --git a/packages/codex-session-relay/tests/test_cli.py b/packages/codex-session-relay/tests/test_cli.py index b848267..21c4b79 100644 --- a/packages/codex-session-relay/tests/test_cli.py +++ b/packages/codex-session-relay/tests/test_cli.py @@ -180,6 +180,59 @@ def test_a_staged_claim_is_visible_and_not_deliverable(self): self.assertEqual(self.run_cli("status")["deliveries"], []) +class ScopedStatus(CliBase): + """A filtered status must filter every block it returns, health included. + + Reporting one assignment's deliveries beside every assignment's observation backlog + reads as that assignment being behind, which is the opposite of what a filter is for. + """ + + def staged(self, name): + """A second assignment with its own parent, child and staged receipt.""" + parent, child = f"01parent-{name}", f"01child-{name}" + root = os.path.join(self.root, name) + os.makedirs(root, exist_ok=True) + relationship = self.run_cli( + "register", "--parent-task", parent, "--parent-host", HOST, + "--child-task", child, "--child-host", HOST, "--issue", f"REL-{name}", + "--artifact-root", root, "--allowed-recipient", parent, + "--dispatch-request-id", f"dispatch-{name}", "--dispatch-turn-id", f"turn-{name}", + ) + path = os.path.join(root, "out.txt") + with open(path, "w", encoding="utf-8") as handle: + handle.write(f"{name} still going") + emitted = self.run_cli( + "emit", "--relationship", relationship["relationshipId"], "--generation", "1", + "--outcome", "ready_for_review", "--turn-thread", child, + "--turn-id", f"turn-{name}", "--turn-status", "completed", "--artifact", path, + ) + self.assertEqual(emitted["stage"], "staged") + return relationship["relationshipId"], emitted["receipt"]["eventId"] + + def test_a_scoped_status_reports_only_the_requested_assignment(self): + mine, my_event = self.staged("a") + theirs, their_event = self.staged("b") + + health = self.run_cli("status", "--relationship", mine)["observation"] + + self.assertEqual([s["eventId"] for s in health["stagedEvents"]], [my_event]) + self.assertEqual(list(health["anchors"]), [mine]) + self.assertEqual(list(health["backlog"]), [mine]) + self.assertNotIn(theirs, health["backlog"]) + self.assertNotIn(their_event, [s["eventId"] for s in health["stagedEvents"]]) + + def test_an_unscoped_status_still_reports_every_assignment(self): + mine, my_event = self.staged("a") + theirs, their_event = self.staged("b") + + health = self.run_cli("status")["observation"] + + self.assertEqual({s["eventId"] for s in health["stagedEvents"]}, + {my_event, their_event}) + self.assertEqual(set(health["anchors"]), {mine, theirs}) + self.assertEqual(set(health["backlog"]), {mine, theirs}) + + class ServiceExitCodes(CliBase): """A refusal that exits zero is read by automation as a success.""" diff --git a/packages/codex-session-relay/tests/test_daemon.py b/packages/codex-session-relay/tests/test_daemon.py index 674cb31..3a7ec1b 100644 --- a/packages/codex-session-relay/tests/test_daemon.py +++ b/packages/codex-session-relay/tests/test_daemon.py @@ -186,6 +186,71 @@ def test_a_failed_turn_suppresses_the_staged_claim_instead_of_delivering_it(self self.assertEqual(failure["outcome"], "failed") self.assertIn(failure["event_id"], sent[0]) + def test_an_absent_anchor_is_not_counted_as_a_healthy_poll(self): + """observation_health reads poll freshness and settlement, nothing else. + + Recording an absent turn as a successful poll refreshed last_polled_at on every tick, + so an anchor the host exhaustively reports gone - one that can never settle - stayed + healthy indefinitely. Process alive is not the same as work progressing, and neither + is a poll that found nothing. + """ + self.register() # the anchor turn is never created on the host + + self.daemon.tick() + + row = self.store.one( + "SELECT last_status, last_polled_at, last_error FROM poll_observations" + " WHERE turn_id = ?", (DISPATCH_TURN,), + ) + self.assertIsNotNone(row, "the anchor was never polled at all") + self.assertEqual(row["last_status"], "absent") + self.assertIsNone( + row["last_polled_at"], + "an absent anchor was recorded as a successful poll, so health never decays", + ) + self.assertIsNotNone(row["last_error"]) + + def test_a_pause_during_the_host_read_does_not_retire_a_failed_turn(self): + """The scheduler selects active assignments and then reads the host. + + A pause landing in between says nothing about what the turn did. Recording a + settlement anyway retires it - _worth_polling drops it from every later tick - while + the synthesized receipt that is the only carrier of that outcome was never written. A + resume then finds nothing left to observe and the parent waits for a verdict forever. + """ + from unittest import mock + + from codex_session_relay.errors import RefusalReason, RegistrationError + + self.register() + self.adapter.start_turn(CHILD, turn_id=DISPATCH_TURN, status="failed") + + def paused(*_args, **_kwargs): + raise RegistrationError( + RefusalReason.RELATIONSHIP_NOT_ACTIVE, + "paused while the host read was in flight", + ) + + with mock.patch.object(self.intake, "daemon_observation", side_effect=paused): + report = self.daemon.tick() + + self.assertEqual(report.observed, 0) + self.assertIsNone( + self.store.one( + "SELECT 1 FROM assignment_settlements WHERE turn_id = ?", (DISPATCH_TURN,), + ), + "the turn was retired while its outcome was never written", + ) + + # And once the assignment is active again, the very next tick produces the receipt. + resumed = self.daemon.tick() + + self.assertEqual(resumed.observed, 1) + self.assertIsNotNone( + self.store.one("SELECT 1 FROM events WHERE producer = 'daemon_observation'"), + "the outcome never reached the parent after the assignment resumed", + ) + def test_a_synthesized_failure_is_persisted_and_delivered_as_separate_outcomes(self): relationship = self.register() self.adapter.start_turn(CHILD, turn_id=DISPATCH_TURN, status="failed") diff --git a/packages/codex-session-relay/tests/test_diagnostics.py b/packages/codex-session-relay/tests/test_diagnostics.py new file mode 100644 index 0000000..29410b0 --- /dev/null +++ b/packages/codex-session-relay/tests/test_diagnostics.py @@ -0,0 +1,658 @@ +"""One word for five situations told an operator nothing about what to do. + +withheld_pre_send covered a receipt not yet collected, a parent mid-turn, a host that would +not confirm the authorized settings, a started turn, and an outstanding acknowledgement. The +cause is the only part that suggests an action, and it was the part not recorded. +""" + +import json +import unittest + +from codex_session_relay.models import TurnRef + +from .support import CHILD, PARENT, DeliveryTestCase +from .test_daemon import DaemonTestCase + + +class Phases(DeliveryTestCase): + def phase_of(self, event_id): + for item in self.delivery.snapshot()["deliveries"]: + if item["eventId"] == event_id: + return item + raise AssertionError("no such delivery") + + def test_a_queued_delivery_is_waiting_on_the_send_not_the_receipt(self): + """A delivery row only exists because the receipt was collected and accepted. + + awaiting_receipt pointed an operator at the child for a delay that is entirely this + relay's: what is outstanding is reaching the recipient. + """ + _relationship, event_id = self.queued_event() + self.assertEqual(self.phase_of(event_id)["phase"], "awaiting_send") + + def test_a_delivery_whose_send_is_in_flight_says_so(self): + """The claim committed and the process stopped; there IS an attempt to reconcile.""" + from codex_session_relay.delivery import _phase + + row = {"state": "sending", "kind": "completion_event", "hold_reason": None} + self.assertEqual(_phase(row, [], None), "in_flight") + + def test_a_busy_parent_is_named_as_such_with_its_next_retry(self): + _relationship, event_id = self.queued_event() + self.adapter.set_status(PARENT, "active") + self.attempt(event_id) + item = self.phase_of(event_id) + self.assertEqual(item["phase"], "parent_busy") + self.assertIsNotNone(item["nextRetryAt"], "an operator needs to know when, too") + self.assertEqual(item["lastFailedOperation"]["operation"], "parent_busy") + + def test_a_dispatched_delivery_is_awaiting_acknowledgement(self): + _relationship, event_id = self.queued_event() + self.attempt(event_id) + self.assertEqual(self.phase_of(event_id)["phase"], "awaiting_ack") + + def test_a_closed_channel_is_queryable_rather_than_hidden(self): + _relationship, event_id = self.queued_event() + self.adapter.script("approval_policy") + self.attempt(event_id) + item = self.phase_of(event_id) + self.assertEqual(item["phase"], "channel_closed") + self.assertIsNotNone(item["lastFailedOperation"]) + self.assertEqual(item["lastFailedOperation"]["error_code"], + "unsupported_approval_policy") + + def test_a_settings_rejection_records_the_field_the_host_disagreed_on(self): + """The difference is dropped by classification, so it is read from the raw receipt.""" + _relationship, event_id = self.queued_event() + original = self.adapter.send_message + + def rejecting(request_id, thread_id, message, settings=None): + receipt = original(request_id, thread_id, message, settings) + receipt.update( + status="failed", + error="thread/resume: settings_not_preserved", + rpcError={"code": "settings_not_preserved", "message": "mismatch"}, + resumed={"approvalPolicy": "onRequest"}, + settingsFindings=[ + {"field": "approvalPolicy", "expected": "never", "returned": "onRequest"}, + {"field": "reasoningEffort", "expected": "xhigh", "returned": "low"}, + ], + ) + self.adapter.ledger[request_id] = receipt + return dict(receipt) + + self.adapter.send_message = rejecting + self.attempt(event_id) + + failure = self.phase_of(event_id)["lastFailedOperation"] + self.assertEqual(failure["operation"], "settings_check") + self.assertIn("approvalPolicy", failure["difference"]) + self.assertIn("onRequest", failure["difference"]) + self.assertIn("reasoningEffort", failure["difference"], + "every mismatched field, not only the first") + + def test_the_diagnosis_survives_reopening_the_database(self): + from codex_session_relay.delivery import DeliveryService + from codex_session_relay.store import Store + + _relationship, event_id = self.queued_event() + self.adapter.set_status(PARENT, "active") + self.attempt(event_id) + path = self.store.path + self.store.close() + reopened = Store(path) + self.addCleanup(reopened.close) + service = DeliveryService(reopened, self.registry, self.intake, self.clock) + self.assertTrue(service.failures_for(event_id)) + + +class NoAttemptPhases(Phases): + """Some refusals happen before an attempt exists, and those had no cause to read.""" + + def test_missing_settings_are_named_rather_than_reported_as_awaiting_a_receipt(self): + """_settings_for refuses before anything is claimed, so there is no attempt record. + + Every other cause reaches an operator through the attempt. This one refused first, + and status called it awaiting_receipt - which says the relay is waiting on the child + when the actionable problem is settings nobody recorded. + """ + _relationship, event_id = self.queued_event(settings=None) + + self.attempt(event_id) + + item = self.phase_of(event_id) + self.assertEqual(self.delivery.get(event_id)["state"], "withheld_pre_send") + self.assertEqual(item["attempts"], 0, "nothing was claimed and nothing was sent") + self.assertNotEqual(item["phase"], "awaiting_receipt") + self.assertEqual(item["phase"], "withheld:settings_check") + self.assertIsNotNone(item["lastFailedOperation"]) + self.assertEqual(item["lastFailedOperation"]["operation"], "settings_check") + self.assertIsNotNone(item["lastFailedOperation"]["next_retry_at"]) + + +class UncertainPhases(unittest.TestCase): + """Two phases claimed more than the record supports, read straight from _phase. + + Driven directly rather than through a fixture: what is under test is the rule, and a + transport fixture that happens to classify a receipt one way or another would decide the + outcome instead of the rule doing it. + """ + + def phase(self, state, record, *, kind="completion_event", failure=None, + hold_reason=None): + from codex_session_relay.delivery import _phase + + attempts = [{"internal_state": "settled", "operation_observation": None, + "record": json.dumps(record)}] + row = {"state": state, "kind": kind, "hold_reason": hold_reason} + return _phase(row, attempts, None, failure) + + def test_a_refused_turn_start_is_not_evidence_that_a_turn_exists(self): + """turn_accepted was reported from the operation name alone. + + A failed turn/start with no turn id means the call was REFUSED, not that its answer + was lost, so claiming a turn exists points an operator at a turn nobody can find. + """ + self.assertEqual( + self.phase("held_uncertain", {"failedOperation": "turn/start", "turnId": None}), + "outcome_unknown", + ) + + def test_a_started_turn_whose_answer_was_lost_is_still_turn_accepted(self): + """A turn id is affirmative evidence, and the branch must keep honouring it.""" + self.assertEqual( + self.phase("held_uncertain", + {"failedOperation": "turn/start", "turnId": "turn-9"}), + "turn_accepted", + ) + + def test_an_ordinary_resume_failure_is_not_called_a_settings_rejection(self): + """thread/resume fails for connectivity and internal reasons too. + + Naming those settings_rejected hands an operator a remediation - re-record the + authorized settings - that cannot possibly work. + """ + phase = self.phase( + "withheld_pre_send", {"failedOperation": "thread/resume"}, + failure={"operation": "transport", "error_code": "internal"}, + ) + self.assertNotEqual(phase, "settings_rejected") + self.assertEqual(phase, "withheld:thread/resume") + + def test_a_real_settings_rejection_still_says_so(self): + """_settle records settings_check only when the receipt carried field-level findings.""" + self.assertEqual( + self.phase( + "withheld_pre_send", {"failedOperation": "thread/resume"}, + failure={"operation": "settings_check", "error_code": "settings_not_preserved"}, + ), + "settings_rejected", + ) + + +class RefusedBeforeTheQueue(DeliveryTestCase): + """The most stuck state in the system was the one status could not show.""" + + def test_an_event_refused_at_the_queue_is_visible_in_status(self): + """It has no deliveries row at all, and snapshot was built only from deliveries. + + A permanently paused or unauthorized assignment therefore had no status entry, no + phase and no retry time while the daemon went on retrying it. + """ + relationship, event_id = self.ready_event() + with self.store.transaction() as db: + self.delivery.record_intent_in( + db, event_id, relationship_id=relationship["relationshipId"], + kind="completion_event", recipient_task_id=PARENT, + error="relationship_not_active", now=self.clock.now(), + ) + + payload = self.delivery.snapshot() + + self.assertEqual(payload["deliveries"], [], "there is no delivery row, by design") + self.assertEqual([i["eventId"] for i in payload["pendingIntents"]], [event_id]) + intent = payload["pendingIntents"][0] + self.assertEqual(intent["phase"], "refused_pre_queue") + self.assertIn("relationship_not_active", intent["lastError"]) + self.assertIsNotNone(intent["nextRetryAt"]) + + def test_a_scoped_status_filters_the_pending_intents_too(self): + relationship, event_id = self.ready_event() + with self.store.transaction() as db: + self.delivery.record_intent_in( + db, event_id, relationship_id=relationship["relationshipId"], + kind="completion_event", recipient_task_id=PARENT, + error="relationship_not_active", now=self.clock.now(), + ) + scoped = self.delivery.snapshot(relationship_id="rel-someone-else") + self.assertEqual(scoped["pendingIntents"], []) + + +class SettledAcknowledgements(unittest.TestCase): + """A verified rejection is as settled as a verified acceptance.""" + + def phase(self, ack): + from codex_session_relay.delivery import _phase + + row = {"state": "dispatched", "kind": "completion_event", "hold_reason": None} + return _phase(row, [], ack) + + def test_a_verified_rejection_is_not_reported_as_awaiting_a_receipt(self): + """Recognising only the accepted case let a rejection fall past every later branch. + + The receipt was delivered and the parent answered; awaiting_receipt says the child + has produced nothing, which is the opposite of what happened. + """ + phase = self.phase({"verified": "verified", "accepted": 0}) + self.assertNotEqual(phase, "awaiting_receipt") + self.assertEqual(phase, "rejected") + + def test_a_verified_acceptance_still_reports_acknowledged(self): + self.assertEqual(self.phase({"verified": "verified", "accepted": 1}), "acknowledged") + + def test_an_unverified_acknowledgement_settles_nothing(self): + """Intent is not evidence; an unverified ack must not close the delivery.""" + self.assertEqual(self.phase({"verified": "unverified", "accepted": 1}), "awaiting_ack") + + +class RevisionPhases(DeliveryTestCase): + """Contract v1 acknowledges the child-to-parent direction only.""" + + def test_a_dispatched_revision_is_not_waiting_for_an_acknowledgement(self): + """AckService refuses to acknowledge a revision, so awaiting_ack can never clear. + + The child answers a revision request with its next completion receipt. Reporting an + obligation that nothing is allowed to meet left every dispatched revision looking + permanently stuck. + """ + from codex_session_relay import identity + + _relationship, event_id = self.queued_event(recipients=[PARENT, CHILD]) + self.attempt(event_id) + self.clock.advance(5) + turn = self.adapter.start_turn(PARENT, turn_id="ack-turn", status="inProgress") + self.ack.acknowledge( + event_id, ack_turn_id=turn.turn_id, + ack_proof=identity.ack_proof(event_id, turn.turn_id), accepted=True, + adapter=self.adapter, + ) + self.ack.record_verdict( + event_id, verdict="needs_changes", verdict_turn_id="verdict-1", + criteria=[{"id": "c-1", "verdict": "needs_changes", "note": "missing migration"}], + ) + revision = self.store.one("SELECT * FROM deliveries WHERE kind = 'revision_request'") + self.delivery.attempt(revision["event_id"], self.adapter) + + item = [d for d in self.delivery.snapshot()["deliveries"] + if d["eventId"] == revision["event_id"]][0] + + self.assertEqual(item["state"], "dispatched") + self.assertEqual(item["phase"], "awaiting_child_receipt") + self.assertNotEqual(item["phase"], "awaiting_ack") + + def test_a_dispatched_completion_still_awaits_its_acknowledgement(self): + """The branch must not swallow the direction that really is waiting on an ack.""" + _relationship, event_id = self.queued_event() + self.attempt(event_id) + item = [d for d in self.delivery.snapshot()["deliveries"] + if d["eventId"] == event_id][0] + self.assertEqual(item["phase"], "awaiting_ack") + + +class ObservationHealth(DaemonTestCase): + def test_a_live_loop_with_nothing_polled_is_not_healthy(self): + """A live pid was the whole problem in the reproduced incident.""" + relationship = self.register() + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + self.adapter.fail_reads("read_turn") + self.daemon.tick(now=self.clock.now()) + + health = self.delivery.observation_health(now=self.clock.now()) + anchor = health["anchors"][relationship["relationshipId"]] + self.assertIsNone(anchor["lastPolledAt"], "a failed first read is not a poll") + self.assertIsNotNone(anchor["lastError"]) + self.assertEqual(health["health"], "stalled") + + def test_a_successful_poll_then_a_failure_keeps_the_last_success(self): + relationship = self.register() + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + self.daemon.tick(now=self.clock.now()) + first = self.delivery.observation_health(now=self.clock.now()) + polled = first["anchors"][relationship["relationshipId"]]["lastPolledAt"] + self.assertIsNotNone(polled, "an in-progress turn was still successfully looked at") + + self.adapter.fail_reads("read_turn") + self.clock.advance(10) + self.daemon.tick(now=self.clock.now()) + second = self.delivery.observation_health(now=self.clock.now()) + anchor = second["anchors"][relationship["relationshipId"]] + self.assertEqual(anchor["lastPolledAt"], polled, "a failure is not a success") + self.assertIsNotNone(anchor["lastError"]) + + def test_a_staged_backlog_is_visible_with_its_age(self): + relationship = self.register() + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + path = self.artifact("out.txt", "still going") + payload = self.ready_payload( + relationship, [path], turn=TurnRef(CHILD, "turn-dispatch-1", "inProgress"), + ) + self.accept(payload) + self.clock.advance(7200) + + health = self.delivery.observation_health(now=self.clock.now()) + + self.assertEqual(len(health["stagedEvents"]), 1) + self.assertGreater(health["oldestStagedAgeSeconds"], 3600) + self.assertEqual(health["backlog"][relationship["relationshipId"]], 1) + self.assertIn("liveness", health["note"]) + + def test_an_anchor_the_scheduler_has_not_reached_is_not_reported_healthy(self): + """Starting from the poll table would omit it entirely and report healthy.""" + relationship = self.register() + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + # No tick at all: nothing has ever looked at this anchor. + health = self.delivery.observation_health(now=self.clock.now()) + anchor = health["anchors"][relationship["relationshipId"]] + self.assertIsNone(anchor["lastPolledAt"]) + self.assertEqual( + health["health"], "stalled", + "an anchor nothing has read is not evidence of health", + ) + + def test_a_finished_quiet_assignment_does_not_age_into_a_false_alarm(self): + """_worth_polling stops scheduling a terminal turn with nothing staged behind it. + + Its last poll therefore can never advance again, so ageing it out marked every + fully observed assignment stalled once stale_after had elapsed - on every status + call, forever, with nothing wrong. + """ + relationship = self.register() + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + self.daemon.tick(now=self.clock.now()) + self.adapter.finish_turn(CHILD, "turn-dispatch-1") + self.daemon.tick(now=self.clock.now()) + + anchor_id = relationship["relationshipId"] + settled = self.delivery.observation_health(now=self.clock.now()) + self.assertTrue(settled["anchors"][anchor_id]["settled"]) + + self.clock.advance(7200) + later = self.delivery.observation_health(now=self.clock.now()) + + self.assertGreater(later["anchors"][anchor_id]["ageSeconds"], 900) + self.assertEqual( + later["health"], "healthy", + "nothing is left to learn from this turn, so nothing is being missed", + ) + + def test_a_late_staged_receipt_reopens_the_same_anchor(self): + """Settled is a property of the work, not a latch. New staged work un-settles it.""" + relationship = self.register() + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + self.daemon.tick(now=self.clock.now()) + self.adapter.finish_turn(CHILD, "turn-dispatch-1") + self.daemon.tick(now=self.clock.now()) + + path = self.artifact("late.txt", "staged after the completion was observed") + self.accept(self.ready_payload( + relationship, [path], turn=TurnRef(CHILD, "turn-dispatch-1", "inProgress"), + )) + self.clock.advance(7200) + + health = self.delivery.observation_health(now=self.clock.now()) + anchor_id = relationship["relationshipId"] + + self.assertFalse(health["anchors"][anchor_id]["settled"]) + self.assertEqual(health["health"], "stalled", + "there is staged work here and nothing has looked at it since") + + def test_an_upgraded_store_does_not_forget_what_it_had_already_settled(self): + """assignment_settlements is new, and the scheduler asks it instead of observations. + + Leaving it empty on upgrade makes every historical turn look unsettled, so a current + turn that can no longer be read strands a previously settled assignment forever. + """ + from codex_session_relay.store import Store + + relationship = self.register() + rid = relationship["relationshipId"] + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + self.adapter.finish_turn(CHILD, "turn-dispatch-1") + self.daemon.tick(now=self.clock.now()) + self.assertTrue(self.store.all("SELECT * FROM assignment_settlements")) + + # Exactly the state an upgrade starts from: observations populated, the new table not. + with self.store.transaction() as db: + db.execute("DELETE FROM assignment_settlements") + path = self.store.path + self.store.close() + + reopened = Store(path) + self.addCleanup(reopened.close) + + rows = reopened.all("SELECT * FROM assignment_settlements") + self.assertEqual([row["relationship_id"] for row in rows], [rid]) + self.assertEqual(rows[0]["turn_id"], "turn-dispatch-1") + + def test_each_assignment_settles_a_shared_turn_for_itself(self): + """observations is keyed by the turn alone, so it can only name who settled it first. + + Every other assignment on a shared child turn therefore looked permanently unsettled, + was polled again on every round, reported the tick non-quiet and spent observation + budget forever. assignment_settlements records the per-assignment fact. + """ + import os + + from codex_session_relay.models import Endpoint + from codex_session_relay.registry import record_settings + from .support import HOST, task_settings + + child, turn = "01child-shared", "turn-shared-1" + made = [] + for name in ("a", "b"): + parent = f"01parent-{name}" + root = os.path.join(self.root, name) + os.makedirs(root, exist_ok=True) + made.append(self.registry.register( + parent=Endpoint(parent, HOST, cwd=f"/p/{name}"), + child=Endpoint(child, HOST, cwd=root), + issue_key=f"SHARED-{name}", artifact_roots=[root], + allowed_recipients=[parent], + dispatch_request_id=f"dispatch-{name}", dispatch_turn_id=turn, + )) + self.adapter.add_thread(parent) + record_settings(self.store, self.clock, parent, task_settings(f"/p/{name}"), + source="creation_result") + self.adapter.add_thread(child) + self.adapter.start_turn(child, turn_id=turn, status="inProgress") + self.adapter.finish_turn(child, turn) + for _tick in range(4): + self.clock.advance(1) + self.daemon.tick(now=self.clock.now()) + + self.assertEqual( + len(self.store.all("SELECT * FROM observations")), 1, + "the turn table is unchanged and still holds one row", + ) + self.assertEqual( + {row["relationship_id"] + for row in self.store.all("SELECT * FROM assignment_settlements")}, + {r["relationshipId"] for r in made}, + "but each assignment has settled it for itself", + ) + + self.clock.advance(7200) + health = self.delivery.observation_health(now=self.clock.now()) + for relationship in made: + self.assertTrue(health["anchors"][relationship["relationshipId"]]["settled"]) + self.assertEqual(health["health"], "healthy") + + # And nothing is re-polled: a settled assignment costs no further budget. + self.clock.advance(1) + quiet = self.daemon.tick(now=self.clock.now()) + self.assertEqual(quiet.observed, 0, "neither assignment is settled a second time") + + def test_another_assignments_staged_work_does_not_unsettle_this_one(self): + """staged_here counted by thread and turn, so a shared anchor contaminated both. + + An assignment that has observed its turn and has nothing of its own outstanding was + pulled back to unsettled by a claim belonging to someone else, and from there it ages + into a stall with nothing wrong. + """ + import os + + from codex_session_relay.models import Endpoint + from codex_session_relay.registry import record_settings + from .support import HOST, task_settings + + child, turn = "01child-shared", "turn-shared-1" + made = [] + for name in ("a", "b"): + parent = f"01parent-{name}" + root = os.path.join(self.root, name) + os.makedirs(root, exist_ok=True) + made.append(self.registry.register( + parent=Endpoint(parent, HOST, cwd=f"/p/{name}"), + child=Endpoint(child, HOST, cwd=root), + issue_key=f"SHARED-{name}", artifact_roots=[root], + allowed_recipients=[parent], + dispatch_request_id=f"dispatch-{name}", dispatch_turn_id=turn, + )) + self.adapter.add_thread(parent) + record_settings(self.store, self.clock, parent, task_settings(f"/p/{name}"), + source="creation_result") + self.adapter.add_thread(child) + self.adapter.start_turn(child, turn_id=turn, status="inProgress") + self.adapter.finish_turn(child, turn) + self.daemon.tick(now=self.clock.now()) + + observed = self.store.one( + "SELECT relationship_id FROM observations WHERE turn_id = ?", (turn,), + )["relationship_id"] + settled = next(r for r in made if r["relationshipId"] == observed) + other = next(r for r in made if r["relationshipId"] != observed) + self.assertTrue( + self.delivery.observation_health( + now=self.clock.now(), + )["anchors"][observed]["settled"], + ) + + # A claim belonging to the OTHER assignment, on the anchor turn they share. + path = os.path.join(self.root, "other.txt") + with open(path, "w", encoding="utf-8") as handle: + handle.write("not this assignment's outstanding work") + self.store.db.execute( + "INSERT INTO events (event_id, relationship_id, execution_generation, attempt," + " revision_hash, outcome, producer, turn_thread_id, turn_id, turn_status," + " receipt, stage, staged_at, first_seen_at, last_seen_at)" + " VALUES ('shared-staged',?,1,1,'x','ready_for_review','child',?,?,'inProgress'," + " '{}','staged',?,?,?)", + (other["relationshipId"], child, turn, + self.clock.iso(), self.clock.iso(), self.clock.iso()), + ) + del path + + health = self.delivery.observation_health(now=self.clock.now()) + + self.assertTrue( + health["anchors"][observed]["settled"], + "this assignment observed its turn and has nothing of its own left to resolve", + ) + del settled + + def test_a_cancelled_assignments_staged_event_does_not_hold_health_down(self): + """The scheduler drops an inactive assignment and will never settle its claim. + + Ageing that claim anyway left the whole health block degraded indefinitely while + every active assignment was fine. + """ + relationship = self.register() + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + path = self.artifact("out.txt", "still going") + self.accept(self.ready_payload( + relationship, [path], turn=TurnRef(CHILD, "turn-dispatch-1", "inProgress"), + )) + self.daemon.tick(now=self.clock.now()) + self.clock.advance(7200) + before = self.delivery.observation_health(now=self.clock.now()) + self.assertEqual(len(before["stagedEvents"]), 1) + self.assertNotEqual(before["health"], "healthy") + + self.registry.set_status( + relationship["relationshipId"], "cancelled", actor="test", + ) + + health = self.delivery.observation_health(now=self.clock.now()) + + self.assertEqual(health["stagedEvents"], [], + "nothing is going to settle this one, so it is not a backlog") + self.assertEqual(health["health"], "healthy") + + def test_backlog_and_staged_events_agree_after_an_assignment_is_cancelled(self): + """stagedEvents filtered on the active relationship; backlog read events directly. + + The two fields disagreed the moment an assignment was paused or cancelled: status + reported work the scheduler will never process. + """ + relationship = self.register() + rid = relationship["relationshipId"] + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + path = self.artifact("out.txt", "still going") + self.accept(self.ready_payload( + relationship, [path], turn=TurnRef(CHILD, "turn-dispatch-1", "inProgress"), + )) + before = self.delivery.observation_health(now=self.clock.now()) + self.assertEqual(len(before["stagedEvents"]), 1) + self.assertEqual(before["backlog"].get(rid), 1) + + self.registry.set_status(rid, "cancelled", actor="test") + + health = self.delivery.observation_health(now=self.clock.now()) + + self.assertEqual(health["stagedEvents"], []) + self.assertEqual( + health["backlog"], {}, + "backlog must not report work stagedEvents has already excluded", + ) + + def test_a_generation_whose_anchor_is_not_bound_yet_is_not_a_stall(self): + """A needs_changes verdict opens a generation before its revision is dispatched. + + Until the dispatch receipt binds the anchor there is no turn for the observation + scheduler to poll, so counting it as never polled reported stalled for a relay doing + exactly what it is supposed to do. + """ + relationship = self.register() + rid = relationship["relationshipId"] + self.registry.open_generation( + rid, dispatch_request_id="revision-1", reason="needs_changes_revision", + ) + + health = self.delivery.observation_health(now=self.clock.now()) + anchor = health["anchors"][rid] + + self.assertTrue(anchor["anchorPending"]) + self.assertIsNone(anchor["turnId"]) + self.assertEqual( + health["health"], "healthy", + "there is no turn to poll yet, so nothing is being missed", + ) + + def test_an_unbound_anchor_becomes_pollable_once_it_binds(self): + """Pending is a phase, not an exemption. Once bound it is held to the same freshness.""" + relationship = self.register() + rid = relationship["relationshipId"] + opened = self.registry.open_generation( + rid, dispatch_request_id="revision-1", reason="needs_changes_revision", + ) + self.registry.bind_anchor( + rid, opened["executionGeneration"], dispatch_turn_id="turn-revision-1", + source="dispatch_receipt", + ) + self.clock.advance(7200) + + health = self.delivery.observation_health(now=self.clock.now()) + + self.assertFalse(health["anchors"][rid]["anchorPending"]) + self.assertEqual(health["health"], "stalled", + "now there is a turn, and nothing has ever read it") diff --git a/packages/codex-session-relay/tests/test_enqueue_durability.py b/packages/codex-session-relay/tests/test_enqueue_durability.py new file mode 100644 index 0000000..e69ac66 --- /dev/null +++ b/packages/codex-session-relay/tests/test_enqueue_durability.py @@ -0,0 +1,213 @@ +"""JUN-167 P1: a terminal observation must not outlive the queuing it implies. + +_settle_turn recorded the observation first and queued after, catching enqueue errors. If the +relationship was paused at that moment, or the database was briefly busy, the event was final +with no delivery row - and the next tick skipped the turn through _already_observed, so +resuming the relationship never helped. The event simply never reached anyone. +""" + +from codex_session_relay.errors import DeliveryRefused, RefusalReason +from codex_session_relay.models import TurnRef + +from .support import CHILD, DeliveryTestCase + + +class EnqueueDurability(DeliveryTestCase): + def daemon(self): + from codex_session_relay.daemon import RelayDaemon + + return RelayDaemon( + self.store, self.registry, self.intake, self.delivery, self.ack, + self.reconciler, self.adapter, clock=self.clock, + ) + + def staged_completion(self): + """A child claim emitted from inside its own live turn, which is therefore staged.""" + relationship = self.register() + self._rid = relationship["relationshipId"] + turn = self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + path = self.artifact("out.txt", "the deliverable") + payload = self.ready_payload( + relationship, [path], + turn=TurnRef(CHILD, turn.turn_id, "inProgress"), + ) + self.accept(payload) + self.assertEqual(self.intake.row(payload["eventId"])["stage"], "staged") + # The turn ends normally, which is what makes the staged claim deliverable. + self.adapter.finish_turn(CHILD, turn.turn_id, status="completed") + return relationship, payload["eventId"] + + def refuse_enqueue_once(self): + """Exactly the shape a pause committed between selection and enqueue produces.""" + calls = [] + original = self.delivery.enqueue_in + + def refusing(db, event_id, **kwargs): + calls.append(event_id) + raise DeliveryRefused( + RefusalReason.RELATIONSHIP_NOT_ACTIVE, "paused between selection and enqueue", + ) + + self.delivery.enqueue_in = refusing + return calls, original + + def test_an_event_refused_at_enqueue_is_still_delivered_later(self): + _relationship, event_id = self.staged_completion() + calls, original = self.refuse_enqueue_once() + + self.daemon().tick(now=self.clock.now()) + + # The defect state, asserted explicitly rather than inferred. + self.assertTrue(calls, "the tick must have reached the enqueue it then refused") + self.assertEqual(self.intake.row(event_id)["stage"], "final") + self.assertIsNotNone( + self.store.one( + "SELECT 1 FROM observations WHERE thread_id = ? AND turn_id = ?", + (CHILD, "turn-dispatch-1"), + ), + "the observation was recorded", + ) + self.assertIsNone(self.delivery.find(event_id), "and nothing was queued for it") + + # The refusal is over. Nothing about the turn has changed, so a loop that only + # reconsiders unobserved turns will never look at this event again. + self.delivery.enqueue_in = original + # Past the refusal's backoff. A retry that fired immediately would hammer a refusal + # that is usually still true a moment later. + self.clock.advance(3600) + self.daemon().tick(now=self.clock.now()) + + queued = self.delivery.find(event_id) + self.assertIsNotNone( + queued, "a final event with no delivery row must be recoverable, not lost", + ) + self.assertEqual(queued["event_id"], event_id, "the original event, not a new one") + + def test_a_transient_failure_leaves_no_observation_behind(self): + """Durable refusal and transient failure are not the same and must not settle alike.""" + import sqlite3 + + _relationship, event_id = self.staged_completion() + + def blow_up(db, event_id_, **kwargs): + raise sqlite3.OperationalError("database is locked") + + self.delivery.enqueue_in = blow_up + self.daemon().tick(now=self.clock.now()) + self.assertIsNone( + self.store.one( + "SELECT 1 FROM observations WHERE thread_id = ? AND turn_id = ?", + (CHILD, "turn-dispatch-1"), + ), + "a transient failure rolls the observation back so the next tick retries cleanly", + ) + + def test_an_event_nobody_asked_to_send_is_not_resurrected(self): + """Absence of a delivery row is not evidence that delivery was wanted and failed. + + An event emitted with --no-enqueue looks exactly like one whose queuing was refused, + so recovery reads the recorded intent rather than guessing from what is missing. + """ + _relationship, event_id = self.staged_completion() + self.intake.resolve_staged(TurnRef(CHILD, "turn-dispatch-1", "completed")) + self.assertEqual(self.intake.row(event_id)["stage"], "final") + self.assertIsNone(self.delivery.find(event_id)) + + report = self.daemon().tick(now=self.clock.now()) + + self.assertIsNone( + self.delivery.find(event_id), + "recovery must not send something nobody asked it to send", + ) + self.assertEqual(report.requeued, 0) + + def test_a_refused_event_records_an_intent_that_recovery_reads(self): + _relationship, event_id = self.staged_completion() + self.refuse_enqueue_once() + self.daemon().tick(now=self.clock.now()) + intent = self.store.one( + "SELECT * FROM delivery_intent WHERE event_id = ?", (event_id,), + ) + self.assertIsNotNone(intent, "the refusal recorded that delivery was wanted") + self.assertEqual(intent["attempts"], 1) + self.assertGreater(intent["next_retry_at"], self.clock.now()) + + def test_a_permanently_refused_intent_backs_off_instead_of_holding_its_slot(self): + """Otherwise four unqueueable events keep every recovery slot forever.""" + relationship, event_id = self.staged_completion() + self.refuse_enqueue_once() + self.daemon().tick(now=self.clock.now()) + first = self.store.one( + "SELECT * FROM delivery_intent WHERE event_id = ?", (event_id,), + ) + # The relationship now excludes its own parent, so every retry is refused for good. + self.registry.set_status(relationship["relationshipId"], "paused", actor="test") + self.clock.advance(3600) + self.daemon().tick(now=self.clock.now()) + second = self.store.one( + "SELECT * FROM delivery_intent WHERE event_id = ?", (event_id,), + ) + self.assertGreater(second["attempts"], first["attempts"]) + self.assertGreater(second["next_retry_at"], first["next_retry_at"]) + + def test_the_backoff_survives_an_intent_that_is_refused_indefinitely(self): + """base * 2 ** (attempts - 1) was computed and only then clamped. + + A relationship that stays paused has no cap on its attempt count, and around the + 1025th refusal the product is an integer too large to convert to a float. The + OverflowError escaped the handler meant to absorb the refusal, the transaction + rolled back with the intent still due, and every later tick failed the same way. + """ + ceiling = self.delivery.policy.presend_max_seconds + for attempts in (1, 2, 10, 1024, 1025, 5000, 10 ** 6): + delay = self.delivery._backoff(attempts) + self.assertIsInstance(delay, (int, float)) + self.assertLessEqual(delay, ceiling) + self.assertGreaterEqual(delay, 0) + self.assertEqual(self.delivery._backoff(10 ** 6), ceiling) + self.assertLess( + self.delivery._backoff(1), self.delivery._backoff(4), + "and it still backs off before the ceiling", + ) + + def test_the_backoff_bound_follows_the_policy_rather_than_a_fixed_step_count(self): + """A small base needs more doublings, and a constant bound truncated its backoff.""" + from codex_session_relay.policy import RetryPolicy + + # Deliberately extreme: this ratio needs about 70 doublings, so a fixed 64-step bound + # returns the ceiling while the policy's own backoff still has room. + self.delivery.policy = RetryPolicy( + presend_base_seconds=1e-12, presend_max_seconds=1e9, + ) + ceiling = self.delivery.policy.presend_max_seconds + self.assertLess( + self.delivery._backoff(66), ceiling, + "this policy has not reached its own ceiling yet", + ) + self.assertLess(self.delivery._backoff(66), self.delivery._backoff(80)) + self.assertEqual(self.delivery._backoff(10 ** 6), ceiling) + + def test_an_intent_refused_past_the_overflow_point_still_records_its_retry(self): + """The end-to-end shape: the write must survive, not just the arithmetic.""" + relationship, event_id = self.staged_completion() + self.refuse_enqueue_once() + self.daemon().tick(now=self.clock.now()) + self.registry.set_status(relationship["relationshipId"], "paused", actor="test") + with self.store.transaction() as db: + db.execute( + "UPDATE delivery_intent SET attempts = 1024, next_retry_at = 0" + " WHERE event_id = ?", (event_id,), + ) + + self.clock.advance(3600) + report = self.daemon().tick(now=self.clock.now()) + + intent = self.store.one( + "SELECT * FROM delivery_intent WHERE event_id = ?", (event_id,), + ) + self.assertEqual(intent["attempts"], 1025) + self.assertEqual( + intent["next_retry_at"], + self.clock.now() + self.delivery.policy.presend_max_seconds, + ) + self.assertIsNotNone(report) diff --git a/packages/codex-session-relay/tests/test_fairness.py b/packages/codex-session-relay/tests/test_fairness.py new file mode 100644 index 0000000..3471cc0 --- /dev/null +++ b/packages/codex-session-relay/tests/test_fairness.py @@ -0,0 +1,561 @@ +"""Per-parent fairness: one parent's backlog must not be every other parent's wait. + +delivery.eligible was a single ORDER BY created_at LIMIT across every relationship, so a +parent with a large older backlog filled the window by itself. _reconcile had the same shape, +and there a gate skip still consumed its place in the prefix. +""" + +import os +import unittest + +from codex_session_relay.models import Endpoint, TurnRef +from codex_session_relay.transport import DEFERRED_BUSY, DISPATCHED + +from .support import HOST, DeliveryTestCase +from .test_daemon import DaemonTestCase + + +class ParentFixture(DaemonTestCase): + def assignment(self, name, *, events=1): + """A parent with its own child, and a given number of queued completions.""" + parent, child = f"01parent-{name}", f"01child-{name}" + root = os.path.join(self.root, name) + os.makedirs(root, exist_ok=True) + relationship = self.registry.register( + parent=Endpoint(parent, HOST, cwd=f"/p/{name}"), + child=Endpoint(child, HOST, cwd=root), + issue_key=f"REL-{name}", artifact_roots=[root], + allowed_recipients=[parent], + dispatch_request_id=f"dispatch-{name}", dispatch_turn_id=f"turn-{name}", + ) + self.adapter.add_thread(parent) + self.adapter.add_thread(child) + from codex_session_relay.registry import record_settings + from .support import task_settings + + record_settings(self.store, self.clock, parent, task_settings(f"/p/{name}"), + source="creation_result") + ids = [] + for index in range(events): + path = os.path.join(root, f"out-{index}.txt") + with open(path, "w", encoding="utf-8") as handle: + handle.write(f"{name}-{index}") + payload = self.ready_payload( + relationship, [path], attempt=index + 1, + turn=self.assigned_turn(thread=child, turn=f"turn-{name}"), + ) + self.accept(payload) + self.delivery.enqueue(payload["eventId"]) + ids.append(payload["eventId"]) + self.clock.advance(1) + return relationship, ids + + +class DeliveryFairness(ParentFixture): + def test_a_newer_parent_is_selected_despite_a_large_older_backlog(self): + """The shape a global prefix gets wrong, at a size no window could absorb.""" + self.assignment("a", events=40) + _relationship, newer = self.assignment("b", events=1) + + chosen = self.delivery.eligible(now=self.clock.now(), limit=4) + + parents = {row["parent_task_id"] for row in chosen} + self.assertIn("01parent-b", parents, "the newer parent was never even considered") + self.assertIn(newer[0], [row["event_id"] for row in chosen]) + + def test_an_explicit_bulk_limit_is_not_capped_by_the_per_tick_share(self): + """deliver --limit is an operator asking for a bulk send, not a tick. + + The per-parent share exists so one parent cannot fill a tick's window against the + others. Applying it to an explicit limit made `deliver --limit 20` against a single + parent quietly send two. Fairness across parents does not depend on the share: + eligible() deals rows one parent at a time whatever the window is. + """ + self.assignment("solo", events=20) + share = self.delivery.policy.max_sends_per_parent_per_tick + self.assertLess(share, 20, "the fixture has to exceed the share to say anything") + + tick = self.delivery.eligible(now=self.clock.now(), limit=20) + bulk = self.delivery.eligible(now=self.clock.now(), limit=20, per_parent_limit=20) + + self.assertEqual(len(tick), share, "the tick still respects its own share") + self.assertEqual(len(bulk), 20, "an explicit limit was capped by the tick share") + + def test_a_bulk_limit_still_deals_between_parents(self): + """Lifting the per-parent window must not turn a bulk send into one parent's queue.""" + self.assignment("x", events=10) + self.assignment("y", events=10) + + chosen = self.delivery.eligible(now=self.clock.now(), limit=6, per_parent_limit=6) + + parents = [row["parent_task_id"] for row in chosen] + self.assertEqual(len(chosen), 6) + self.assertEqual(len(set(parents)), 2, f"one parent took the whole bulk: {parents}") + + def test_the_share_is_even_rather_than_dealt_in_blocks(self): + for name in ("a", "b", "c"): + self.assignment(name, events=10) + counts = {} + # The advancing head is what makes the odd slot circulate; without it the same + # parent takes it every time, which is the 18/9/9 split this used to produce. + for tick in range(9): + for row in self.delivery.eligible(now=self.clock.now(), limit=4, cursor=tick): + counts[row["parent_task_id"]] = counts.get(row["parent_task_id"], 0) + 1 + spread = max(counts.values()) - min(counts.values()) + self.assertEqual(len(counts), 3) + self.assertLessEqual(spread, 1, f"uneven share: {counts}") + + def test_the_rotation_is_persisted_and_moves_between_ticks(self): + for name in ("a", "b", "c"): + self.assignment(name, events=6) + first = self.daemon._cursor("delivery_parents", 3) + self.daemon.tick(now=self.clock.now()) + second = self.daemon._cursor("delivery_parents", 3) + self.assertNotEqual(second, first, "the head must move, or the odd slot never moves") + stored = self.store.one( + "SELECT cursor FROM discovery_cursors WHERE listing = ?", ("delivery_parents",), + ) + self.assertIsNotNone(stored, "the delivery rotation must survive a restart") + + def test_a_struggling_parent_does_not_spend_the_whole_budget(self): + """Busy is a returned outcome, not an exception, and it used to eat the tick.""" + self.assignment("a", events=8) + _relationship, healthy = self.assignment("b", events=1) + self.adapter.set_status("01parent-a", "active") + + report = self.daemon.tick(now=self.clock.now()) + + delivered = [thread for _r, thread, _m, _o in self.adapter.sends] + self.assertIn("01parent-b", delivered, "the healthy parent was starved by the busy one") + self.assertGreaterEqual(report.deferred, 1) + + def test_cancelling_one_assignment_leaves_the_others_served(self): + cancelled, _ids = self.assignment("a", events=2) + _relationship, healthy = self.assignment("b", events=1) + self.registry.set_status(cancelled["relationshipId"], "cancelled", actor="test") + + report = self.daemon.tick(now=self.clock.now()) + + delivered = [thread for _r, thread, _m, _o in self.adapter.sends] + self.assertIn("01parent-b", delivered) + self.assertNotIn("01parent-a", delivered, "a cancelled assignment is not served") + self.assertFalse(report.quiet) + + +class ReconciliationFairness(ParentFixture): + def dealt_over(self, ticks): + """Which attempts _reconcile actually handed to the gate, across several ticks.""" + from codex_session_relay.daemon import TickReport + + seen = set() + original = self.daemon._gate + + def spy(attempt): + seen.add(attempt["request_id"]) + return original(attempt) + + self.daemon._gate = spy + try: + for _tick in range(ticks): + self.daemon._reconcile(TickReport(), self.clock.now()) + finally: + self.daemon._gate = original + return seen + + def unresolved(self, name, count): + """Attempts whose response was lost, which is what reconciliation has to settle.""" + _relationship, ids = self.assignment(name, events=count) + for event_id in ids: + self.adapter.script("transport_unknown") + self.clock.advance(3600) + self.delivery.attempt(event_id, self.adapter, now=self.clock.now()) + return ids + + def test_one_parents_backlog_does_not_hide_another_parents_attempt(self): + self.unresolved("a", 10) + newer = self.unresolved("b", 1) + + parents = self.reconciler.open_parents() + self.assertEqual(set(parents), {"01parent-a", "01parent-b"}) + dealt = self.reconciler.open_attempts(limit=4, parents=["01parent-b"]) + self.assertTrue(dealt, "the second parent has unresolved work and must be reachable") + self.assertEqual({row["parent_task_id"] for row in dealt}, {"01parent-b"}) + del newer + + def test_recovery_still_sees_everything(self): + """The bounded form is for the tick; recovery must stay exhaustive.""" + self.unresolved("a", 6) + self.assertEqual(len(self.reconciler.open_attempts()), 6) + self.assertEqual(len(self.reconciler.open_attempts(limit=2)), 2) + + def test_every_attempt_of_one_parent_is_reached_across_ticks(self): + """The parent order had a cursor; the attempts inside a parent did not. + + _gate skips an attempt whose fingerprint has not changed, but the skipped attempt + still held its place in the prefix, so with more unresolved attempts than the share + the ones behind them were never reconciled at all - and an anchor waiting on one of + them would never bind. + """ + self.unresolved("a", 9) + self.unresolved("b", 1) + self.unresolved("c", 1) + + reached = self.dealt_over(12) + + everything = {row["request_id"] + for row in self.reconciler.open_attempts(parents=["01parent-a"])} + self.assertEqual(len(everything), 9) + self.assertEqual( + reached & everything, everything, + "a fixed prefix leaves the attempts behind it permanently unreconciled", + ) + + def test_the_attempt_cursor_is_persisted_per_parent(self): + budget = self.daemon.policy.max_reconciles_per_tick + self.unresolved("a", budget + 2) + self.dealt_over(1) + stored = self.store.one( + "SELECT cursor FROM discovery_cursors WHERE listing = ?", + ("reconcile:01parent-a",), + ) + self.assertIsNotNone(stored, "the rotation must survive a restart") + self.assertEqual( + int(stored["cursor"]), budget, + "exactly as far as the attempts this tick actually dealt", + ) + + def test_a_cursor_moves_only_past_attempts_that_were_actually_dealt(self): + """Advancing at selection time skipped attempts the budget then dropped. + + With more parents than budget the parent rotation and the attempt cursors moved + together, so the same attempts could be stepped over on every tick - permanently. + """ + # MORE parents than the budget, which is the shape that exposes it: every parent is + # selected and had its cursor advanced, but only the first budgeted queues are dealt. + budget = self.daemon.policy.max_reconciles_per_tick + for index in range(budget + 4): + self.unresolved(f"p{index}", 3) + + reached = self.dealt_over(80) + + everything = {row["request_id"] for row in self.reconciler.open_attempts()} + self.assertEqual(len(everything), (budget + 4) * 3) + self.assertEqual( + reached & everything, everything, + "every unresolved attempt must be reached in a finite number of ticks", + ) + + def test_a_parent_that_was_dealt_nothing_keeps_its_place(self): + """The precise defect: a cursor advanced for work the budget then dropped. + + With more parents than the budget, every parent is selected and only the first + budgeted queues are dealt. Advancing inside the selection moved the cursors of the + parents that got nothing, so their leading attempts were stepped over unread. + """ + from codex_session_relay.daemon import TickReport + + budget = self.daemon.policy.max_reconciles_per_tick + for index in range(budget + 4): + self.unresolved(f"p{index}", 3) + + self.daemon._reconcile(TickReport(), self.clock.now()) + + dealt_parents = { + row["listing"].split(":", 1)[1] + for row in self.store.all( + "SELECT listing, cursor FROM discovery_cursors WHERE listing LIKE 'reconcile:%'" + ) + if int(row["cursor"]) > 0 + } + self.assertLessEqual( + len(dealt_parents), budget, + "a cursor moved for a parent this tick never reconciled", + ) + + +class DeliveryRotation(ParentFixture): + """A delivery that fails without changing its own state must not block its successors.""" + + def test_a_persistently_failing_delivery_does_not_block_the_rest(self): + """eligible_for_parent returned the same oldest prefix on every tick. + + The failing row stays eligible and stays oldest, and the struggling set suppresses + every later row within the tick, so its successors were never attempted at all. + """ + _relationship, ids = self.assignment("a", events=6) + first = ids[0] + original = self.delivery.attempt + + def attempt(event_id, adapter, *, now=None): + if event_id == first: + raise RuntimeError("this one fails before it changes state") + return original(event_id, adapter, now=now) + + seen = set() + + def watched(event_id, adapter, *, now=None): + seen.add(event_id) + return attempt(event_id, adapter, now=now) + + self.delivery.attempt = watched + try: + for _tick in range(20): + self.clock.advance(1) + self.daemon.tick(now=self.clock.now()) + finally: + self.delivery.attempt = original + + self.assertEqual( + seen & set(ids[1:]), set(ids[1:]), + "every delivery behind the failing one must be attempted in a finite number of ticks", + ) + + def test_the_delivery_cursor_moves_only_past_what_was_attempted(self): + """A row the budget dropped was never looked at; moving past it skips work.""" + budget = self.daemon.policy.max_sends_per_tick + for index in range(budget + 3): + self.assignment(f"p{index}", events=2) + + self.daemon.tick(now=self.clock.now()) + + moved = [ + row["listing"] for row in self.store.all( + "SELECT listing, cursor FROM discovery_cursors WHERE listing LIKE 'deliver:%'") + if int(row["cursor"]) > 0 + ] + self.assertLessEqual( + len(moved), budget, + "a cursor moved for a parent this tick never attempted", + ) + + def test_the_delivery_cursor_is_persisted(self): + """The rotation has to survive a restart, or it starts from the head every time.""" + self.assignment("a", events=6) + self.daemon.tick(now=self.clock.now()) + stored = self.store.one( + "SELECT cursor FROM discovery_cursors WHERE listing = ?", ("deliver:01parent-a",), + ) + self.assertIsNotNone(stored) + self.assertGreater(int(stored["cursor"]), 0) + + +class SharedChildTurns(DaemonTestCase): + """Two assignments can legitimately be watching the same child turn.""" + + def two_parents_on_one_child(self): + """Different parents, different issues, one child thread and one anchor turn.""" + from codex_session_relay.registry import record_settings + from .support import task_settings + + child, turn = "01child-shared", "turn-shared-1" + made = [] + for name in ("a", "b"): + parent = f"01parent-{name}" + root = os.path.join(self.root, name) + os.makedirs(root, exist_ok=True) + made.append(self.registry.register( + parent=Endpoint(parent, HOST, cwd=f"/p/{name}"), + child=Endpoint(child, HOST, cwd=root), + issue_key=f"SHARED-{name}", artifact_roots=[root], + allowed_recipients=[parent], + dispatch_request_id=f"dispatch-{name}", dispatch_turn_id=turn, + )) + self.adapter.add_thread(parent) + record_settings(self.store, self.clock, parent, task_settings(f"/p/{name}"), + source="creation_result") + self.adapter.add_thread(child) + return made, child, turn + + def test_a_failed_shared_turn_reaches_every_parent_waiting_on_it(self): + """_already_observed asked globally, so the first settlement closed the turn for all. + + The second assignment never reached _synthesize, and a failed turn suppresses the + staged claim rather than finalizing it - so its parent was left waiting on a verdict + that can never arrive. + """ + relationships, child, turn = self.two_parents_on_one_child() + self.adapter.start_turn(child, turn_id=turn, status="inProgress") + self.adapter.finish_turn(child, turn, status="failed") + + # The relationship rotation serves a bounded number per tick, so both are reached + # across ticks rather than in one. What matters is that neither is closed out by + # the other's observation. + for _tick in range(4): + self.clock.advance(60) + self.daemon.tick(now=self.clock.now()) + + owners = { + self.intake.row(row["event_id"])["relationship_id"] + for row in self.store.all("SELECT event_id FROM events") + } + self.assertEqual( + owners, {r["relationshipId"] for r in relationships}, + "both parents must get a terminal outcome for the turn they shared", + ) + recipients = {thread for _r, thread, _m, _o in self.adapter.sends} + self.assertEqual(recipients, {"01parent-a", "01parent-b"}) + + def test_a_staged_claim_on_a_shared_turn_is_settled_only_by_its_owner(self): + """_turns_to_poll collected staged turns by CHILD THREAD, not by assignment. + + A staged claim owned by B could be selected by A, and resolve_staged_in selected by + (thread, turn) alone - so A suppressed B's claim while daemon_observation refused to + synthesize a receipt for A. B's parent waited on an outcome already thrown away. + """ + import os + + relationships, child, turn = self.two_parents_on_one_child() + # The owner is the assignment the relationship rotation reaches SECOND, so the + # non-owner polls this turn first. That ordering is the whole defect: whoever polls + # first used to settle it for everyone. + other, owner = relationships[0], relationships[1] + # A continuation turn that is NEITHER assignment's anchor, staged by the owner only. + self.adapter.start_turn(child, turn_id="turn-shared-2", status="inProgress") + root = os.path.join(self.root, "b") + os.makedirs(root, exist_ok=True) + path = os.path.join(root, "late.txt") + with open(path, "w", encoding="utf-8") as handle: + handle.write("owned by exactly one assignment") + payload = self.ready_payload( + owner, [path], turn=TurnRef(child, "turn-shared-2", "inProgress"), + ) + # A turn other than the anchor is admitted only with an explicit continuation, which + # is what makes this claim unambiguously ONE assignment's. + self.intake.accept_child_receipt( + payload, observation=TurnRef(child, "turn-shared-2", "inProgress"), + continuation={"anchorTurnId": turn, "actor": child, + "reason": "continuation of this execution"}, + ) + event_id = payload["eventId"] + + self.assertEqual( + [row["turn_id"] for row in self.intake.staged_events( + thread_id=child, relationship_id=other["relationshipId"])], + [], + "the fixture needs this claim to belong to exactly one assignment", + ) + self.adapter.finish_turn(child, "turn-shared-2", status="failed") + for _tick in range(6): + self.clock.advance(1) + self.daemon.tick(now=self.clock.now()) + + # A failed turn SUPPRESSES the staged claim, so the outcome the owner's parent is + # waiting for can only come from a synthesized execution-only receipt. That is the + # part the global settlement destroyed: it suppressed the claim on behalf of the + # other assignment, whose daemon_observation refused to synthesize anything, and the + # turn then left the owner's ring with nothing recorded. + self.assertEqual(self.intake.row(event_id)["stage"], "suppressed") + outcomes = [ + row for row in self.store.all( + "SELECT * FROM events WHERE relationship_id = ? AND turn_id = ?", + (owner["relationshipId"], "turn-shared-2"), + ) + if row["outcome"] in ("failed", "interrupted") + ] + self.assertTrue( + outcomes, + "the owner must still produce a terminal outcome for the parent waiting on it", + ) + self.assertEqual(outcomes[0]["stage"], "final") + + def test_an_inactive_assignments_staged_turn_stays_out_of_an_active_ring(self): + """A paused assignment is absent from _active_relationships and must stay absent. + + Collecting staged turns by thread put its work into an active assignment's ring, and + the globally scoped settlement then finalized it and created a delivery intent that + was retried for an assignment nothing should be processing. + """ + import os + + relationships, child, turn = self.two_parents_on_one_child() + paused, active = relationships[0], relationships[1] + self.adapter.start_turn(child, turn_id="turn-shared-3", status="inProgress") + root = os.path.join(self.root, "a") + os.makedirs(root, exist_ok=True) + path = os.path.join(root, "paused.txt") + with open(path, "w", encoding="utf-8") as handle: + handle.write("belongs to the assignment that is about to pause") + payload = self.ready_payload( + paused, [path], turn=TurnRef(child, "turn-shared-3", "inProgress"), + ) + self.intake.accept_child_receipt( + payload, observation=TurnRef(child, "turn-shared-3", "inProgress"), + continuation={"anchorTurnId": turn, "actor": child, + "reason": "continuation of this execution"}, + ) + self.registry.set_status(paused["relationshipId"], "paused", actor="test") + self.adapter.finish_turn(child, "turn-shared-3", status="completed") + + for _tick in range(6): + self.clock.advance(1) + self.daemon.tick(now=self.clock.now()) + + self.assertEqual( + self.intake.row(payload["eventId"])["stage"], "staged", + "a paused assignment's claim must not be settled through an active one", + ) + self.assertIsNone( + self.delivery.find(payload["eventId"]), + "and nothing may be queued on its behalf", + ) + del active + + def test_one_assignment_is_still_settled_only_once(self): + """Per-assignment must not become per-tick: the same turn is not re-observed.""" + relationships, child, turn = self.two_parents_on_one_child() + self.adapter.start_turn(child, turn_id=turn, status="inProgress") + self.adapter.finish_turn(child, turn, status="failed") + for _tick in range(4): + self.clock.advance(60) + self.daemon.tick(now=self.clock.now()) + before = self.store.one("SELECT COUNT(*) AS c FROM events")["c"] + + for _tick in range(4): + self.clock.advance(60) + self.daemon.tick(now=self.clock.now()) + + self.assertEqual(self.store.one("SELECT COUNT(*) AS c FROM events")["c"], before) + self.assertEqual(len(self.adapter.sends), len(relationships)) + + +if __name__ == "__main__": + unittest.main() + + +class SelectionCost(ParentFixture): + """Query count is not query cost, so the plan is inspected rather than assumed.""" + + def test_the_per_parent_query_uses_an_index_rather_than_scanning(self): + self.assignment("a", events=30) + self.assignment("b", events=1) + plan = self.store.all( + "EXPLAIN QUERY PLAN SELECT d.*, r.parent_task_id AS parent_task_id" + " FROM deliveries d" + " JOIN relationships r ON r.relationship_id = d.relationship_id" + " JOIN events e ON e.event_id = d.event_id" + " WHERE d.state IN (?,?,?) AND d.hold_reason IS NULL" + " AND (d.next_eligible_at IS NULL OR d.next_eligible_at <= ?)" + " AND r.status = 'active' AND r.superseded_by IS NULL AND e.stage = 'final'" + " AND r.parent_task_id = ?" + " ORDER BY d.created_at LIMIT ? OFFSET ?", + ("queued", "deferred_busy", "withheld_pre_send", self.clock.now(), + "01parent-b", 2, 0), + ) + detail = " | ".join(row["detail"] for row in plan) + self.assertIn("deliveries", detail) + # Recorded rather than asserted as a hard shape: SQLite may legitimately choose a + # different index as the schema grows. What matters is that a reviewer can see it. + self.assertTrue(detail, "the query plan must be inspectable") + + def test_selection_issues_a_bounded_number_of_queries(self): + for name in ("a", "b", "c"): + self.assignment(name, events=20) + seen = [] + original = self.store.all + self.store.all = lambda sql, params=(): (seen.append(sql), original(sql, params))[1] + try: + self.delivery.eligible(now=self.clock.now(), limit=4) + finally: + self.store.all = original + # One parent query plus one per eligible parent. It does not grow with backlog size. + self.assertEqual(len(seen), 4, seen) diff --git a/packages/codex-session-relay/tests/test_observation_budget.py b/packages/codex-session-relay/tests/test_observation_budget.py new file mode 100644 index 0000000..b5f19b5 --- /dev/null +++ b/packages/codex-session-relay/tests/test_observation_budget.py @@ -0,0 +1,233 @@ +"""The observation budget must never permanently skip the current generation. + +Reproduced in real operation as JUN-100 generation 11 and JUN-101 generation 13: the daemon +was alive and inside its time bound, the child turns were completed, and the events sat staged +with no delivery forever. + +_turns_to_poll collected every generation anchor oldest-first, sliced to the per-tick budget, +and _observe filtered already-observed turns AFTER that slice. Past eight generations the +slice was permanently the first eight, all of them already observed, so the current generation +was never selected again. +""" + +from codex_session_relay.models import TurnRef + +from .support import CHILD, DeliveryTestCase + +from .test_daemon import DaemonTestCase + + +class ObservationBudget(DaemonTestCase): + def history(self, generations: int): + """A relationship whose generation count is past the per-tick budget. + + Every older anchor is a completed turn that has ALREADY been observed, which is the + ordinary state of a long-running assignment and the exact state that starved the", + current one. + """ + relationship = self.register() + self._rid = relationship["relationshipId"] + for number in range(2, generations + 1): + turn_id = f"turn-dispatch-{number}" + self.adapter.start_turn(CHILD, turn_id=turn_id, status="inProgress") + self.registry.open_generation( + self._rid, dispatch_request_id=f"dispatch-{number}", + reason="needs_changes_revision", dispatch_turn_id=turn_id, + ) + self.adapter.finish_turn(CHILD, turn_id, status="completed") + # The first anchor too. + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + self.adapter.finish_turn(CHILD, "turn-dispatch-1", status="completed") + return self.registry.get(self._rid) + + def observe_everything_older(self, current: int): + """Mark every anchor except the current one as already seen.""" + for number in range(1, current): + self.intake.record_observation( + TurnRef(CHILD, f"turn-dispatch-{number}", "completed"), "execution_only", + relationship_id=self._rid, + ) + + def staged_on_current(self, relationship, generation: int): + turn_id = f"turn-dispatch-{generation}" + self.adapter.start_turn(CHILD, turn_id=turn_id + "-live", status="inProgress") + path = self.artifact("out.txt", "work for the current generation") + payload = self.ready_payload( + relationship, [path], generation=generation, + turn=TurnRef(CHILD, turn_id, "inProgress"), + ) + self.accept(payload) + return payload["eventId"] + + def test_the_current_generation_is_polled_however_long_the_history_is(self): + relationship = self.history(12) + self.observe_everything_older(12) + event_id = self.staged_on_current(relationship, 12) + self.assertEqual(self.intake.row(event_id)["stage"], "staged") + + self.daemon.tick(now=self.clock.now()) + + self.assertEqual( + self.intake.row(event_id)["stage"], "final", + "twelve generations of already-observed history starved the current one", + ) + + def test_a_tick_never_exceeds_its_read_budget(self): + relationship = self.history(12) + self.observe_everything_older(12) + self.staged_on_current(relationship, 12) + reads = [] + original = self.adapter.read_turn + self.adapter.read_turn = lambda thread, turn: ( + reads.append(turn), original(thread, turn), + )[1] + self.daemon.tick(now=self.clock.now()) + self.assertLessEqual( + len(reads), self.daemon.policy.max_turn_reads_per_tick, + "the bound the loop promises must hold even while it catches up", + ) + + def test_a_receipt_staged_after_the_turn_was_observed_is_still_resolved(self): + """The ordering the old guard got wrong: already observed is not already finished.""" + relationship = self.register() + self._rid = relationship["relationshipId"] + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + self.adapter.finish_turn(CHILD, "turn-dispatch-1", status="completed") + self.daemon.tick(now=self.clock.now()) + self.assertIsNotNone( + self.store.one( + "SELECT 1 FROM observations WHERE turn_id = ?", ("turn-dispatch-1",), + ), + ) + + # The receipt lands AFTER the completion was observed. + path = self.artifact("late.txt", "written just after the turn ended") + payload = self.ready_payload( + relationship, [path], turn=TurnRef(CHILD, "turn-dispatch-1", "inProgress"), + ) + self.accept(payload) + self.assertEqual(self.intake.row(payload["eventId"])["stage"], "staged") + + self.daemon.tick(now=self.clock.now()) + + self.assertEqual( + self.intake.row(payload["eventId"])["stage"], "final", + "a turn already observed must still have its later staged claim resolved", + ) + + +class SchedulingFairness(DaemonTestCase): + """The finite-coverage claim, under the shapes that break a prefix.""" + + def relationship(self, suffix, *, generations=1): + from codex_session_relay.models import Endpoint + + child = f"01child-{suffix}" + root = self.artifact(f"{suffix}/seed.txt", "seed") + record = self.registry.register( + parent=Endpoint(f"01parent-{suffix}", "host-a", cwd=f"/p/{suffix}"), + child=Endpoint(child, "host-a", cwd=f"/c/{suffix}"), + issue_key=f"REL-{suffix}", artifact_roots=[self.root], + allowed_recipients=[f"01parent-{suffix}"], + dispatch_request_id=f"dispatch-{suffix}-1", + dispatch_turn_id=f"turn-{suffix}-1", + ) + self.adapter.add_thread(child) + for number in range(1, generations + 1): + turn_id = f"turn-{suffix}-{number}" + self.adapter.start_turn(child, turn_id=turn_id, status="inProgress") + if number > 1: + self.registry.open_generation( + record["relationshipId"], + dispatch_request_id=f"dispatch-{suffix}-{number}", + reason="needs_changes_revision", dispatch_turn_id=turn_id, + ) + self.adapter.finish_turn(child, turn_id, status="completed") + del root + return record, child + + def observed_turns(self): + return { + row["turn_id"] for row in self.store.all("SELECT turn_id FROM observations") + } + + def test_every_relationship_is_served_even_past_the_read_budget(self): + """More relationships than the tick can read, so the rotation has to carry them.""" + names = [f"r{index}" for index in range(12)] + for name in names: + self.relationship(name) + for _ in range(24): + self.daemon.tick(now=self.clock.now()) + self.clock.advance(1) + seen = self.observed_turns() + missing = [name for name in names if f"turn-{name}-1" not in seen] + self.assertEqual(missing, [], "the rotation left relationships unserved") + + def test_an_empty_window_does_not_pin_the_rotation(self): + """The cursor has to move even when the served relationships had nothing to do.""" + idle = [f"i{index}" for index in range(6)] + for name in idle: + self.relationship(name) + # Drain them, so the next ticks select windows with no candidates at all. + for _ in range(12): + self.daemon.tick(now=self.clock.now()) + self.clock.advance(1) + self.assertTrue(all(f"turn-{name}-1" in self.observed_turns() for name in idle)) + + record, child = self.relationship("latecomer") + for _ in range(12): + self.daemon.tick(now=self.clock.now()) + self.clock.advance(1) + self.assertIn( + "turn-latecomer-1", self.observed_turns(), + "a window of relationships with nothing to do must not pin the cursor", + ) + + def test_a_backlog_larger_than_the_share_is_covered_in_finite_ticks(self): + record, child = self.relationship("deep", generations=9) + for _ in range(20): + self.daemon.tick(now=self.clock.now()) + self.clock.advance(1) + seen = self.observed_turns() + missing = [n for n in range(1, 10) if f"turn-deep-{n}" not in seen] + self.assertEqual(missing, [], "the ring cursor did not cover the whole backlog") + + def test_the_rotation_survives_a_restart(self): + from codex_session_relay.daemon import RelayDaemon + + for index in range(8): + self.relationship(f"s{index}") + self.daemon.tick(now=self.clock.now()) + first = self.store.one( + "SELECT cursor FROM discovery_cursors WHERE listing = ?", ("relationships",), + ) + self.assertIsNotNone(first, "the rotation is persisted, not held in memory") + fresh = RelayDaemon( + self.store, self.registry, self.intake, self.delivery, self.ack, + self.reconciler, self.adapter, clock=self.clock, + ) + self.clock.advance(1) + fresh.tick(now=self.clock.now()) + second = self.store.one( + "SELECT cursor FROM discovery_cursors WHERE listing = ?", ("relationships",), + ) + self.assertNotEqual(second["cursor"], first["cursor"]) + + def test_a_turn_that_cannot_be_read_does_not_pin_the_ring(self): + record, child = self.relationship("blocked", generations=4) + original = self.adapter.read_turn + + def refuse(thread, turn): + if turn == "turn-blocked-1": + raise ConnectionError("this one never answers") + return original(thread, turn) + + self.adapter.read_turn = refuse + for _ in range(16): + self.daemon.tick(now=self.clock.now()) + self.clock.advance(1) + seen = self.observed_turns() + self.assertTrue( + {"turn-blocked-2", "turn-blocked-3", "turn-blocked-4"} <= seen, + "one unreadable turn must not starve the rest of the ring", + ) diff --git a/packages/codex-session-relay/tests/test_supersession.py b/packages/codex-session-relay/tests/test_supersession.py new file mode 100644 index 0000000..2ab024f --- /dev/null +++ b/packages/codex-session-relay/tests/test_supersession.py @@ -0,0 +1,464 @@ +"""A stale event must be stopped before the send, not rejected after it. + +Reproduced 2026-09-16: JUN-119 generation 2 events delivered after generation 3 started, and +JUN-100 generation 5 delivered after generation 7, every one rejected downstream as +disposition_conflict: stale_generation. They had been waiting on a busy parent, and the wait +ending was treated as permission to send. +""" + +from codex_session_relay import identity +from codex_session_relay.currency import STALE_GENERATION, SUPERSEDED as SUPERSEDED_REVISION +from codex_session_relay.models import TurnRef +from codex_session_relay.transport import DEFERRED_BUSY, DISPATCHED, SUPERSEDED + +from .support import CHILD, PARENT, DeliveryTestCase + + +class PreSendSupersession(DeliveryTestCase): + def advance_generation(self, relationship, number): + """Open the next generation, as a needs_changes verdict would.""" + turn_id = f"turn-dispatch-{number}" + self.adapter.start_turn(CHILD, turn_id=turn_id, status="inProgress") + return self.registry.open_generation( + relationship["relationshipId"], dispatch_request_id=f"dispatch-{number}", + reason="needs_changes_revision", dispatch_turn_id=turn_id, + ) + + def queued_outcome(self, outcome): + """A queued completion carrying the given outcome, on generation 1.""" + relationship = self.register() + self._rid = relationship["relationshipId"] + if outcome == "ready_for_review": + path = self.artifact("out.txt", "the deliverable") + payload = self.ready_payload(relationship, [path]) + else: + payload = self.execution_payload(relationship, outcome) + self.accept(payload) + self.delivery.enqueue(payload["eventId"]) + return relationship, payload["eventId"] + + def test_a_queued_delivery_is_annotated_when_the_generation_advances(self): + """_claim does suppress a stale queued row - but attempt() can return BEFORE _claim. + + Rate limiting, a busy recipient, an unavailable host all return early, and a recipient + that is never free means _claim is never reached at all. Generation advance already + knows the row is stale, so leaving it unannotated let it retry indefinitely while + every status read reported it as current. + """ + relationship, event_id = self.queued_outcome("ready_for_review") + self.assertEqual(self.delivery.get(event_id)["state"], "queued") + + self.advance_generation(relationship, 2) + + note = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (event_id,), + ) + self.assertIsNotNone(note, "a stale queued delivery said nothing about being stale") + self.assertEqual(note["reason"], STALE_GENERATION) + + def test_an_outstanding_send_is_annotated_when_the_generation_advances(self): + """attempt() rejects a non-claimable state, so nothing reached the pre-send check. + + A delivery that was sending or held_uncertain as a newer generation opened therefore + got no delivery_supersession row at all. It could reconcile to dispatched and be + presented as an ordinary current delivery rather than as history. + """ + relationship, event_id = self.queued_outcome("ready_for_review") + self.adapter.script("transport_unknown") + self.attempt(event_id) + self.assertEqual(self.delivery.get(event_id)["state"], "held_uncertain") + + self.advance_generation(relationship, 2) + + note = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (event_id,), + ) + self.assertIsNotNone(note, "the outstanding send is no longer current and says so") + self.assertEqual(note["reason"], STALE_GENERATION) + self.assertEqual( + self.delivery.get(event_id)["state"], "held_uncertain", + "annotated, never rewritten: a lost response still has to be reconcilable", + ) + item = [d for d in self.delivery.snapshot()["deliveries"] + if d["eventId"] == event_id][0] + self.assertIsNotNone(item["supersededNote"]) + + def test_a_current_generations_delivery_is_left_alone(self): + """The annotation must not mark the generation that is actually running.""" + relationship, event_id = self.queued_outcome("ready_for_review") + self.adapter.script("transport_unknown") + self.attempt(event_id) + self.advance_generation(relationship, 2) + self.store.db.execute( + "DELETE FROM delivery_supersession WHERE event_id = ?", (event_id,), + ) + + self.advance_generation(relationship, 3) + + rows = self.store.all("SELECT event_id FROM delivery_supersession") + self.assertEqual([r["event_id"] for r in rows], [event_id], + "only the older generation's outstanding send is annotated") + + def test_a_capped_delivery_is_annotated_when_the_generation_advances(self): + """Generation advance is the ONLY chance a capped delivery ever gets. + + Once a busy or pre-send cap sets hold_reason, attempt() returns before the pre-send + supersession check, so nothing else can ever annotate it. Leaving the capped states + out of the annotation meant status reported a current-looking cap forever. + """ + relationship, event_id = self.queued_outcome("ready_for_review") + with self.store.transaction() as db: + db.execute( + "UPDATE deliveries SET state = ?, hold_reason = ? WHERE event_id = ?", + (DEFERRED_BUSY, "busy_cap", event_id), + ) + + self.advance_generation(relationship, 2) + + note = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (event_id,), + ) + self.assertIsNotNone(note, "a capped delivery has no other annotation opportunity") + self.assertEqual(note["reason"], STALE_GENERATION) + row = self.delivery.get(event_id) + self.assertEqual(row["state"], DEFERRED_BUSY, "the cap itself is history, untouched") + self.assertEqual(row["holdReason"] if "holdReason" in row.keys() else "busy_cap", + "busy_cap") + item = [d for d in self.delivery.snapshot()["deliveries"] + if d["eventId"] == event_id][0] + self.assertEqual(item["phase"], f"superseded:{STALE_GENERATION}") + + def test_a_capped_withheld_delivery_is_annotated_too(self): + relationship, event_id = self.queued_outcome("ready_for_review") + with self.store.transaction() as db: + db.execute( + "UPDATE deliveries SET state = ?, hold_reason = ? WHERE event_id = ?", + ("withheld_pre_send", "presend_cap", event_id), + ) + + self.advance_generation(relationship, 2) + + note = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (event_id,), + ) + self.assertIsNotNone(note) + self.assertEqual(note["reason"], STALE_GENERATION) + + def test_a_dispatched_delivery_is_annotated_when_the_generation_advances(self): + """Its acknowledgement will be refused as stale_generation, so awaiting_ack lies. + + Excluding dispatched left status reporting an obligation that can no longer be met, + with no supersession note to say why. + """ + relationship, event_id = self.queued_outcome("ready_for_review") + self.attempt(event_id) + self.assertEqual(self.delivery.get(event_id)["state"], DISPATCHED) + + self.advance_generation(relationship, 2) + + note = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (event_id,), + ) + self.assertIsNotNone(note) + self.assertEqual(note["reason"], STALE_GENERATION) + self.assertEqual( + self.delivery.get(event_id)["state"], DISPATCHED, + "annotated, not rewritten: what was actually sent stays history", + ) + + def test_an_annotated_send_is_not_reported_as_awaiting_anything(self): + """Its state is left alone so a lost response stays reconcilable. + + That is the right call for reconciliation and the wrong one for an operator: status + went on reporting awaiting_ack for an obligation nothing can now meet. + """ + relationship, event_id = self.queued_outcome("ready_for_review") + self.attempt(event_id) + self.assertEqual(self.delivery.get(event_id)["state"], DISPATCHED) + + self.advance_generation(relationship, 2) + + item = [d for d in self.delivery.snapshot()["deliveries"] + if d["eventId"] == event_id][0] + self.assertNotEqual(item["phase"], "awaiting_ack") + self.assertEqual(item["phase"], f"superseded:{STALE_GENERATION}") + self.assertEqual(item["state"], DISPATCHED, "the history is untouched") + + def test_a_terminal_receipt_annotates_its_predecessor_without_a_settlement(self): + """A receipt the host already reports terminal never touches the settlement path. + + It goes straight through acceptance and enqueue, so an annotation hung only off + settlement missed it entirely. + """ + relationship, older = self.queued_outcome("ready_for_review") + self.adapter.script("transport_unknown") + self.attempt(older) + self.assertEqual(self.delivery.get(older)["state"], "held_uncertain") + + path = self.artifact("newer.txt", "the corrected deliverable") + successor = self.ready_payload(relationship, [path], attempt=2) + self.accept(successor) + with self.store.transaction() as db: + db.execute( + "UPDATE revision_lineage SET supersedes_hash = ? WHERE event_id = ?", + (self.intake.get(older)["revisionHash"], successor["eventId"]), + ) + self.assertEqual(self.intake.row(successor["eventId"])["stage"], "final") + + self.delivery.enqueue(successor["eventId"]) + + note = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (older,), + ) + self.assertIsNotNone(note, "enqueue is the route every deliverable event takes") + self.assertEqual(note["reason"], SUPERSEDED_REVISION) + + def test_a_re_emitted_final_receipt_still_reports_its_stage(self): + """Acceptance and enqueue are separate transactions on the command line. + + A receipt whose acceptance committed and whose enqueue then failed is retried - and + the duplicate return carried no stage at all, so the caller's "if this is final, + queue it" never ran and the accepted event stayed permanently without a delivery row. + Nothing else recovers that: the requeue pass looks for events that have a recorded + delivery intent, and a failure before the intent leaves none. + """ + relationship = self.register() + path = self.artifact("out.txt", "the deliverable") + payload = self.ready_payload(relationship, [path]) + first = self.accept(payload) + self.assertEqual(first["_stage"], "final") + + again = self.accept(payload) + + self.assertTrue(again["_duplicate"]) + self.assertEqual( + again["_stage"], "final", + "a retry could not tell the caller this receipt still needs queuing", + ) + + def test_a_later_execution_only_outcome_survives_a_final_revision_head(self): + """The head rule is one REVISION replacing another, and it was applied to everything. + + A generation that produced a reviewable revision and then ended failed, interrupted + or blocked was measured against its own final head and suppressed before any + transport call - so the parent never learned the assignment had ended, while the + generation was still current and the event declared no supersession of its own. + """ + relationship, reviewable = self.queued_outcome("ready_for_review") + self.attempt(reviewable) + self.assertEqual(self.intake.row(reviewable)["stage"], "final") + + later = self.execution_payload(relationship, "failed") + self.accept(later) + self.delivery.enqueue(later["eventId"]) + + # The rule itself, which is what _claim consults immediately before the send. + with self.store.transaction() as db: + reason = self.delivery._supersession_reason(db, later["eventId"]) + + self.assertIsNone( + reason, + "the generation's own terminal outcome was read as replaced by its revision, so" + " the parent never learns the assignment ended", + ) + self.assertNotEqual( + self.delivery.get(later["eventId"])["state"], SUPERSEDED, + ) + + def test_a_queued_predecessor_is_annotated_by_its_successor(self): + """Same generation, and the predecessor has not reached the transport at all. + + _claim does suppress a stale queued predecessor - but attempt() returns before _claim + for a rate limit, a busy recipient or unreadable settings, and a recipient that is + never free means _claim is never reached. Until then the predecessor stays eligible, + keeps retrying, and carries none of the supersession phase the diagnostics promise. + """ + relationship, older = self.queued_outcome("ready_for_review") + self.assertEqual(self.delivery.get(older)["state"], "queued") + + path = self.artifact("newer.txt", "the corrected deliverable") + successor = self.ready_payload(relationship, [path], attempt=2) + self.accept(successor) + with self.store.transaction() as db: + db.execute( + "UPDATE revision_lineage SET supersedes_hash = ? WHERE event_id = ?", + (self.intake.get(older)["revisionHash"], successor["eventId"]), + ) + + self.delivery.enqueue(successor["eventId"]) + + note = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (older,), + ) + self.assertIsNotNone(note, "a queued predecessor said nothing about being replaced") + self.assertEqual(note["reason"], SUPERSEDED_REVISION) + + def test_an_outstanding_predecessor_is_annotated_by_its_successor(self): + """Same generation, no advance: attempt() returns early for a non-claimable state. + + An older revision that was already in flight when its successor became final left no + supersession row at all, so reconciliation could promote it to dispatched and status + would present it as the current delivery. + """ + relationship, older = self.queued_outcome("ready_for_review") + self.adapter.start_turn(CHILD, turn_id="turn-dispatch-1", status="inProgress") + self.adapter.script("transport_unknown") + self.attempt(older) + self.assertEqual(self.delivery.get(older)["state"], "held_uncertain") + + path = self.artifact("newer.txt", "the corrected deliverable") + successor = self.ready_payload( + relationship, [path], attempt=2, + turn=TurnRef(CHILD, "turn-dispatch-1", "inProgress"), + ) + self.accept(successor) + # Declared, as a revision that replaces another does when it is emitted. Without the + # link the generation has two unsuperseded revisions and no head at all, which is a + # different problem and one this PR does not decide. + with self.store.transaction() as db: + db.execute( + "UPDATE revision_lineage SET supersedes_hash = ? WHERE event_id = ?", + (self.intake.get(older)["revisionHash"], successor["eventId"]), + ) + self.adapter.finish_turn(CHILD, "turn-dispatch-1") + self.daemon_tick() + + note = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (older,), + ) + self.assertIsNotNone( + note, "the successor became final; the older in-flight send is not current", + ) + self.assertEqual(note["reason"], SUPERSEDED_REVISION) + self.assertEqual( + self.delivery.get(older)["state"], "held_uncertain", + "annotated, never rewritten: a lost response still has to be reconcilable", + ) + + def daemon_tick(self): + from codex_session_relay.daemon import RelayDaemon + + daemon = RelayDaemon( + self.store, self.registry, self.intake, self.delivery, self.ack, + self.reconciler, self.adapter, clock=self.clock, + ) + return daemon.tick(now=self.clock.now()) + def test_a_new_generation_with_no_revision_still_suppresses_the_old_outcome(self): + """The exact reproduction: g3 opened, g3 empty, and a g2 event went out anyway.""" + relationship, event_id = self.queued_outcome("ready_for_review") + self.advance_generation(relationship, 2) + self.clock.advance(3600) + + record = self.attempt(event_id) + + self.assertEqual(self.adapter.sends, [], "a stale event must not reach the host") + self.assertEqual(record["deliveryState"], SUPERSEDED) + self.assertEqual(record["supersededReason"], STALE_GENERATION) + self.assertEqual(self.delivery.get(event_id)["hold_reason"], STALE_GENERATION) + + def test_every_outcome_is_suppressed_not_only_a_reviewable_one(self): + """blocked_needs_input carries no manifest, and failed carries none either.""" + for outcome in ("blocked_needs_input", "failed"): + with self.subTest(outcome=outcome): + self.setUp() + relationship, event_id = self.queued_outcome(outcome) + self.advance_generation(relationship, 2) + self.clock.advance(3600) + record = self.attempt(event_id) + self.assertEqual(record["deliveryState"], SUPERSEDED) + self.assertEqual(record["supersededReason"], STALE_GENERATION) + self.assertEqual(self.adapter.sends, []) + + def test_a_busy_release_re_checks_the_generation_before_sending(self): + """The waiting half of the reproduction: the parent was busy, then it was not.""" + relationship, event_id = self.queued_outcome("ready_for_review") + self.adapter.set_status(PARENT, "active") + self.assertIsNone(self.attempt(event_id)) + self.assertEqual(self.delivery.get(event_id)["state"], DEFERRED_BUSY) + + # The assignment moves on while the event waits. + self.advance_generation(relationship, 2) + self.adapter.set_status(PARENT, "idle") + self.clock.advance(3600) + + record = self.attempt(event_id) + + self.assertEqual(record["deliveryState"], SUPERSEDED) + self.assertEqual(self.adapter.sends, [], "the wait ending is not permission to send") + + def test_suppression_opens_no_generation_and_makes_no_transport_call(self): + relationship, event_id = self.queued_outcome("ready_for_review") + self.advance_generation(relationship, 2) + before = len(self.registry.get(self._rid)["generations"]) + self.clock.advance(3600) + + self.attempt(event_id) + + self.assertEqual(len(self.registry.get(self._rid)["generations"]), before) + self.assertEqual(self.adapter.sends, []) + self.assertEqual(self.registry.get(self._rid)["executionGeneration"], 2) + + def test_a_newer_final_revision_supersedes_the_older_one_in_its_generation(self): + relationship, older = self.queued_outcome("ready_for_review") + newer_path = self.artifact("newer.txt", "the corrected deliverable") + newer = self.ready_payload(relationship, [newer_path], attempt=2) + older_hash = self.intake.row(older)["revision_hash"] + self.accept(newer, ) + with self.store.transaction() as db: + db.execute( + "UPDATE revision_lineage SET supersedes_hash = ? WHERE event_id = ?", + (older_hash, newer["eventId"]), + ) + self.delivery.enqueue(newer["eventId"]) + self.clock.advance(3600) + + record = self.attempt(older) + + self.assertEqual(record["deliveryState"], SUPERSEDED) + self.assertEqual(record["supersededReason"], SUPERSEDED_REVISION) + # And the newest still goes. + self.clock.advance(3600) + sent = self.attempt(newer["eventId"]) + self.assertEqual(sent["deliveryState"], DISPATCHED) + + def test_a_staged_successor_does_not_destroy_the_older_events_chance(self): + """A claim is not a replacement; if it fails, the older one is all there is.""" + relationship, older = self.queued_outcome("ready_for_review") + path = self.artifact("staged.txt", "still being written") + staged = self.ready_payload( + relationship, [path], attempt=2, + # On the anchor turn: a claim from a turn the generation never admitted is a + # different refusal and would not exercise this rule. + turn=TurnRef(CHILD, "turn-dispatch-1", "inProgress"), + ) + self.accept(staged) + self.assertEqual(self.intake.row(staged["eventId"])["stage"], "staged") + self.clock.advance(3600) + + record = self.attempt(older) + + self.assertEqual( + record["deliveryState"], DISPATCHED, + "a staged claim must not suppress the only finished revision there is", + ) + + def test_an_outstanding_send_is_annotated_rather_than_rewritten(self): + """Rewriting it would make a lost response permanently unresolvable.""" + relationship, event_id = self.queued_outcome("ready_for_review") + self.adapter.script("transport_unknown") + self.clock.advance(3600) + self.attempt(event_id) + state = self.delivery.get(event_id)["state"] + + self.advance_generation(relationship, 2) + self.delivery.mark_superseded(event_id, reason=STALE_GENERATION) + + self.assertEqual( + self.delivery.get(event_id)["state"], state, + "an unresolved send keeps its state so reconciliation can still settle it", + ) + noted = self.store.one( + "SELECT * FROM delivery_supersession WHERE event_id = ?", (event_id,), + ) + self.assertIsNotNone(noted) + self.assertEqual(noted["reason"], STALE_GENERATION)