From 8005a487dbade3c91d34b4623b1baf991a19a9f7 Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 17:59:00 +0200 Subject: [PATCH 1/8] fix: make terminal run publication atomic --- docs/logs/engineering-log.md | 41 ++ docs/logs/long-term-thinking-log.md | 22 ++ docs/logs/observational-log.md | 17 + docs/logs/system-log.md | 24 ++ ...minal-status-event-atomicity-impact-map.md | 114 ++++++ ...67-terminal-status-event-atomicity-plan.md | 119 ++++++ docs/plans/INDEX.md | 2 + docs/plans/active-plan.md | 14 +- internal/harness/runner.go | 181 +++++++-- internal/harness/runner_event_journal.go | 9 +- .../harness/runner_terminal_atomicity_test.go | 364 ++++++++++++++++++ .../harness/runner_terminal_store_test.go | 97 +++++ .../server/http_terminal_atomicity_test.go | 161 ++++++++ 13 files changed, 1123 insertions(+), 42 deletions(-) create mode 100644 docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md create mode 100644 docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md create mode 100644 internal/harness/runner_terminal_atomicity_test.go create mode 100644 internal/server/http_terminal_atomicity_test.go diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 123ff99e..93186a1d 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -33,6 +33,47 @@ `-count=5`; harness vet passed; and unchanged foreground non-TTY `./scripts/test-regression.sh` passed at 85.6% total coverage with zero uncovered functions. +## 2026-07-31 (Terminal Status/Event Atomicity — Issue #1067) + +- Symptom: aggregate race load exposed `RunStatusFailed` from `GetRun` while + the same run's immediate replay ended at `llm.turn.requested` without + `run.failed`; code inspection found the same status-first window on completed + and cancelled paths. +- Cause: every terminal helper called `setStatus` before `emit`, splitting the + public run record from the event journal's ledger, bounded store append, + subscriber fanout, and recorder drain. +- Deterministic red: a no-sleep transition barrier reproduced all three states. + Completed replay lacked `run.completed`, failed replay contained the required + `error.context` but lacked `run.failed`, and cancelled replay lacked + `run.cancelled` while `GetRun` already returned each terminal status. +- Fix: one `transitionTerminal` seam now lets the winning terminal emit seal and + append the matching event, completes the bounded store append and ordered + recorder dispatch/drain, commits and persists the matching status, then fans + out to subscribers. Per-run transition serialization prevents competing + terminal helpers from performing mismatched side effects or overwriting the + winning status. +- Preserved reliability: terminal store I/O remains outside `Runner.mu`, and + status-store I/O remains outside the per-conversation journal lock; unrelated + `GetRun` and unrelated event journals stay responsive; durable-before-fanout, terminal + redaction sealing, event IDs, causal/error snapshot order, recorder order, + status persistence, backup, and pruning contracts remain intact. +- Explicit exception: existing terminal `StorageModeNone` configurations still + suppress the matching replay event while sealing and publishing status, as + pinned by terminal-redaction tests. The stronger replay implication applies + to terminal events retained by policy. +- Regression coverage: completed/failed/cancelled barrier checks; required + causal/error ordering; blocked terminal-store target status plus unrelated + query availability; 100-iteration competing terminal races; same-conversation + terminal-before-later-event subscriber ordering; and HTTP terminal poll + followed immediately by Last-Event-ID SSE replay. +- Verification: focused normal/race stress passed at `-count=100`; complete + `internal/harness` + `internal/server` normal/race and affected `go vet` + passed; unchanged foreground non-TTY `./scripts/test-regression.sh` passed + normal, race, and coverage at 85.6% with zero uncovered functions. +- Environmental retry evidence: the first coverage attempt hit two real + Keychain 15-second kills plus an OpenRouter connection reset. A direct + affected coverage run passed, and an unchanged full-gate retry passed without + code, test, or command changes. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/long-term-thinking-log.md b/docs/logs/long-term-thinking-log.md index 8b6bcf45..9a72de0a 100644 --- a/docs/logs/long-term-thinking-log.md +++ b/docs/logs/long-term-thinking-log.md @@ -28,6 +28,28 @@ normal/race x100, complete harness race x5, harness vet, and the unchanged repository regression gate pass. The local commit is ready for parent promotion; PR #1069 remains open and unmerged pending hosted reruns. +## 2026-07-31 (Terminal Status/Event Atomicity — Issue #1067) + +- Command intent: repair the aggregate-load Runner race where `GetRun` exposes + completed, failed, or cancelled before the matching terminal event and + required causal evidence are replayable. +- User intent: external monitoring must never report a terminal result from an + incomplete transcript, and this engine repair must remain isolated from PR + #1060/#1055. +- Success definition: deterministic no-sleep red evidence covers all terminal + statuses; one shared lifecycle seam makes terminal ledger/store publication + precede status visibility while preserving recorder order; immediate + Subscribe and HTTP SSE replay agree; focused stress, affected race/vet, full + regression, and hosted checks pass on one unmerged closing PR. +- Non-goals: conversation cursor redesign, cron/callback behavior, client UI, + provider routing, schemas, or workflow timing changes. +- Guardrails: preserve out-of-lock bounded store writes, durable-before-fanout, + terminal sealing, recorder drain order, cleanup order, causal/error snapshots, + status persistence, SSE IDs, and unrelated query responsiveness. +- Outcome: one winner-only transition now commits terminal ledger/store history + before matching status and subscriber fanout. Deterministic all-status red, + focused normal/race stress, affected normal/race/vet, HTTP reconnect, and the + unchanged full regression are green locally; PR and hosted review remain. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index 69617900..8085aa26 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -22,6 +22,23 @@ Use this file for observations about system behavior without immediately prescri - Cleanup observation: a failure-safe bounded fixture must unblock provider calls before invoking `Shutdown`; otherwise cleanup can wait on the very run the fixture still holds blocked. +## 2026-07-31 (Terminal Run Publication Window) + +- Concurrency observation: a terminal event can be prepared under the Runner + lock and persisted outside it without blocking unrelated run queries, but the + matching status needs one explicit commit point between persistence and + subscriber fanout. Status before preparation yields incomplete replay; + status after fanout lets terminal-event consumers briefly read `running`. +- Testing observation: a phase channel at the terminal transition boundary + deterministically exposes the forbidden state for completed, failed, and + cancelled paths without relying on aggregate load or fixed sleeps. +- Replay observation: after an HTTP status poll returns terminal, reconnecting + run SSE from the first event ID must replay exactly one matching terminal + event and no terminal event of another status. +- Conversation-stream observation: terminal persistence and terminal fanout + must share the same per-conversation critical section; releasing it between + those phases lets a later run's event overtake the terminal event for an + already-connected conversation subscriber. ## 2026-07-31 (Source-Workflow Dual-Error Arbitration) diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index 08dc4d65..09a87529 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -17,6 +17,30 @@ - Compatibility/failure modes: no API, config, persistence, client, provider, or tool contract changes; existing queue-drain, timeout, and idempotency behavior remains the rollback boundary. +## 2026-07-31 (Terminal Run Transition Publication — Issue #1067) + +- System/component: `Runner.transitionTerminal`, `Runner.emit`, and + `eventJournal` terminal persistence/fanout in `internal/harness`. +- Responsibilities: the event journal remains the only event-ledger writer and + terminal-seal owner; the transition seam binds the winning terminal event to + its completed, failed, or cancelled `Run` record. +- Order: prior causal/error events -> terminal ledger append/seal -> bounded + store append -> ordered terminal recorder dispatch/drain -> matching + in-memory and persisted status -> subscriber fanout -> backup/pruning + lifecycle. +- Concurrency boundary: store and recorder I/O remain outside `Runner.mu`. + `conversationEventMu` preserves replay-to-live ordering through event-store + append, recorder drain, in-memory status commit, and terminal fanout; it is + released before status-store I/O. The status commit briefly reacquires only + the Runner state lock. +- Consumers: `GetRun`, run summary, run SSE replay/live delivery, + conversation replay, CLI/TUI exit handling, and macOS transcript state keep + existing schemas and event IDs. +- Failure boundary: bounded store errors remain non-fatal and live in-memory + replay remains available; terminal redaction drops still seal and publish + status by the existing explicit policy; a competing terminal helper is + serialized before terminal side effects, loses the seal, and cannot write a + mismatched audit/profile outcome or overwrite status. ## 2026-07-31 (Source-Workflow Terminal Error Arbitration) diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md new file mode 100644 index 00000000..55a58ae3 --- /dev/null +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md @@ -0,0 +1,114 @@ +# Cross-Surface Impact Map: Issue #1067 Terminal Publication Atomicity + +## Task + +- Task / issue: #1067, terminal status visible before matching replay event. +- Plan: `2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md`. +- Owner: Codex. +- Status: implemented and fully verified locally; hosted checks pending. + +## Current Ownership, Callers, and Data Flow + +- Entry points: `completeRun`, `failRun`, `failRunMaxSteps`, + `failRunMaxTurns`, and `cancelledRun`. +- Source of truth: `Runner` owns `runState.run.Status`, `runState.events`, + `runState.terminated`, recorder channels, and run subscribers; + `eventJournal` owns append/store/fanout ordering. +- Callers/consumers: step-engine completion/provider/tool/budget/cancellation + paths; `GetRun`; `Subscribe`; run HTTP/SSE routes; CLI, TUI, and macOS + transcript/lifecycle consumers. +- Similar abstractions searched: `rg -n + "setStatus|completeRun|failRun|cancelledRun|publishTerminal|GetRun|Subscribe" + internal/harness internal/server`. No second terminal lifecycle owner exists. +- Duplication conclusion: repair the shared Runner transition; do not add + provider-, server-, or client-specific compensation. + +## Config, API, CLI, and Tools + +- Config/env/defaults: none. +- Endpoints/request/response/wire formats: unchanged `Run`, `Event`, event IDs, + SSE names, payload schema, and HTTP routes. +- CLI/tools/integrations: no command changes; terminal polling and stream + consumers gain a stronger ordering guarantee. +- Error states: unchanged completed/failed/cancelled values and payloads. + +## Persistence and Compatibility + +- Schemas/migrations/caches/generated data: none. +- Store order: matching terminal `AppendEvent` remains bounded and precedes + recorder dispatch, terminal status `UpdateRun`, and subscriber fanout; + status persistence occurs after releasing the per-conversation journal lock. +- Recorder: terminal JSONL remains queued after all prior events, closed once, + and drained before terminal transition returns. +- Compatibility: additive ordering guarantee only; event/status values and + replay IDs remain stable. +- Mixed-version behavior: process-local; older daemons retain the race until + upgraded, with no data migration. + +## Lifecycle, Security, and Reliability + +- Concurrency: the winning terminal event seals the ledger before status is + updated; competing terminal helpers cannot overwrite it with a mismatched + status. +- Cancellation/retries/cleanup: cooperative cancellation and idempotency stay + unchanged; workspace/tool/MCP cleanup remains before terminal publication. +- Locks/resources: terminal store/recorder waits remain outside `Runner.mu`, so + unrelated queries are not blocked; status-store I/O also remains outside the + per-conversation journal lock, so unrelated event journals are not blocked. +- Auth/permissions/privacy/secrets: no boundary change after searches through + run routes and redaction/audit paths; terminal payload redaction remains + owned by the event journal. Explicit terminal `StorageModeNone` remains the + documented exception: it seals and publishes status without replaying the + intentionally suppressed event. +- Failure/recovery: bounded store failures remain non-fatal and in-memory replay + remains authoritative for the live Runner; persisted-before-prune guards stay + intact. + +## Product and Integration Surfaces + +- Server/runtime: `GetRun` terminal now implies immediate `Subscribe` replay + contains the matching event. +- TUI/web/macOS/other clients: terminal badges, failure text, exit codes, and + transcript state no longer disagree during the publication window; no client + code changes. +- Provider/model/tool catalogs/routing: none; provider failure is only a caller. +- External systems/automation: cron/callback/workflow semantics unchanged. +- UX/accessibility/focus/motion: no visual or interaction change. + +## Deployment and Operations + +- Deployment/migrations/flags: ordinary daemon rollout; no migration or flag. +- Observability: deterministic regression records transition phases without + logging prompts, event payload secrets, or credentials. +- Rollback: revert if terminal fanout deadlocks, unrelated `GetRun` blocks, + cleanup order changes, recorder output truncates, or cancellation regresses. +- Runbooks/operator docs: no public/operator command changes. + +## Regression Tests + +- First red: phase barrier proves old completed/failed/cancelled status can win + before terminal history. +- Acceptance: terminal status implies one matching replay event; failed causal + snapshot precedes `run.failed`; competing terminal transitions match the + winning sealed event; later same-conversation events cannot overtake terminal + fanout to an existing conversation subscriber. +- Store/recorder: durability and existing drain barriers preserve non-terminal + status without blocking unrelated queries; a blocked status-store write does + not block unrelated event journals. +- Integration: HTTP poll immediately followed by run SSE replay for all three + statuses. +- Exact gates: focused normal/race stress `-count=100`; harness/server + normal/race/vet; unchanged foreground non-TTY regression; hosted checks. + +## Documentation and Handoff + +- Plans/specs: issue-specific plan and this map. +- Logs/indexes: engineering, observational, system, long-term, plans index, and + active plan. +- Public/training/release docs: none because no new route, schema, or command is + introduced. + +## Warning Check + +- Every cross-surface heading is resolved. Unaffected surfaces are explicitly + named with search and data-flow rationale above. diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md new file mode 100644 index 00000000..43991a82 --- /dev/null +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md @@ -0,0 +1,119 @@ +# Plan: Make Terminal Status and Event Publication Atomic + +## Context + +- Governing GitHub issue: #1067. +- Problem: terminal helpers publish `Run.Status` before the event journal has + prepared, persisted, and exposed the matching terminal event. A concurrent + `GetRun` can therefore return completed, failed, or cancelled while an + immediate `Subscribe` replay still ends at a non-terminal event. +- User impact: API polling, SSE reconnect, CLI/TUI, and macOS clients can + briefly render terminal state without the authoritative terminal transcript + or its preceding causal/error evidence. +- Constraints: preserve durable-before-fanout, terminal sealing, recorder + drain ordering, bounded store writes, run-independent query availability, + current event/status schemas, cleanup ordering, and the explicit + `StorageModeNone` terminal-redaction policy. + +## Scope + +- In scope: one shared Runner terminal-transition seam for completed, failed, + cancelled, max-step failed, and max-turn failed paths; deterministic + concurrency and replay regressions; real HTTP poll-then-replay proof. +- Out of scope: PR #1060/#1055 changes, cron/callback behavior, conversation + cursor redesign, GUI visual changes, provider routing, schemas, and workflow + timing issue #1049. + +## Documentation Contract + +- Feature status: implemented and fully verified locally; hosted checks pending. +- Public docs affected: none; existing terminal event/status wire formats stay + unchanged. +- Spec docs before code: this plan and its linked impact map. +- Implementation notes after code: engineering, observational, system, and + long-term logs plus the plans index and active plan. + +## Test Plan (TDD) + +- First red: a deterministic phase barrier pauses each completed, failed, and + cancelled helper after the old status write but before terminal event + publication. Concurrent `GetRun` plus `Subscribe` must never observe that + forbidden state. +- Causal control: on an error-chain-enabled failure, the required + `error.context` snapshot must precede `run.failed` before failed status is + observable. +- Store/recorder controls: block terminal store append and preserve the existing + recorder drain regressions; assert target status remains non-terminal while + unrelated run queries remain responsive, then becomes terminal only after + replay, durability, and recorder delivery are ready. Block status-store + persistence separately and prove unrelated event journals remain responsive. +- Concurrency control: race competing terminal transitions and require the + winning status to match the single sealed terminal event; hold a terminal at + the pre-fanout boundary and prove a later same-conversation event cannot + overtake it for an existing conversation subscriber. +- Real path: HTTP `GET /v1/runs/{id}` followed immediately by run-event SSE + replay contains the matching terminal event for all three statuses. +- Focused stress: normal and race at `-count=100`. +- Affected gates: `internal/harness` and `internal/server` normal/race and vet. +- Repository gate: unchanged foreground non-TTY + `./scripts/test-regression.sh`. +- Hosted gates: required PR checks, including `test-fast` and `test-race`. + +## Cross-Surface Impact Map + +- See `2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md`. + +## Implementation Checklist + +- [x] Link contract-complete bug #1067 before implementation. +- [x] Record current ownership, callers, sources of truth, and search evidence. +- [x] Write this plan and impact map before code. +- [x] Add and confirm the deterministic failing regressions. +- [x] Implement the smallest shared terminal-transition repair. +- [x] Confirm focused stress, affected normal/race/vet, and repository gates. +- [x] Prove the HTTP poll-then-replay path. +- [x] Update all required logs and documentation status. +- [ ] Open one closing PR, push its exact head, and request `@codex` review. +- [ ] Confirm hosted checks are green; do not merge. + +## Risks and Mitigations + +- Risk: holding `Runner.mu` across persistence would block unrelated queries. +- Mitigation: retain the existing out-of-lock bounded terminal append/fanout + path and test unrelated `GetRun` responsiveness while it is blocked. +- Risk: concurrent terminal helpers could publish one event and a different + status. +- Mitigation: serialize each run's complete terminal helper lifecycle, make the + shared transition return whether it won terminal sealing, and update status + only for that winner. +- Risk: moving status later could reorder cleanup, causal snapshots, audit, + profile persistence, backup, or pruning. +- Mitigation: pin causal/event order and keep cleanup before terminal + transition, operational side effects after the matching status/event pair. +- Risk: recorder or store failure could weaken the existing lifecycle. +- Mitigation: preserve bounded non-fatal persistence semantics, recorder drain, + terminal retention, and terminal-event-persisted pruning guards. +- Risk: an explicit terminal `StorageModeNone` policy intentionally removes the + matching event from replay. +- Mitigation: preserve and test the existing redaction exception and scope the + stronger replay implication to terminal events retained by policy. + +## Verification Evidence + +- Semantic red: + `go test ./internal/harness -run + '^TestTerminalStatusNeverPrecedesTerminalReplayEvent$' -count=1` failed all + three cases: completed before `run.completed`, failed after `error.context` + but before `run.failed`, and cancelled before `run.cancelled`. +- Focused final green: terminal atomicity, competing transitions, blocked store, + and HTTP replay passed normal and race at `-count=100` across + `internal/harness` and `internal/server`. +- Affected packages: complete harness/server normal and race passed; `go vet` + passed. +- Real path: HTTP terminal polling followed immediately by Last-Event-ID run + SSE replay passed for completed, failed, and cancelled. +- Repository: unchanged foreground non-TTY `./scripts/test-regression.sh` + passed normal, race, and coverage + (`total=85.6%`, `zero-functions=0`). An earlier coverage attempt hit transient + real-Keychain timeouts plus an OpenRouter connection reset; the unchanged + retry passed completely without code or command changes. diff --git a/docs/plans/INDEX.md b/docs/plans/INDEX.md index 4e4177a2..8750582c 100644 --- a/docs/plans/INDEX.md +++ b/docs/plans/INDEX.md @@ -2,6 +2,8 @@ - `2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md` — Issue #1068 plan for deterministic instance-scoped Runner dispatcher shutdown verification. - `2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md` — Cross-surface impact map for Issue #1068 lifecycle isolation. +- `2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md` — Issue #1067 plan for linearizable terminal status, event, persistence, and replay publication. +- `2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md` — Cross-surface impact map for Issue #1067 Runner lifecycle ordering. - `2026-07-31-issue-1062-provider-key-matrix-health-wait-plan.md` — Issue #1062 plan for a contention-tolerant provider API-key matrix startup wait. - `2026-07-31-issue-1062-provider-key-matrix-health-wait-impact-map.md` — Cross-surface impact map for Issue #1062. - `2026-07-31-issue-1064-workflow-exit-precedence-plan.md` — Issue #1064 deterministic source-workflow process-exit diagnostic precedence repair. diff --git a/docs/plans/active-plan.md b/docs/plans/active-plan.md index 3b18253b..6c1df9ac 100644 --- a/docs/plans/active-plan.md +++ b/docs/plans/active-plan.md @@ -1,12 +1,10 @@ # Active Plan -Current status: Issue #1068 dispatcher shutdown isolation and the review-found -bounded worker-pool fixture cleanup are implemented and locally verified on a -dedicated branch. The aggregate 4/5 red, deterministic two-Runner red/green, -cleanup red/green, worker-pool normal/race x100, complete harness race x5, vet, -and unchanged regression gate are recorded. PR #1069 remains open and unmerged; -the local review-fix commit still requires parent promotion and hosted reruns. -PR #1060, PR #1055, and issue #1067 remain excluded. +Current status: Issue #1067 terminal publication atomicity is implemented on +isolated branch `codex/issue-1067-terminal-status-event-atomicity`. The hosted +durability regression has a deterministic local red-green repair; final gates +on the branch rebased to current `main` remain in progress before parent +promotion to open PR #1070. PR #1060 and PR #1055 remain excluded. Current status: Issue #1023 anytime contextual `/feedback` intake is implemented test-first and verified in its isolated worktree; targeted, full normal/race, @@ -19,7 +17,7 @@ Remaining work before merge is final verification and any requested review/cleanup. Current active plans: -- `2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md` +- `2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md` - `2026-07-30-issue-1023-feedback-intake-plan.md` - `2026-06-26-adapter-first-eval-harness-plan.md` - `2026-04-05-orchestration-program-plan.md` diff --git a/internal/harness/runner.go b/internal/harness/runner.go index f82640e0..97c59ab7 100644 --- a/internal/harness/runner.go +++ b/internal/harness/runner.go @@ -100,12 +100,15 @@ type runState struct { // error context snapshots. Non-nil only when ErrorChainEnabled is set in // RunnerConfig. snapshotBuilder *errorchain.SnapshotBuilder - // terminated is set to true once the terminal event (run.completed or - // run.failed) has been emitted. Any subsequent emit() call returns - // immediately to prevent post-terminal streaming callbacks from appending - // events after the forensic record is closed. + // terminated is set to true once a terminal event (run.completed, + // run.failed, or run.cancelled) has been emitted. Any subsequent emit() call + // returns immediately to prevent post-terminal streaming callbacks from + // appending events after the forensic record is closed. terminated bool terminalEventPersisted bool + // terminalMu serializes the complete terminal-helper lifecycle so only the + // event winner may run terminal audit/profile/cleanup side effects. + terminalMu sync.Mutex // compactMu serializes auto-compact and manual CompactRun calls. compactMu sync.RWMutex // resetIndex increments each time the agent calls reset_context. @@ -162,6 +165,9 @@ type runState struct { // mirror that must drain exactly that ledger before a terminal emit returns. // 3. state.terminated is armed before terminal redaction/fanout so no // post-terminal goroutine can append to the sealed forensic record. +// 4. For terminal events retained by redaction policy, status is published +// only after the winning event reaches replay/store/recorder history; +// GetRun therefore cannot expose terminal state ahead of replay. // // Message lifecycle: // 1. state.messages is the only source of truth for run context. @@ -343,6 +349,12 @@ type Runner struct { // immediately before it marks dispatcherWG done. It lets lifecycle tests // identify one Runner without scanning process-global goroutine stacks. poolDispatcherExitHook func() + // terminalTransitionHook is a test seam invoked at the publication boundary + // between terminal lifecycle preparation and terminal event emission. + terminalTransitionHook func(string, RunStatus, EventType) + // terminalBeforeDispatchHook is a test seam invoked after terminal replay + // persistence and before recorder/status/subscriber publication. + terminalBeforeDispatchHook func(string, EventType) // runQueue is a FIFO channel of pending (runID, req) pairs waiting for a // worker slot. It is only used when workerSem is non-nil. runQueue chan queuedRun @@ -3203,6 +3215,12 @@ func (r *Runner) drainSteering(runID string, messages *[]Message) { } func (r *Runner) completeRun(runID, output string) { + unlockTerminal, ok := r.lockTerminalTransition(runID) + if !ok { + return + } + defer unlockTerminal() + rc := r.configForRun(runID) // Clean up per-run workspace before terminal event (issue #324). r.runWorkspaceCleanup(runID) @@ -3282,8 +3300,6 @@ func (r *Runner) completeRun(runID, output string) { r.closeAuditWriter(runID) } - r.setStatus(runID, RunStatusCompleted, output, "") - usageTotals, costTotals := r.accountingTotals(runID) // Efficiency suggestion: if the run used a named profile and the @@ -3294,7 +3310,7 @@ func (r *Runner) completeRun(runID, output string) { // Profile run history: persist completion record for analysis. r.persistProfileRun(runID, "completed", costTotals.CostUSDTotal) - r.emit(runID, EventRunCompleted, map[string]any{ + r.transitionTerminal(runID, RunStatusCompleted, output, "", EventRunCompleted, map[string]any{ "output": output, "usage_totals": usageTotals, "cost_totals": costTotals, @@ -3615,6 +3631,12 @@ func (r *Runner) emitContextWindowSnapshot( } func (r *Runner) failRun(runID string, err error) { + unlockTerminal, ok := r.lockTerminalTransition(runID) + if !ok { + return + } + defer unlockTerminal() + rc := r.configForRun(runID) if err == nil { err = errors.New("run failed") @@ -3658,14 +3680,12 @@ func (r *Runner) failRun(runID string, err error) { r.closeAuditWriter(runID) } - r.setStatus(runID, RunStatusFailed, "", err.Error()) - usageTotals, costTotals := r.accountingTotals(runID) // Profile run history: persist failure record for analysis. r.persistProfileRun(runID, "failed", costTotals.CostUSDTotal) - r.emit(runID, EventRunFailed, map[string]any{ + r.transitionTerminal(runID, RunStatusFailed, "", err.Error(), EventRunFailed, map[string]any{ "error": err.Error(), "usage_totals": usageTotals, "cost_totals": costTotals, @@ -3682,6 +3702,12 @@ func (r *Runner) failRun(runID string, err error) { // reason="max_steps_reached" and max_steps field so clients can distinguish // this terminal state from other failures without parsing the error string. func (r *Runner) failRunMaxSteps(runID string, maxSteps int) { + unlockTerminal, ok := r.lockTerminalTransition(runID) + if !ok { + return + } + defer unlockTerminal() + rc := r.configForRun(runID) err := fmt.Errorf("max steps (%d) reached", maxSteps) @@ -3710,14 +3736,12 @@ func (r *Runner) failRunMaxSteps(runID string, maxSteps int) { r.closeAuditWriter(runID) } - r.setStatus(runID, RunStatusFailed, "", err.Error()) - usageTotals, costTotals := r.accountingTotals(runID) // Profile run history: persist partial record (max steps reached) for analysis. r.persistProfileRun(runID, "partial", costTotals.CostUSDTotal) - r.emit(runID, EventRunFailed, map[string]any{ + r.transitionTerminal(runID, RunStatusFailed, "", err.Error(), EventRunFailed, map[string]any{ "error": err.Error(), "reason": "max_steps_reached", "max_steps": maxSteps, @@ -3736,6 +3760,12 @@ func (r *Runner) failRunMaxSteps(runID string, maxSteps int) { // reason="max_turns_exhausted" and max_turns field so clients can distinguish // this terminal state from other failures without parsing the error string. func (r *Runner) failRunMaxTurns(runID string, maxTurns int) { + unlockTerminal, ok := r.lockTerminalTransition(runID) + if !ok { + return + } + defer unlockTerminal() + rc := r.configForRun(runID) err := fmt.Errorf("max turns (%d) reached", maxTurns) @@ -3764,14 +3794,12 @@ func (r *Runner) failRunMaxTurns(runID string, maxTurns int) { r.closeAuditWriter(runID) } - r.setStatus(runID, RunStatusFailed, "", err.Error()) - usageTotals, costTotals := r.accountingTotals(runID) // Profile run history: persist partial record (max turns exhausted) for analysis. r.persistProfileRun(runID, "partial", costTotals.CostUSDTotal) - r.emit(runID, EventRunFailed, map[string]any{ + r.transitionTerminal(runID, RunStatusFailed, "", err.Error(), EventRunFailed, map[string]any{ "error": err.Error(), "reason": "max_turns_exhausted", "max_turns": maxTurns, @@ -3789,6 +3817,12 @@ func (r *Runner) failRunMaxTurns(runID string, maxTurns int) { // to RunStatusCancelled. It mirrors the structure of failRun but uses the // dedicated cancelled event and status rather than failed. func (r *Runner) cancelledRun(runID string) { + unlockTerminal, ok := r.lockTerminalTransition(runID) + if !ok { + return + } + defer unlockTerminal() + rc := r.configForRun(runID) // Clean up per-run workspace before terminal event (issue #324). r.runWorkspaceCleanup(runID) @@ -3812,10 +3846,8 @@ func (r *Runner) cancelledRun(runID string) { r.closeAuditWriter(runID) } - r.setStatus(runID, RunStatusCancelled, "", "") - usageTotals, costTotals := r.accountingTotals(runID) - r.emit(runID, EventRunCancelled, map[string]any{ + r.transitionTerminal(runID, RunStatusCancelled, "", "", EventRunCancelled, map[string]any{ "usage_totals": usageTotals, "cost_totals": costTotals, }) @@ -4174,12 +4206,21 @@ func (a usageTotalsAccumulator) completionUsage() CompletionUsage { } func (r *Runner) setStatus(runID string, status RunStatus, output, runErr string) { + if !r.setStatusInMemory(runID, status, output, runErr) { + return + } + + // Persist the updated run state to the store (non-fatal, called after unlock). + r.storeUpdateRun(runID) +} + +func (r *Runner) setStatusInMemory(runID string, status RunStatus, output, runErr string) bool { r.mu.Lock() state, ok := r.runs[runID] if !ok { r.mu.Unlock() - return + return false } state.run.Status = status state.run.Output = output @@ -4191,9 +4232,7 @@ func (r *Runner) setStatus(runID string, status RunStatus, output, runErr string state.run.Recap = nil } r.mu.Unlock() - - // Persist the updated run state to the store (non-fatal, called after unlock). - r.storeUpdateRun(runID) + return true } func (r *Runner) setMessages(runID string, messages []Message) { @@ -5329,7 +5368,21 @@ func (r runTranscriptReader) Snapshot(limit int, includeTools bool) htools.Trans // emit appends one event to the canonical in-memory ledger and mirrors that // same event to subscribers and the optional JSONL recorder. -func (r *Runner) emit(runID string, eventType EventType, payload map[string]any) { +func (r *Runner) emit(runID string, eventType EventType, payload map[string]any) bool { + return r.emitWithTerminalCommit(runID, eventType, payload, nil) +} + +// emitWithTerminalCommit runs terminalCommit after the terminal event is in +// replay/store/recorder history but before subscribers receive it. The commit +// changes only in-memory status; its store write happens after this method +// releases conversationEventMu so status-store I/O cannot stall unrelated +// event journals or conversation subscriptions. Non-terminal callers pass nil. +func (r *Runner) emitWithTerminalCommit( + runID string, + eventType EventType, + payload map[string]any, + terminalCommit func(), +) bool { r.conversationEventMu.Lock() conversationLocked := true defer func() { @@ -5342,7 +5395,7 @@ func (r *Runner) emit(runID string, eventType EventType, payload map[string]any) state, ok := r.runs[runID] if !ok { r.mu.Unlock() - return + return false } // Drop post-terminal events to preserve forensic ordering. Provider @@ -5351,32 +5404,94 @@ func (r *Runner) emit(runID string, eventType EventType, payload map[string]any) // appended to the forensic record after it is sealed. if state.terminated { r.mu.Unlock() - return + return false } journal := newEventJournal(r) delivery, deliver := journal.prepareLocked(state, runID, eventType, payload) publishTerminal := deliver && !delivery.dropped && IsTerminalEvent(eventType) r.mu.Unlock() if !deliver { - return + return false } if publishTerminal { - journal.publishTerminal(delivery) + journal.persistTerminal(delivery) + if r.terminalBeforeDispatchHook != nil { + r.terminalBeforeDispatchHook(runID, eventType) + } + journal.dispatch(delivery) + if terminalCommit != nil { + terminalCommit() + } + journal.fanoutTerminal(delivery) r.conversationEventMu.Unlock() conversationLocked = false - r.pruneCompletedRuns() - journal.dispatch(delivery) - return + return true } if delivery.dropped { + journal.dispatch(delivery) + if IsTerminalEvent(eventType) && terminalCommit != nil { + terminalCommit() + } r.conversationEventMu.Unlock() conversationLocked = false - journal.dispatch(delivery) - return + return true } journal.dispatch(delivery) r.conversationEventMu.Unlock() conversationLocked = false + return true +} + +// lockTerminalTransition serializes complete terminal helper lifecycles. The +// second check happens after acquiring terminalMu so a waiter cannot run audit, +// profile, cleanup, backup, or pruning side effects after another helper seals +// the run. +func (r *Runner) lockTerminalTransition(runID string) (func(), bool) { + r.mu.RLock() + state := r.runs[runID] + r.mu.RUnlock() + if state == nil { + return nil, false + } + + state.terminalMu.Lock() + r.mu.RLock() + current := r.runs[runID] + available := current == state && !state.terminated + r.mu.RUnlock() + if !available { + state.terminalMu.Unlock() + return nil, false + } + return state.terminalMu.Unlock, true +} + +// transitionTerminal publishes exactly one matching terminal event before it +// makes the terminal status visible. emit returns false for a run already +// sealed by a competing terminal path, so only the event winner may publish +// status and persist the matching final run record. +func (r *Runner) transitionTerminal( + runID string, + status RunStatus, + output, runErr string, + eventType EventType, + payload map[string]any, +) bool { + if r.terminalTransitionHook != nil { + r.terminalTransitionHook(runID, status, eventType) + } + committed := false + if !r.emitWithTerminalCommit(runID, eventType, payload, func() { + committed = r.setStatusInMemory(runID, status, output, runErr) + }) { + return false + } + if committed { + // Keep status-store I/O outside conversationEventMu: one slow run store + // must not stop every conversation journal from making progress. + r.storeUpdateRun(runID) + } + return committed } // EmitEvent publishes an additive adapter-originated event through the run's diff --git a/internal/harness/runner_event_journal.go b/internal/harness/runner_event_journal.go index 2792dfa7..7cdea320 100644 --- a/internal/harness/runner_event_journal.go +++ b/internal/harness/runner_event_journal.go @@ -179,17 +179,24 @@ func (j *eventJournal) prepareLocked(state *runState, runID string, eventType Ev return delivery, true } -func (j *eventJournal) publishTerminal(delivery eventDispatch) { +func (j *eventJournal) persistTerminal(delivery eventDispatch) { if j.runner.storeAppendEvent(delivery.event, delivery.eventSeq) { j.runner.markTerminalEventPersisted(delivery.runID) } j.runner.recordConversationEvent(delivery.conversationID, delivery.event) +} +func (j *eventJournal) fanoutTerminal(delivery eventDispatch) { for _, sub := range delivery.subscribers { j.runner.sendTerminalSubscriberEvent(sub.ch, sub.event) } } +func (j *eventJournal) publishTerminal(delivery eventDispatch) { + j.persistTerminal(delivery) + j.fanoutTerminal(delivery) +} + func (j *eventJournal) dispatch(delivery eventDispatch) { if delivery.dropped { if delivery.closeRecorder != nil { diff --git a/internal/harness/runner_terminal_atomicity_test.go b/internal/harness/runner_terminal_atomicity_test.go new file mode 100644 index 00000000..efdd6856 --- /dev/null +++ b/internal/harness/runner_terminal_atomicity_test.go @@ -0,0 +1,364 @@ +package harness + +import ( + "context" + "errors" + "fmt" + "sync" + "testing" + "time" +) + +func TestTerminalStatusNeverPrecedesTerminalReplayEvent(t *testing.T) { + tests := []struct { + name string + provider Provider + wantStatus RunStatus + wantEvent EventType + cancelStarted <-chan struct{} + }{ + { + name: "completed", + provider: staticContentProvider{content: "done"}, + wantStatus: RunStatusCompleted, + wantEvent: EventRunCompleted, + }, + { + name: "failed_with_error_context", + provider: &errorProvider{err: errors.New("provider unavailable")}, + wantStatus: RunStatusFailed, + wantEvent: EventRunFailed, + }, + } + + cancelProvider := &terminalCancellationProvider{started: make(chan struct{})} + tests = append(tests, struct { + name string + provider Provider + wantStatus RunStatus + wantEvent EventType + cancelStarted <-chan struct{} + }{ + name: "cancelled", + provider: cancelProvider, + wantStatus: RunStatusCancelled, + wantEvent: EventRunCancelled, + cancelStarted: cancelProvider.started, + }) + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + reached := make(chan struct{}) + release := make(chan struct{}) + t.Cleanup(func() { + select { + case <-release: + default: + close(release) + } + }) + + runner := NewRunner(tt.provider, NewRegistry(), RunnerConfig{ + ErrorChainEnabled: true, + CausalGraphEnabled: true, + }) + runner.terminalTransitionHook = func(_ string, status RunStatus, eventType EventType) { + if status != tt.wantStatus || eventType != tt.wantEvent { + return + } + close(reached) + <-release + } + + run, err := runner.StartRun(RunRequest{Prompt: "terminal atomicity " + tt.name}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + if tt.cancelStarted != nil { + select { + case <-tt.cancelStarted: + case <-time.After(2 * time.Second): + t.Fatal("provider did not start") + } + if err := runner.CancelRun(run.ID); err != nil { + t.Fatalf("CancelRun: %v", err) + } + } + + select { + case <-reached: + case <-time.After(2 * time.Second): + t.Fatalf("terminal transition did not reach %s barrier", tt.wantStatus) + } + + current, ok := runner.GetRun(run.ID) + if !ok { + t.Fatalf("GetRun(%q) returned not found", run.ID) + } + history, _, unsubscribe, err := runner.Subscribe(run.ID) + if err != nil { + t.Fatalf("Subscribe: %v", err) + } + unsubscribe() + + if isTerminalRunStatus(current.Status) && !containsEventType(history, tt.wantEvent) { + t.Fatalf("GetRun returned %s before %s was replayable; history=%v", + current.Status, tt.wantEvent, terminalAtomicityEventTypes(history)) + } + if tt.wantStatus == RunStatusFailed && + containsEventType(history, EventRunFailed) && + !eventPrecedes(history, EventErrorContext, EventRunFailed) { + t.Fatalf("failed status became observable without error.context before run.failed; history=%v", + terminalAtomicityEventTypes(history)) + } + + close(release) + waitForStatus(t, runner, run.ID, tt.wantStatus) + + finalHistory, _, finalUnsubscribe, err := runner.Subscribe(run.ID) + if err != nil { + t.Fatalf("Subscribe after terminal status: %v", err) + } + finalUnsubscribe() + if !containsEventType(finalHistory, tt.wantEvent) { + t.Fatalf("terminal status %s missing matching replay event %s; history=%v", + tt.wantStatus, tt.wantEvent, terminalAtomicityEventTypes(finalHistory)) + } + switch tt.wantStatus { + case RunStatusCompleted: + if !eventPrecedes(finalHistory, EventCausalGraphSnapshot, EventRunCompleted) { + t.Fatalf("completed status missing causal snapshot before run.completed; history=%v", + terminalAtomicityEventTypes(finalHistory)) + } + case RunStatusFailed: + if !eventPrecedes(finalHistory, EventErrorContext, EventRunFailed) { + t.Fatalf("failed status missing error.context before run.failed; history=%v", + terminalAtomicityEventTypes(finalHistory)) + } + } + }) + } +} + +func TestCompetingTerminalTransitionsPublishMatchingStatusAndEvent(t *testing.T) { + const iterations = 100 + for iteration := 0; iteration < iterations; iteration++ { + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{}) + runID := fmt.Sprintf("terminal-race-%d", iteration) + runner.runs[runID] = &runState{ + run: Run{ + ID: runID, + ConversationID: "terminal-race-conversation", + Status: RunStatusRunning, + }, + subscribers: make(map[chan Event]struct{}), + } + + start := make(chan struct{}) + var transitions sync.WaitGroup + transitions.Add(3) + go func() { + defer transitions.Done() + <-start + runner.completeRun(runID, "done") + }() + go func() { + defer transitions.Done() + <-start + runner.failRun(runID, errors.New("failed")) + }() + go func() { + defer transitions.Done() + <-start + runner.cancelledRun(runID) + }() + close(start) + transitions.Wait() + + current, ok := runner.GetRun(runID) + if !ok { + t.Fatalf("iteration %d: GetRun returned not found", iteration) + } + history, _, unsubscribe, err := runner.Subscribe(runID) + if err != nil { + t.Fatalf("iteration %d: Subscribe: %v", iteration, err) + } + unsubscribe() + + terminalEvents := make([]EventType, 0, 1) + for _, event := range history { + if IsTerminalEvent(event.Type) { + terminalEvents = append(terminalEvents, event.Type) + } + } + if len(terminalEvents) != 1 { + t.Fatalf("iteration %d: terminal events=%v, want exactly one; history=%v", + iteration, terminalEvents, terminalAtomicityEventTypes(history)) + } + if wantStatus := statusForTerminalEvent(terminalEvents[0]); current.Status != wantStatus { + t.Fatalf("iteration %d: status=%s does not match sealed event=%s (want %s)", + iteration, current.Status, terminalEvents[0], wantStatus) + } + } +} + +func TestTerminalConversationFanoutCannotBeOvertaken(t *testing.T) { + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{}) + const ( + conversationID = "terminal-conversation-order" + terminalRunID = "terminal-conversation-order-terminal" + laterRunID = "terminal-conversation-order-later" + ) + for _, runID := range []string{terminalRunID, laterRunID} { + runner.runs[runID] = &runState{ + run: Run{ + ID: runID, + ConversationID: conversationID, + Status: RunStatusRunning, + }, + subscribers: make(map[chan Event]struct{}), + } + } + + history, stream, unsubscribe, err := runner.SubscribeConversation(conversationID) + if err != nil { + t.Fatalf("SubscribeConversation: %v", err) + } + defer unsubscribe() + if len(history) != 0 { + t.Fatalf("initial conversation history = %v, want empty", terminalAtomicityEventTypes(history)) + } + + reachedDispatch := make(chan struct{}) + releaseDispatch := make(chan struct{}) + runner.terminalBeforeDispatchHook = func(runID string, eventType EventType) { + if runID != terminalRunID || eventType != EventRunCompleted { + return + } + close(reachedDispatch) + <-releaseDispatch + } + + terminalDone := make(chan bool, 1) + go func() { + terminalDone <- runner.transitionTerminal( + terminalRunID, + RunStatusCompleted, + "done", + "", + EventRunCompleted, + map[string]any{"output": "done"}, + ) + }() + select { + case <-reachedDispatch: + case <-time.After(2 * time.Second): + t.Fatal("terminal transition did not reach pre-dispatch barrier") + } + + // The replay-to-live mutex must remain held from terminal persistence + // through terminal fanout. Before the fix this lock was available here, + // allowing a later same-conversation event to overtake the terminal event. + if runner.conversationEventMu.TryLock() { + runner.conversationEventMu.Unlock() + close(releaseDispatch) + <-terminalDone + t.Fatal("conversation event lock released before terminal fanout") + } + + laterStarted := make(chan struct{}) + laterDone := make(chan struct{}) + go func() { + close(laterStarted) + runner.emit(laterRunID, EventAssistantMessage, map[string]any{"content": "later"}) + close(laterDone) + }() + <-laterStarted + close(releaseDispatch) + if won := <-terminalDone; !won { + t.Fatal("terminal transition did not win") + } + select { + case <-laterDone: + case <-time.After(2 * time.Second): + t.Fatal("later conversation event remained blocked") + } + + got := make([]Event, 0, 2) + for len(got) < 2 { + select { + case event := <-stream: + got = append(got, event) + case <-time.After(2 * time.Second): + t.Fatalf("conversation subscriber received %v, want terminal then later event", + terminalAtomicityEventTypes(got)) + } + } + if got[0].RunID != terminalRunID || got[0].Type != EventRunCompleted || + got[1].RunID != laterRunID || got[1].Type != EventAssistantMessage { + t.Fatalf("conversation subscriber order = %v, want %s/%s then %s/%s", + terminalAtomicityEventTypes(got), terminalRunID, EventRunCompleted, + laterRunID, EventAssistantMessage) + } +} + +type terminalCancellationProvider struct { + started chan struct{} +} + +func (p *terminalCancellationProvider) Complete(ctx context.Context, _ CompletionRequest) (CompletionResult, error) { + select { + case <-p.started: + default: + close(p.started) + } + <-ctx.Done() + return CompletionResult{}, ctx.Err() +} + +func containsEventType(events []Event, want EventType) bool { + for _, event := range events { + if event.Type == want { + return true + } + } + return false +} + +func eventPrecedes(events []Event, first, second EventType) bool { + firstIndex, secondIndex := -1, -1 + for i, event := range events { + switch event.Type { + case first: + if firstIndex == -1 { + firstIndex = i + } + case second: + if secondIndex == -1 { + secondIndex = i + } + } + } + return firstIndex >= 0 && secondIndex > firstIndex +} + +func terminalAtomicityEventTypes(events []Event) []string { + types := make([]string, 0, len(events)) + for _, event := range events { + types = append(types, fmt.Sprint(event.Type)) + } + return types +} + +func statusForTerminalEvent(eventType EventType) RunStatus { + switch eventType { + case EventRunCompleted: + return RunStatusCompleted + case EventRunFailed: + return RunStatusFailed + case EventRunCancelled: + return RunStatusCancelled + default: + return "" + } +} diff --git a/internal/harness/runner_terminal_store_test.go b/internal/harness/runner_terminal_store_test.go index ca4cbbe2..df6ba9a2 100644 --- a/internal/harness/runner_terminal_store_test.go +++ b/internal/harness/runner_terminal_store_test.go @@ -48,6 +48,16 @@ func TestTerminalStoreAppendDoesNotBlockRunnerQueries(t *testing.T) { t.Fatal("timed out waiting for terminal event store append to block") } + blockedRun, ok := runner.GetRun(doneRun.ID) + if !ok { + t.Fatalf("GetRun(%q) returned false during terminal append", doneRun.ID) + } + if isTerminalRunStatus(blockedRun.Status) { + close(backingStore.release) + close(holdProviderRelease) + t.Fatalf("GetRun exposed %s before terminal event store append completed", blockedRun.Status) + } + queryDone := make(chan struct{}) var found bool go func() { @@ -95,6 +105,62 @@ func TestTerminalStoreAppendUsesBoundedContext(t *testing.T) { } } +func TestTerminalStatusStoreUpdateDoesNotBlockOtherEventJournals(t *testing.T) { + holdProviderRelease := make(chan struct{}) + doneProviderRelease := make(chan struct{}) + provider := &promptGateProvider{ + gates: map[string]<-chan struct{}{ + "hold": holdProviderRelease, + "done": doneProviderRelease, + }, + } + backingStore := &blockingTerminalStatusStore{ + Store: runstore.NewMemoryStore(), + started: make(chan struct{}), + release: make(chan struct{}), + } + runner := NewRunner(provider, NewRegistry(), RunnerConfig{Store: backingStore}) + + holdRun, err := runner.StartRun(RunRequest{Prompt: "hold"}) + if err != nil { + t.Fatalf("StartRun hold: %v", err) + } + waitForStatus(t, runner, holdRun.ID, RunStatusRunning) + + doneRun, err := runner.StartRun(RunRequest{Prompt: "done"}) + if err != nil { + t.Fatalf("StartRun done: %v", err) + } + backingStore.setBlockRunID(doneRun.ID) + close(doneProviderRelease) + + select { + case <-backingStore.started: + case <-time.After(2 * time.Second): + close(holdProviderRelease) + t.Fatal("timed out waiting for terminal status store update to block") + } + + emitDone := make(chan struct{}) + go func() { + runner.emit(holdRun.ID, EventAssistantMessage, map[string]any{"content": "still responsive"}) + close(emitDone) + }() + select { + case <-emitDone: + case <-time.After(200 * time.Millisecond): + close(backingStore.release) + close(holdProviderRelease) + <-emitDone + t.Fatal("unrelated event journal blocked behind terminal status store update") + } + + close(backingStore.release) + close(holdProviderRelease) + waitForStatus(t, runner, doneRun.ID, RunStatusCompleted) + waitForStatus(t, runner, holdRun.ID, RunStatusCompleted) +} + type promptGateProvider struct { gates map[string]<-chan struct{} } @@ -135,6 +201,37 @@ type deadlineRecordingStore struct { deadline chan time.Duration } +type blockingTerminalStatusStore struct { + runstore.Store + + mu sync.Mutex + blockRunID string + once sync.Once + started chan struct{} + release chan struct{} +} + +func (s *blockingTerminalStatusStore) setBlockRunID(runID string) { + s.mu.Lock() + defer s.mu.Unlock() + s.blockRunID = runID +} + +func (s *blockingTerminalStatusStore) UpdateRun(ctx context.Context, run *runstore.Run) error { + s.mu.Lock() + blockRunID := s.blockRunID + s.mu.Unlock() + if run.ID == blockRunID && run.Status == runstore.RunStatusCompleted { + s.once.Do(func() { close(s.started) }) + select { + case <-s.release: + case <-ctx.Done(): + return ctx.Err() + } + } + return s.Store.UpdateRun(ctx, run) +} + func (s *deadlineRecordingStore) AppendEvent(ctx context.Context, event *runstore.Event) error { if event.EventType == string(EventRunCompleted) { if deadline, ok := ctx.Deadline(); ok { diff --git a/internal/server/http_terminal_atomicity_test.go b/internal/server/http_terminal_atomicity_test.go new file mode 100644 index 00000000..7bcb1413 --- /dev/null +++ b/internal/server/http_terminal_atomicity_test.go @@ -0,0 +1,161 @@ +package server + +import ( + "bytes" + "context" + "encoding/json" + "errors" + "io" + "net/http" + "net/http/httptest" + "strings" + "testing" + "time" + + "go-agent-harness/internal/harness" +) + +func TestTerminalStatusPollImmediatelyReplaysMatchingTerminalEvent(t *testing.T) { + tests := []struct { + name string + provider *terminalHTTPProvider + wantStatus harness.RunStatus + wantEvent harness.EventType + cancel bool + }{ + { + name: "completed", + provider: &terminalHTTPProvider{result: harness.CompletionResult{Content: "done"}}, + wantStatus: harness.RunStatusCompleted, + wantEvent: harness.EventRunCompleted, + }, + { + name: "failed", + provider: &terminalHTTPProvider{err: errors.New("provider unavailable")}, + wantStatus: harness.RunStatusFailed, + wantEvent: harness.EventRunFailed, + }, + { + name: "cancelled", + provider: &terminalHTTPProvider{started: make(chan struct{}), hang: true}, + wantStatus: harness.RunStatusCancelled, + wantEvent: harness.EventRunCancelled, + cancel: true, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + runner := harness.NewRunner(tt.provider, harness.NewRegistry(), harness.RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + }) + ts := httptest.NewServer(New(runner)) + t.Cleanup(func() { + ts.Close() + _ = runner.Shutdown(context.Background()) + }) + + runID := startTerminalHTTPRun(t, ts) + if tt.cancel { + select { + case <-tt.provider.started: + case <-time.After(2 * time.Second): + t.Fatal("provider did not start") + } + res, err := http.Post(ts.URL+"/v1/runs/"+runID+"/cancel", "application/json", nil) + if err != nil { + t.Fatalf("POST cancel: %v", err) + } + _ = res.Body.Close() + if res.StatusCode != http.StatusOK { + t.Fatalf("POST cancel status=%d, want %d", res.StatusCode, http.StatusOK) + } + } + + if got := waitForRunStatus(t, ts, runID, string(tt.wantStatus)); got != string(tt.wantStatus) { + t.Fatalf("terminal status=%s, want %s", got, tt.wantStatus) + } + + req, err := http.NewRequest(http.MethodGet, ts.URL+"/v1/runs/"+runID+"/events", nil) + if err != nil { + t.Fatalf("build reconnect request: %v", err) + } + req.Header.Set("Last-Event-ID", runID+":0") + res, err := http.DefaultClient.Do(req) + if err != nil { + t.Fatalf("GET event replay: %v", err) + } + body, readErr := io.ReadAll(res.Body) + _ = res.Body.Close() + if readErr != nil { + t.Fatalf("read event replay: %v", readErr) + } + if res.StatusCode != http.StatusOK { + t.Fatalf("GET event replay status=%d body=%s", res.StatusCode, body) + } + + replay := string(body) + matchingFrame := "event: " + string(tt.wantEvent) + "\n" + if strings.Count(replay, matchingFrame) != 1 { + t.Fatalf("terminal status %s replay count for %s=%d, want 1; replay=%s", + tt.wantStatus, tt.wantEvent, strings.Count(replay, matchingFrame), replay) + } + for _, other := range []harness.EventType{ + harness.EventRunCompleted, + harness.EventRunFailed, + harness.EventRunCancelled, + } { + if other != tt.wantEvent && strings.Contains(replay, "event: "+string(other)+"\n") { + t.Fatalf("terminal status %s replay included mismatched event %s; replay=%s", + tt.wantStatus, other, replay) + } + } + }) + } +} + +type terminalHTTPProvider struct { + result harness.CompletionResult + err error + started chan struct{} + hang bool +} + +func (p *terminalHTTPProvider) Complete(ctx context.Context, _ harness.CompletionRequest) (harness.CompletionResult, error) { + if p.started != nil { + select { + case <-p.started: + default: + close(p.started) + } + } + if p.hang { + <-ctx.Done() + return harness.CompletionResult{}, ctx.Err() + } + return p.result, p.err +} + +func startTerminalHTTPRun(t *testing.T, ts *httptest.Server) string { + t.Helper() + res, err := http.Post(ts.URL+"/v1/runs", "application/json", bytes.NewBufferString(`{"prompt":"terminal atomicity"}`)) + if err != nil { + t.Fatalf("POST run: %v", err) + } + defer res.Body.Close() + if res.StatusCode != http.StatusAccepted { + body, _ := io.ReadAll(res.Body) + t.Fatalf("POST run status=%d, want %d: %s", res.StatusCode, http.StatusAccepted, body) + } + var created struct { + RunID string `json:"run_id"` + } + if err := json.NewDecoder(res.Body).Decode(&created); err != nil { + t.Fatalf("decode run response: %v", err) + } + if created.RunID == "" { + t.Fatal("POST run returned empty run_id") + } + return created.RunID +} From ac96f943dd411aec28d1c066a1bfb7efd87150e6 Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 18:24:10 +0200 Subject: [PATCH 2/8] fix: persist terminal status before fanout --- docs/logs/engineering-log.md | 14 +- docs/logs/observational-log.md | 10 +- docs/logs/system-log.md | 12 +- ...minal-status-event-atomicity-impact-map.md | 14 +- ...67-terminal-status-event-atomicity-plan.md | 10 +- internal/harness/job_bridge.go | 2 + internal/harness/runner.go | 144 +++++++++++++----- .../harness/runner_terminal_store_test.go | 51 +++++++ 8 files changed, 194 insertions(+), 63 deletions(-) diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 93186a1d..fc4fee66 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -53,8 +53,10 @@ terminal helpers from performing mismatched side effects or overwriting the winning status. - Preserved reliability: terminal store I/O remains outside `Runner.mu`, and - status-store I/O remains outside the per-conversation journal lock; unrelated - `GetRun` and unrelated event journals stay responsive; durable-before-fanout, terminal + status-store I/O remains outside the global conversation journal lock; + a per-conversation sequence guard prevents same-conversation overtaking while + unrelated `GetRun` and unrelated event journals stay responsive; + durable-before-fanout, terminal redaction sealing, event IDs, causal/error snapshot order, recorder order, status persistence, backup, and pruning contracts remain intact. - Explicit exception: existing terminal `StorageModeNone` configurations still @@ -63,9 +65,11 @@ to terminal events retained by policy. - Regression coverage: completed/failed/cancelled barrier checks; required causal/error ordering; blocked terminal-store target status plus unrelated - query availability; 100-iteration competing terminal races; same-conversation - terminal-before-later-event subscriber ordering; and HTTP terminal poll - followed immediately by Last-Event-ID SSE replay. + query availability; blocked final-status persistence withholding both terminal + status and terminal fanout while unrelated journals progress; 100-iteration + competing terminal races; same-conversation terminal-before-later-event + subscriber ordering; and HTTP terminal poll followed immediately by + Last-Event-ID SSE replay. - Verification: focused normal/race stress passed at `-count=100`; complete `internal/harness` + `internal/server` normal/race and affected `go vet` passed; unchanged foreground non-TTY `./scripts/test-regression.sh` passed diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index 8085aa26..1e09ffa6 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -36,9 +36,13 @@ Use this file for observations about system behavior without immediately prescri run SSE from the first event ID must replay exactly one matching terminal event and no terminal event of another status. - Conversation-stream observation: terminal persistence and terminal fanout - must share the same per-conversation critical section; releasing it between - those phases lets a later run's event overtake the terminal event for an - already-connected conversation subscriber. + must share the same per-conversation sequence; the global journal lock can be + released for slow recorder/status persistence only if later events and + subscriptions on that conversation cannot overtake the terminal event. +- Durability observation: publishing terminal status or terminal fanout before + the final run record reaches the store violates the existing contract even + when event replay is already complete; unrelated conversations still need to + progress during that status-store write. ## 2026-07-31 (Source-Workflow Dual-Error Arbitration) diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index 09a87529..ba30baaf 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -25,14 +25,14 @@ terminal-seal owner; the transition seam binds the winning terminal event to its completed, failed, or cancelled `Run` record. - Order: prior causal/error events -> terminal ledger append/seal -> bounded - store append -> ordered terminal recorder dispatch/drain -> matching - in-memory and persisted status -> subscriber fanout -> backup/pruning + event-store append -> ordered terminal recorder dispatch/drain -> matching + persisted status -> matching in-memory status -> subscriber fanout -> backup/pruning lifecycle. - Concurrency boundary: store and recorder I/O remain outside `Runner.mu`. - `conversationEventMu` preserves replay-to-live ordering through event-store - append, recorder drain, in-memory status commit, and terminal fanout; it is - released before status-store I/O. The status commit briefly reacquires only - the Runner state lock. + A per-conversation sequence guard preserves replay-to-live ordering across + the whole transition. The global `conversationEventMu` is released around + recorder and status-store I/O, so unrelated conversation journals progress; + the in-memory status commit briefly reacquires only the Runner state lock. - Consumers: `GetRun`, run summary, run SSE replay/live delivery, conversation replay, CLI/TUI exit handling, and macOS transcript state keep existing schemas and event IDs. diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md index 55a58ae3..3ccde62a 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md @@ -36,8 +36,9 @@ - Schemas/migrations/caches/generated data: none. - Store order: matching terminal `AppendEvent` remains bounded and precedes - recorder dispatch, terminal status `UpdateRun`, and subscriber fanout; - status persistence occurs after releasing the per-conversation journal lock. + recorder dispatch, terminal status `UpdateRun`, in-memory status publication, + and subscriber fanout. Status persistence occurs after releasing the global + journal lock while retaining a target-conversation sequence guard. - Recorder: terminal JSONL remains queued after all prior events, closed once, and drained before terminal transition returns. - Compatibility: additive ordering guarantee only; event/status values and @@ -53,8 +54,9 @@ - Cancellation/retries/cleanup: cooperative cancellation and idempotency stay unchanged; workspace/tool/MCP cleanup remains before terminal publication. - Locks/resources: terminal store/recorder waits remain outside `Runner.mu`, so - unrelated queries are not blocked; status-store I/O also remains outside the - per-conversation journal lock, so unrelated event journals are not blocked. + unrelated queries are not blocked. Status-store I/O also remains outside the + global conversation journal lock; only the target conversation's sequence is + gated, so unrelated event journals are not blocked. - Auth/permissions/privacy/secrets: no boundary change after searches through run routes and redaction/audit paths; terminal payload redaction remains owned by the event journal. Explicit terminal `StorageModeNone` remains the @@ -93,8 +95,8 @@ winning sealed event; later same-conversation events cannot overtake terminal fanout to an existing conversation subscriber. - Store/recorder: durability and existing drain barriers preserve non-terminal - status without blocking unrelated queries; a blocked status-store write does - not block unrelated event journals. + status without blocking unrelated queries; a blocked final-status write also + withholds terminal fanout without blocking unrelated event journals. - Integration: HTTP poll immediately followed by run SSE replay for all three statuses. - Exact gates: focused normal/race stress `-count=100`; harness/server diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md index 43991a82..a0e6bd2c 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md @@ -45,8 +45,9 @@ - Store/recorder controls: block terminal store append and preserve the existing recorder drain regressions; assert target status remains non-terminal while unrelated run queries remain responsive, then becomes terminal only after - replay, durability, and recorder delivery are ready. Block status-store - persistence separately and prove unrelated event journals remain responsive. + replay, durability, and recorder delivery are ready. Block final status-store + persistence separately; prove terminal status and terminal fanout both wait + while unrelated event journals remain responsive. - Concurrency control: race competing terminal transitions and require the winning status to match the single sealed terminal event; hold a terminal at the pre-fanout boundary and prove a later same-conversation event cannot @@ -79,8 +80,9 @@ ## Risks and Mitigations - Risk: holding `Runner.mu` across persistence would block unrelated queries. -- Mitigation: retain the existing out-of-lock bounded terminal append/fanout - path and test unrelated `GetRun` responsiveness while it is blocked. +- Mitigation: retain out-of-lock store/recorder I/O, serialize only the target + conversation across the terminal sequence, and test unrelated `GetRun` and + unrelated conversation-journal responsiveness while persistence is blocked. - Risk: concurrent terminal helpers could publish one event and a different status. - Mitigation: serialize each run's complete terminal helper lifecycle, make the diff --git a/internal/harness/job_bridge.go b/internal/harness/job_bridge.go index 1067ed8a..3c6199f1 100644 --- a/internal/harness/job_bridge.go +++ b/internal/harness/job_bridge.go @@ -184,6 +184,8 @@ func (r *Runner) emitToConversation(convID, originRunID string, eventType EventT if convID == "" { return } + unlockSequence := r.lockConversationSequence(convID) + defer unlockSequence() r.conversationEventMu.Lock() defer r.conversationEventMu.Unlock() diff --git a/internal/harness/runner.go b/internal/harness/runner.go index 97c59ab7..cad788d1 100644 --- a/internal/harness/runner.go +++ b/internal/harness/runner.go @@ -326,6 +326,12 @@ type Runner struct { // boundary with no event prepared before registration and persisted after // the snapshot. conversationEventMu sync.Mutex + // conversationSequenceMu guards the per-conversation publication locks. + // A terminal transition may release conversationEventMu around status-store + // I/O while retaining its conversation lock, so unrelated conversations can + // progress without allowing same-conversation replay/live delivery to pass it. + conversationSequenceMu sync.Mutex + conversationSequence map[string]*sync.Mutex // conversationEvents is the bounded no-run-store replay fallback. Built-in // stores provide durable replay; third-party/no-store configurations retain // this process-local window instead. @@ -2011,6 +2017,8 @@ func (r *Runner) SubscribeConversationFrom( return nil, nil, nil, ConversationReplayInfo{}, fmt.Errorf("conversation %q not found", convID) } + unlockSequence := r.lockConversationSequence(convID) + defer unlockSequence() r.conversationEventMu.Lock() defer r.conversationEventMu.Unlock() @@ -2044,6 +2052,25 @@ func (r *Runner) SubscribeConversationFrom( return history, ch, cancel, replay, nil } +func (r *Runner) lockConversationSequence(convID string) func() { + key := strings.TrimSpace(convID) + if key == "" { + key = "__no_conversation__" + } + r.conversationSequenceMu.Lock() + if r.conversationSequence == nil { + r.conversationSequence = make(map[string]*sync.Mutex) + } + sequence := r.conversationSequence[key] + if sequence == nil { + sequence = &sync.Mutex{} + r.conversationSequence[key] = sequence + } + r.conversationSequenceMu.Unlock() + sequence.Lock() + return sequence.Unlock +} + func (r *Runner) conversationReplay( convID, tenantID, lastEventID string, ) ([]Event, ConversationReplayInfo) { @@ -4206,31 +4233,48 @@ func (a usageTotalsAccumulator) completionUsage() CompletionUsage { } func (r *Runner) setStatus(runID string, status RunStatus, output, runErr string) { - if !r.setStatusInMemory(runID, status, output, runErr) { + finalRun, ok := r.statusRunSnapshot(runID, status, output, runErr) + if !ok || !r.commitStatusSnapshot(runID, finalRun) { return } // Persist the updated run state to the store (non-fatal, called after unlock). - r.storeUpdateRun(runID) + r.storeUpdateRunSnapshot(finalRun) } -func (r *Runner) setStatusInMemory(runID string, status RunStatus, output, runErr string) bool { - r.mu.Lock() - +func (r *Runner) statusRunSnapshot(runID string, status RunStatus, output, runErr string) (Run, bool) { + r.mu.RLock() state, ok := r.runs[runID] if !ok { - r.mu.Unlock() - return false + r.mu.RUnlock() + return Run{}, false } - state.run.Status = status - state.run.Output = output - state.run.Error = runErr - state.run.UpdatedAt = time.Now().UTC() + finalRun := state.run + finalRun.Status = status + finalRun.Output = output + finalRun.Error = runErr + finalRun.UpdatedAt = time.Now().UTC() if shouldPersistWorkflowRecap(status) { - state.run.Recap = buildWorkflowRecap(state.run, state.messages, state.events) + finalRun.Recap = buildWorkflowRecap(finalRun, state.messages, state.events) } else { - state.run.Recap = nil + finalRun.Recap = nil } + r.mu.RUnlock() + return finalRun, true +} + +func (r *Runner) commitStatusSnapshot(runID string, finalRun Run) bool { + r.mu.Lock() + state, ok := r.runs[runID] + if !ok { + r.mu.Unlock() + return false + } + state.run.Status = finalRun.Status + state.run.Output = finalRun.Output + state.run.Error = finalRun.Error + state.run.UpdatedAt = finalRun.UpdatedAt + state.run.Recap = finalRun.Recap r.mu.Unlock() return true } @@ -5369,20 +5413,35 @@ func (r runTranscriptReader) Snapshot(limit int, includeTools bool) htools.Trans // emit appends one event to the canonical in-memory ledger and mirrors that // same event to subscribers and the optional JSONL recorder. func (r *Runner) emit(runID string, eventType EventType, payload map[string]any) bool { - return r.emitWithTerminalCommit(runID, eventType, payload, nil) + return r.emitWithTerminalCommit(runID, eventType, payload, nil, nil) } -// emitWithTerminalCommit runs terminalCommit after the terminal event is in -// replay/store/recorder history but before subscribers receive it. The commit -// changes only in-memory status; its store write happens after this method -// releases conversationEventMu so status-store I/O cannot stall unrelated -// event journals or conversation subscriptions. Non-terminal callers pass nil. +// emitWithTerminalCommit runs terminalPersist and terminalCommit after the +// terminal event is in replay/store/recorder history but before subscribers +// receive it. The global conversationEventMu is released around recorder and +// status-store I/O while a per-conversation sequence lock prevents overtaking; +// unrelated conversation journals remain available. Non-terminal callers pass +// nil callbacks. func (r *Runner) emitWithTerminalCommit( runID string, eventType EventType, payload map[string]any, + terminalPersist func(), terminalCommit func(), ) bool { + r.mu.RLock() + initialState := r.runs[runID] + conversationID := "" + if initialState != nil { + conversationID = initialState.run.ConversationID + } + r.mu.RUnlock() + if initialState == nil { + return false + } + unlockSequence := r.lockConversationSequence(conversationID) + defer unlockSequence() + r.conversationEventMu.Lock() conversationLocked := true defer func() { @@ -5418,7 +5477,14 @@ func (r *Runner) emitWithTerminalCommit( if r.terminalBeforeDispatchHook != nil { r.terminalBeforeDispatchHook(runID, eventType) } + r.conversationEventMu.Unlock() + conversationLocked = false journal.dispatch(delivery) + if terminalPersist != nil { + terminalPersist() + } + r.conversationEventMu.Lock() + conversationLocked = true if terminalCommit != nil { terminalCommit() } @@ -5428,7 +5494,14 @@ func (r *Runner) emitWithTerminalCommit( return true } if delivery.dropped { + r.conversationEventMu.Unlock() + conversationLocked = false journal.dispatch(delivery) + if IsTerminalEvent(eventType) && terminalPersist != nil { + terminalPersist() + } + r.conversationEventMu.Lock() + conversationLocked = true if IsTerminalEvent(eventType) && terminalCommit != nil { terminalCommit() } @@ -5481,16 +5554,20 @@ func (r *Runner) transitionTerminal( r.terminalTransitionHook(runID, status, eventType) } committed := false + var finalRun Run + prepared := false if !r.emitWithTerminalCommit(runID, eventType, payload, func() { - committed = r.setStatusInMemory(runID, status, output, runErr) + finalRun, prepared = r.statusRunSnapshot(runID, status, output, runErr) + if prepared { + r.storeUpdateRunSnapshot(finalRun) + } + }, func() { + if prepared { + committed = r.commitStatusSnapshot(runID, finalRun) + } }) { return false } - if committed { - // Keep status-store I/O outside conversationEventMu: one slow run store - // must not stop every conversation journal from making progress. - r.storeUpdateRun(runID) - } return committed } @@ -5684,26 +5761,15 @@ func (r *Runner) storeCreateRun(run Run) { } } -// storeUpdateRun persists the current run state (status, output, error) to the store. -// Called from setStatus after each status transition. -func (r *Runner) storeUpdateRun(runID string) { - rc := r.configForRun(runID) +func (r *Runner) storeUpdateRunSnapshot(run Run) { + rc := r.configForRun(run.ID) if rc.Store == nil { return } - r.mu.RLock() - state, ok := r.runs[runID] - if !ok { - r.mu.RUnlock() - return - } - run := state.run - r.mu.RUnlock() - sr := runToStoreRun(run) if err := rc.Store.UpdateRun(context.Background(), sr); err != nil { if rc.Logger != nil { - rc.Logger.Error("store: UpdateRun failed", "run_id", runID, "error", err) + rc.Logger.Error("store: UpdateRun failed", "run_id", run.ID, "error", err) } } } diff --git a/internal/harness/runner_terminal_store_test.go b/internal/harness/runner_terminal_store_test.go index df6ba9a2..cedfbec2 100644 --- a/internal/harness/runner_terminal_store_test.go +++ b/internal/harness/runner_terminal_store_test.go @@ -131,6 +131,16 @@ func TestTerminalStatusStoreUpdateDoesNotBlockOtherEventJournals(t *testing.T) { if err != nil { t.Fatalf("StartRun done: %v", err) } + history, terminalStream, unsubscribe, err := runner.Subscribe(doneRun.ID) + if err != nil { + t.Fatalf("Subscribe done: %v", err) + } + defer unsubscribe() + for _, event := range history { + if IsTerminalEvent(event.Type) { + t.Fatalf("done run unexpectedly terminal before provider release: %s", event.Type) + } + } backingStore.setBlockRunID(doneRun.ID) close(doneProviderRelease) @@ -141,6 +151,26 @@ func TestTerminalStatusStoreUpdateDoesNotBlockOtherEventJournals(t *testing.T) { t.Fatal("timed out waiting for terminal status store update to block") } + blockedRun, ok := runner.GetRun(doneRun.ID) + if !ok { + t.Fatalf("GetRun(%q) returned false during terminal status persistence", doneRun.ID) + } + if isTerminalRunStatus(blockedRun.Status) { + t.Fatalf("GetRun exposed %s before terminal status persistence completed", blockedRun.Status) + } + for { + select { + case event := <-terminalStream: + if IsTerminalEvent(event.Type) { + t.Fatalf("terminal event %s fanned out before final status persistence completed", event.Type) + } + default: + goto streamDrained + } + } + +streamDrained: + emitDone := make(chan struct{}) go func() { runner.emit(holdRun.ID, EventAssistantMessage, map[string]any{"content": "still responsive"}) @@ -156,6 +186,27 @@ func TestTerminalStatusStoreUpdateDoesNotBlockOtherEventJournals(t *testing.T) { } close(backingStore.release) + deadline := time.After(2 * time.Second) + for { + select { + case event := <-terminalStream: + if event.Type == EventRunCompleted { + goto terminalDelivered + } + case <-deadline: + t.Fatal("terminal event was not delivered after final status persistence completed") + } + } + +terminalDelivered: + storedRun, err := backingStore.Store.GetRun(context.Background(), doneRun.ID) + if err != nil { + t.Fatalf("store.GetRun(%q): %v", doneRun.ID, err) + } + if storedRun.Status != runstore.RunStatusCompleted || storedRun.Output != "ok: done" { + t.Fatalf("stored run after terminal fanout = status %q output %q, want completed/ok: done", + storedRun.Status, storedRun.Output) + } close(holdProviderRelease) waitForStatus(t, runner, doneRun.ID, RunStatusCompleted) waitForStatus(t, runner, holdRun.ID, RunStatusCompleted) From 1ef8cc4de234c291fae07eb2eb1e2290612a0c2b Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 19:15:10 +0200 Subject: [PATCH 3/8] fix: harden terminal publication failure policy --- docs/logs/engineering-log.md | 55 +- docs/logs/long-term-thinking-log.md | 20 +- docs/logs/observational-log.md | 14 +- docs/logs/system-log.md | 20 +- ...minal-status-event-atomicity-impact-map.md | 45 +- ...67-terminal-status-event-atomicity-plan.md | 69 ++- docs/plans/active-plan.md | 13 +- internal/harness/runner.go | 127 ++++- internal/harness/runner_event_journal.go | 40 +- .../harness/runner_terminal_atomicity_test.go | 19 +- .../runner_terminal_failure_policy_test.go | 487 ++++++++++++++++++ 11 files changed, 783 insertions(+), 126 deletions(-) create mode 100644 internal/harness/runner_terminal_failure_policy_test.go diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index fc4fee66..1261a02b 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -47,37 +47,42 @@ `error.context` but lacked `run.failed`, and cancelled replay lacked `run.cancelled` while `GetRun` already returned each terminal status. - Fix: one `transitionTerminal` seam now lets the winning terminal emit seal and - append the matching event, completes the bounded store append and ordered - recorder dispatch/drain, commits and persists the matching status, then fans - out to subscribers. Per-run transition serialization prevents competing - terminal helpers from performing mismatched side effects or overwriting the - winning status. + append the matching event, completes bounded store append and ordered recorder + dispatch/drain, conditionally persists the matching status, commits in-memory + status, then fans out. Every status transition shares a per-run mutex, so a + delayed running/waiting snapshot cannot overwrite terminal state. - Preserved reliability: terminal store I/O remains outside `Runner.mu`, and status-store I/O remains outside the global conversation journal lock; - a per-conversation sequence guard prevents same-conversation overtaking while - unrelated `GetRun` and unrelated event journals stay responsive; - durable-before-fanout, terminal - redaction sealing, event IDs, causal/error snapshot order, recorder order, - status persistence, backup, and pruning contracts remain intact. + a refcounted per-conversation sequence guard prevents same-conversation + overtaking while unrelated `GetRun` and unrelated event journals stay + responsive, then reclaims idle keys. Terminal redaction sealing, event IDs, + causal/error snapshot order, recorder order, backup, and pruning contracts + remain intact. +- Failure policy: retained terminal status persistence is never attempted when + terminal append reports failure. If append succeeds but final status update + errors or reaches its context deadline, durable status may remain + non-terminal while the durable event, in-memory terminal state, and subscriber + fanout proceed. This is the strongest one-way guarantee available without a + store transaction and does not claim two-way atomicity. - Explicit exception: existing terminal `StorageModeNone` configurations still suppress the matching replay event while sealing and publishing status, as pinned by terminal-redaction tests. The stronger replay implication applies to terminal events retained by policy. -- Regression coverage: completed/failed/cancelled barrier checks; required - causal/error ordering; blocked terminal-store target status plus unrelated - query availability; blocked final-status persistence withholding both terminal - status and terminal fanout while unrelated journals progress; 100-iteration - competing terminal races; same-conversation terminal-before-later-event - subscriber ordering; and HTTP terminal poll followed immediately by - Last-Event-ID SSE replay. -- Verification: focused normal/race stress passed at `-count=100`; complete - `internal/harness` + `internal/server` normal/race and affected `go vet` - passed; unchanged foreground non-TTY `./scripts/test-regression.sh` passed - normal, race, and coverage at 85.6% with zero uncovered functions. -- Environmental retry evidence: the first coverage attempt hit two real - Keychain 15-second kills plus an OpenRouter connection reset. A direct - affected coverage run passed, and an unchanged full-gate retry passed without - code, test, or command changes. +- Review regressions: append failure cannot persist terminal status; status + update failure/timeout still completes live publication; unrelated + conversations progress during terminal I/O while target events cannot + overtake; delayed non-terminal status cannot overwrite terminal; explicit + terminal redaction waits for recorder drain; and contended/distinct keyed + locks reclaim to zero. +- Verification: the expanded terminal suite and HTTP replay passed normal/race + at `-count=100`; complete `internal/harness` + `internal/server` normal/race + and affected `go vet` passed. The first final full-regression invocation + passed normal and race, then returned red during its coverage stage with the + failure diagnostic lost in the command's oversized coverage output. The + unchanged full coverage command passed immediately afterward and + `coveragegate` reported 85.6% total with zero uncovered functions. A fresh + uninterrupted `./scripts/test-regression.sh` then passed normal, race, and + coverage at the same 85.6%/zero-function threshold. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/long-term-thinking-log.md b/docs/logs/long-term-thinking-log.md index 9a72de0a..b442653f 100644 --- a/docs/logs/long-term-thinking-log.md +++ b/docs/logs/long-term-thinking-log.md @@ -43,13 +43,19 @@ regression, and hosted checks pass on one unmerged closing PR. - Non-goals: conversation cursor redesign, cron/callback behavior, client UI, provider routing, schemas, or workflow timing changes. -- Guardrails: preserve out-of-lock bounded store writes, durable-before-fanout, - terminal sealing, recorder drain order, cleanup order, causal/error snapshots, - status persistence, SSE IDs, and unrelated query responsiveness. -- Outcome: one winner-only transition now commits terminal ledger/store history - before matching status and subscriber fanout. Deterministic all-status red, - focused normal/race stress, affected normal/race/vet, HTTP reconnect, and the - unchanged full regression are green locally; PR and hosted review remain. +- Guardrails: preserve out-of-lock bounded store writes, terminal sealing, + recorder drain order, cleanup order, causal/error snapshots, SSE IDs, and + unrelated conversation responsiveness. Do not claim a cross-record store + transaction the interface cannot provide. +- Outcome: one winner-only transition now publishes terminal ledger history + before matching in-memory status and subscriber fanout. Retained terminal + status persistence is attempted only after event append reports success; + append/status failures have explicit bounded live-availability behavior. + Shared per-run status serialization prevents a delayed non-terminal overwrite, + and refcounted per-conversation sequencing avoids both overtaking and lock-map + growth. Focused normal/race stress, affected normal/race/vet, and HTTP replay + plus the unchanged full repository regression are green on the final review + diff; hosted gates remain pending parent promotion. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index 1e09ffa6..6990d172 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -39,10 +39,16 @@ Use this file for observations about system behavior without immediately prescri must share the same per-conversation sequence; the global journal lock can be released for slow recorder/status persistence only if later events and subscriptions on that conversation cannot overtake the terminal event. -- Durability observation: publishing terminal status or terminal fanout before - the final run record reaches the store violates the existing contract even - when event replay is already complete; unrelated conversations still need to - progress during that status-store write. +- Durability observation: the current store interface has separate + `AppendEvent` and `UpdateRun` calls, so it cannot promise two-way atomicity. + The enforceable direction is: never attempt retained terminal status + persistence after terminal append reports failure. If status update then + fails or times out, durable event may lead durable status while bounded + in-memory status and fanout still complete. +- Resource observation: a keyed sequence lock needs waiter-inclusive reference + accounting. Deleting only after owners and queued waiters release prevents a + second lock generation for the same key and avoids an unbounded conversation + map. ## 2026-07-31 (Source-Workflow Dual-Error Arbitration) diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index ba30baaf..020fc6d0 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -26,8 +26,8 @@ its completed, failed, or cancelled `Run` record. - Order: prior causal/error events -> terminal ledger append/seal -> bounded event-store append -> ordered terminal recorder dispatch/drain -> matching - persisted status -> matching in-memory status -> subscriber fanout -> backup/pruning - lifecycle. + conditional status persistence -> matching in-memory status -> subscriber + fanout -> backup/pruning lifecycle. - Concurrency boundary: store and recorder I/O remain outside `Runner.mu`. A per-conversation sequence guard preserves replay-to-live ordering across the whole transition. The global `conversationEventMu` is released around @@ -36,11 +36,17 @@ - Consumers: `GetRun`, run summary, run SSE replay/live delivery, conversation replay, CLI/TUI exit handling, and macOS transcript state keep existing schemas and event IDs. -- Failure boundary: bounded store errors remain non-fatal and live in-memory - replay remains available; terminal redaction drops still seal and publish - status by the existing explicit policy; a competing terminal helper is - serialized before terminal side effects, loses the seal, and cannot write a - mismatched audit/profile outcome or overwrite status. +- Failure boundary: retained terminal `UpdateRun` is attempted only after + `AppendEvent` reports success. Append failure leaves durable status + non-terminal; later status-update failure/timeout may leave durable terminal + event ahead of durable status. Both remain non-fatal to bounded in-memory + status/fanout, so this is explicitly one-way rather than transactional + two-way atomicity. Terminal redaction drops remain the explicit no-event + exception and now drain the recorder before publishing status. +- Status/resource boundary: every status transition shares a per-run mutex, so + delayed non-terminal writes cannot overwrite terminal state. The + per-conversation sequence lock counts queued waiters and deletes idle keys; + external terminal I/O never holds the global conversation journal mutex. ## 2026-07-31 (Source-Workflow Terminal Error Arbitration) diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md index 3ccde62a..a1ffb4b0 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md @@ -5,7 +5,8 @@ - Task / issue: #1067, terminal status visible before matching replay event. - Plan: `2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md`. - Owner: Codex. -- Status: implemented and fully verified locally; hosted checks pending. +- Status: review hardening implemented and fully verified locally; hosted + checks pending. ## Current Ownership, Callers, and Data Flow @@ -35,12 +36,19 @@ ## Persistence and Compatibility - Schemas/migrations/caches/generated data: none. -- Store order: matching terminal `AppendEvent` remains bounded and precedes - recorder dispatch, terminal status `UpdateRun`, in-memory status publication, - and subscriber fanout. Status persistence occurs after releasing the global - journal lock while retaining a target-conversation sequence guard. +- Store order: matching retained terminal `AppendEvent` is bounded and precedes + recorder dispatch, conditional terminal status `UpdateRun`, in-memory status + publication, and subscriber fanout. `UpdateRun` is attempted only after + `AppendEvent` reports success. An append error leaves durable status + non-terminal; an update error can leave a durable terminal event with a + non-terminal durable run row. In either case, bounded in-memory terminal + publication/fanout completes. This is a one-way invariant, not a two-record + transaction; third-party stores must return errors without partial writes if + they need the same durable-read characterization as the built-in stores. - Recorder: terminal JSONL remains queued after all prior events, closed once, - and drained before terminal transition returns. + and drained before terminal transition returns. An explicitly suppressed + `StorageModeNone` terminal also closes and drains the recorder before status + visibility even though no terminal event is appended. - Compatibility: additive ordering guarantee only; event/status values and replay IDs remain stable. - Mixed-version behavior: process-local; older daemons retain the race until @@ -50,21 +58,23 @@ - Concurrency: the winning terminal event seals the ledger before status is updated; competing terminal helpers cannot overwrite it with a mismatched - status. + status. Every status snapshot/persist/commit sequence shares a per-run mutex, + so a delayed running/waiting write cannot overwrite terminal state. - Cancellation/retries/cleanup: cooperative cancellation and idempotency stay unchanged; workspace/tool/MCP cleanup remains before terminal publication. -- Locks/resources: terminal store/recorder waits remain outside `Runner.mu`, so - unrelated queries are not blocked. Status-store I/O also remains outside the - global conversation journal lock; only the target conversation's sequence is - gated, so unrelated event journals are not blocked. +- Locks/resources: terminal store/recorder waits remain outside `Runner.mu` and + the global conversation journal lock. A refcounted target-conversation lock + prevents same-conversation overtaking while unrelated journals progress, and + deletes itself when owners and queued waiters drain. - Auth/permissions/privacy/secrets: no boundary change after searches through run routes and redaction/audit paths; terminal payload redaction remains owned by the event journal. Explicit terminal `StorageModeNone` remains the documented exception: it seals and publishes status without replaying the intentionally suppressed event. -- Failure/recovery: bounded store failures remain non-fatal and in-memory replay - remains authoritative for the live Runner; persisted-before-prune guards stay - intact. +- Failure/recovery: append and status writes use bounded contexts and failures + remain non-fatal to the live Runner. In-memory replay/status/fanout remain + authoritative for that process; persisted-before-prune guards stay intact. + No two-way durable atomicity is claimed without a transactional store API. ## Product and Integration Surfaces @@ -94,9 +104,10 @@ snapshot precedes `run.failed`; competing terminal transitions match the winning sealed event; later same-conversation events cannot overtake terminal fanout to an existing conversation subscriber. -- Store/recorder: durability and existing drain barriers preserve non-terminal - status without blocking unrelated queries; a blocked final-status write also - withholds terminal fanout without blocking unrelated event journals. +- Store/recorder: blocked append allows unrelated conversations but not target + overtaking; append error prevents terminal status persistence; status update + error/timeout preserves live publication; retained and suppressed terminal + recorder paths drain before status visibility. - Integration: HTTP poll immediately followed by run SSE replay for all three statuses. - Exact gates: focused normal/race stress `-count=100`; harness/server diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md index a0e6bd2c..9483f304 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md @@ -10,10 +10,11 @@ - User impact: API polling, SSE reconnect, CLI/TUI, and macOS clients can briefly render terminal state without the authoritative terminal transcript or its preceding causal/error evidence. -- Constraints: preserve durable-before-fanout, terminal sealing, recorder - drain ordering, bounded store writes, run-independent query availability, - current event/status schemas, cleanup ordering, and the explicit - `StorageModeNone` terminal-redaction policy. +- Constraints: preserve terminal sealing, recorder drain ordering, bounded + store writes, run-independent availability, current event/status schemas, + cleanup ordering, and the explicit `StorageModeNone` terminal-redaction + policy. The store API has no cross-record transaction, so promise the + testable one-way invariant rather than two-way event/status atomicity. ## Scope @@ -26,7 +27,8 @@ ## Documentation Contract -- Feature status: implemented and fully verified locally; hosted checks pending. +- Feature status: review hardening implemented and fully verified locally; + hosted checks pending. - Public docs affected: none; existing terminal event/status wire formats stay unchanged. - Spec docs before code: this plan and its linked impact map. @@ -42,12 +44,13 @@ - Causal control: on an error-chain-enabled failure, the required `error.context` snapshot must precede `run.failed` before failed status is observable. -- Store/recorder controls: block terminal store append and preserve the existing - recorder drain regressions; assert target status remains non-terminal while - unrelated run queries remain responsive, then becomes terminal only after - replay, durability, and recorder delivery are ready. Block final status-store - persistence separately; prove terminal status and terminal fanout both wait - while unrelated event journals remain responsive. +- Store/recorder controls: block terminal append and prove unrelated + conversations progress while later events in the target conversation cannot + overtake. On append error, never attempt a durable terminal status update but + still complete bounded in-memory terminal publication/fanout. On status + update error or context timeout after a successful append, keep the durable + run non-terminal while the live Runner and subscribers complete. For an + explicit `StorageModeNone` drop, drain the recorder before status visibility. - Concurrency control: race competing terminal transitions and require the winning status to match the single sealed terminal event; hold a terminal at the pre-fanout boundary and prove a later same-conversation event cannot @@ -71,7 +74,8 @@ - [x] Write this plan and impact map before code. - [x] Add and confirm the deterministic failing regressions. - [x] Implement the smallest shared terminal-transition repair. -- [x] Confirm focused stress, affected normal/race/vet, and repository gates. +- [x] Confirm focused stress and affected normal/race/vet gates. +- [x] Confirm the unchanged repository regression gate on the final diff. - [x] Prove the HTTP poll-then-replay path. - [x] Update all required logs and documentation status. - [ ] Open one closing PR, push its exact head, and request `@codex` review. @@ -92,9 +96,19 @@ profile persistence, backup, or pruning. - Mitigation: pin causal/event order and keep cleanup before terminal transition, operational side effects after the matching status/event pair. -- Risk: recorder or store failure could weaken the existing lifecycle. -- Mitigation: preserve bounded non-fatal persistence semantics, recorder drain, - terminal retention, and terminal-event-persisted pruning guards. +- Risk: the store API cannot atomically append an event and update the run row. +- Mitigation: enforce the one-way invariant that retained terminal status is + never attempted unless terminal `AppendEvent` reported success. If append + fails, durable status stays non-terminal; if final `UpdateRun` fails after a + successful append, the durable event may lead the durable status. Both + failures remain bounded and non-fatal to in-memory status/fanout. This does + not claim two-way transactional atomicity or infer whether a third-party store + applied a write before returning an error. +- Risk: recorder or store delay could weaken availability or lifecycle order. +- Mitigation: use context-bounded terminal store calls, keep external I/O out + of the global conversation mutex, preserve target-conversation sequencing, + drain retained and suppressed terminal recorders, and reclaim idle keyed + sequence locks. - Risk: an explicit terminal `StorageModeNone` policy intentionally removes the matching event from replay. - Mitigation: preserve and test the existing redaction exception and scope the @@ -107,15 +121,20 @@ '^TestTerminalStatusNeverPrecedesTerminalReplayEvent$' -count=1` failed all three cases: completed before `run.completed`, failed after `error.context` but before `run.failed`, and cancelled before `run.cancelled`. -- Focused final green: terminal atomicity, competing transitions, blocked store, - and HTTP replay passed normal and race at `-count=100` across - `internal/harness` and `internal/server`. -- Affected packages: complete harness/server normal and race passed; `go vet` - passed. +- Review reds: blocked terminal append serialized an unrelated conversation; + append failure still persisted terminal status; delayed non-terminal status + overwrote terminal status; context-blocking final status persistence stranded + the transition; an explicit terminal redaction drop exposed status before + recorder drain; and keyed sequence entries were never reclaimed. +- Focused current green: all terminal publication/failure-policy regressions + and HTTP replay passed normal and race at `-count=100`. +- Affected current green: complete harness/server normal and race passed; + affected `go vet` passed. - Real path: HTTP terminal polling followed immediately by Last-Event-ID run SSE replay passed for completed, failed, and cancelled. -- Repository: unchanged foreground non-TTY `./scripts/test-regression.sh` - passed normal, race, and coverage - (`total=85.6%`, `zero-functions=0`). An earlier coverage attempt hit transient - real-Keychain timeouts plus an OpenRouter connection reset; the unchanged - retry passed completely without code or command changes. +- Repository: a fresh uninterrupted foreground non-TTY + `./scripts/test-regression.sh` passed normal, race, and coverage + (`total=85.6%`, `zero-functions=0`). Its immediately preceding invocation + passed normal/race but returned red in coverage without retaining the hidden + diagnostic; the unchanged coverage command and gate then passed before the + complete clean rerun. diff --git a/docs/plans/active-plan.md b/docs/plans/active-plan.md index 6c1df9ac..bee6df68 100644 --- a/docs/plans/active-plan.md +++ b/docs/plans/active-plan.md @@ -1,10 +1,15 @@ # Active Plan Current status: Issue #1067 terminal publication atomicity is implemented on -isolated branch `codex/issue-1067-terminal-status-event-atomicity`. The hosted -durability regression has a deterministic local red-green repair; final gates -on the branch rebased to current `main` remain in progress before parent -promotion to open PR #1070. PR #1060 and PR #1055 remain excluded. +isolated branch `codex/issue-1067-terminal-status-event-atomicity`. Post-review +hardening now defines and tests the one-way durable failure contract, bounded +store waits, per-run status serialization, per-conversation lock reclamation, +and recorder drain for suppressed terminal events. Focused and affected-package +gates and the unchanged full repository regression are green on the branch +rebased to current `main`. Open PR #1070 still points at its older head and is +intentionally unpushed pending parent composition with #1055. PR #1060 remains +excluded; hosted checks remain pending until the parent promotes the composed +head. Current status: Issue #1023 anytime contextual `/feedback` intake is implemented test-first and verified in its isolated worktree; targeted, full normal/race, diff --git a/internal/harness/runner.go b/internal/harness/runner.go index cad788d1..0ec0327a 100644 --- a/internal/harness/runner.go +++ b/internal/harness/runner.go @@ -109,6 +109,10 @@ type runState struct { // terminalMu serializes the complete terminal-helper lifecycle so only the // event winner may run terminal audit/profile/cleanup side effects. terminalMu sync.Mutex + // statusMu serializes every status snapshot/persist/commit sequence with the + // terminal transition. A delayed waiting/running write therefore cannot + // overwrite a terminal result. + statusMu sync.Mutex // compactMu serializes auto-compact and manual CompactRun calls. compactMu sync.RWMutex // resetIndex increments each time the agent calls reset_context. @@ -331,7 +335,7 @@ type Runner struct { // I/O while retaining its conversation lock, so unrelated conversations can // progress without allowing same-conversation replay/live delivery to pass it. conversationSequenceMu sync.Mutex - conversationSequence map[string]*sync.Mutex + conversationSequence map[string]*conversationSequenceLock // conversationEvents is the bounded no-run-store replay fallback. Built-in // stores provide durable replay; third-party/no-store configurations retain // this process-local window instead. @@ -361,6 +365,12 @@ type Runner struct { // terminalBeforeDispatchHook is a test seam invoked after terminal replay // persistence and before recorder/status/subscriber publication. terminalBeforeDispatchHook func(string, EventType) + // statusBeforeCommitHook is a test seam invoked after a non-terminal status + // snapshot is prepared and before it is committed. + statusBeforeCommitHook func(string, RunStatus) + // terminalStoreTimeout overrides the bounded terminal store timeout in + // deterministic tests. Zero uses terminalEventStoreTimeout. + terminalStoreTimeout time.Duration // runQueue is a FIFO channel of pending (runID, req) pairs waiting for a // worker slot. It is only used when workerSem is non-nil. runQueue chan queuedRun @@ -2059,16 +2069,33 @@ func (r *Runner) lockConversationSequence(convID string) func() { } r.conversationSequenceMu.Lock() if r.conversationSequence == nil { - r.conversationSequence = make(map[string]*sync.Mutex) + r.conversationSequence = make(map[string]*conversationSequenceLock) } sequence := r.conversationSequence[key] if sequence == nil { - sequence = &sync.Mutex{} + sequence = &conversationSequenceLock{} r.conversationSequence[key] = sequence } + sequence.refs++ r.conversationSequenceMu.Unlock() - sequence.Lock() - return sequence.Unlock + sequence.mu.Lock() + var unlockOnce sync.Once + return func() { + unlockOnce.Do(func() { + sequence.mu.Unlock() + r.conversationSequenceMu.Lock() + sequence.refs-- + if sequence.refs == 0 && r.conversationSequence[key] == sequence { + delete(r.conversationSequence, key) + } + r.conversationSequenceMu.Unlock() + }) + } +} + +type conversationSequenceLock struct { + mu sync.Mutex + refs int } func (r *Runner) conversationReplay( @@ -4233,8 +4260,30 @@ func (a usageTotalsAccumulator) completionUsage() CompletionUsage { } func (r *Runner) setStatus(runID string, status RunStatus, output, runErr string) { + r.mu.RLock() + state := r.runs[runID] + r.mu.RUnlock() + if state == nil { + return + } + state.statusMu.Lock() + defer state.statusMu.Unlock() + + r.mu.RLock() + current := r.runs[runID] + available := current == state && !state.terminated && !isTerminalRunStatus(state.run.Status) + r.mu.RUnlock() + if !available { + return + } finalRun, ok := r.statusRunSnapshot(runID, status, output, runErr) - if !ok || !r.commitStatusSnapshot(runID, finalRun) { + if !ok { + return + } + if r.statusBeforeCommitHook != nil { + r.statusBeforeCommitHook(runID, status) + } + if !r.commitStatusSnapshot(runID, finalRun) { return } @@ -4270,6 +4319,14 @@ func (r *Runner) commitStatusSnapshot(runID string, finalRun Run) bool { r.mu.Unlock() return false } + if state.terminated && !isTerminalRunStatus(finalRun.Status) { + r.mu.Unlock() + return false + } + if isTerminalRunStatus(state.run.Status) && !isTerminalRunStatus(finalRun.Status) { + r.mu.Unlock() + return false + } state.run.Status = finalRun.Status state.run.Output = finalRun.Output state.run.Error = finalRun.Error @@ -5426,7 +5483,7 @@ func (r *Runner) emitWithTerminalCommit( runID string, eventType EventType, payload map[string]any, - terminalPersist func(), + terminalPersist func(bool), terminalCommit func(), ) bool { r.mu.RLock() @@ -5473,15 +5530,20 @@ func (r *Runner) emitWithTerminalCommit( return false } if publishTerminal { - journal.persistTerminal(delivery) + r.conversationEventMu.Unlock() + conversationLocked = false + eventPersisted := journal.persistTerminalEvent(delivery) + r.conversationEventMu.Lock() + conversationLocked = true + journal.recordTerminalConversation(delivery) + r.conversationEventMu.Unlock() + conversationLocked = false if r.terminalBeforeDispatchHook != nil { r.terminalBeforeDispatchHook(runID, eventType) } - r.conversationEventMu.Unlock() - conversationLocked = false journal.dispatch(delivery) if terminalPersist != nil { - terminalPersist() + terminalPersist(eventPersisted) } r.conversationEventMu.Lock() conversationLocked = true @@ -5498,7 +5560,10 @@ func (r *Runner) emitWithTerminalCommit( conversationLocked = false journal.dispatch(delivery) if IsTerminalEvent(eventType) && terminalPersist != nil { - terminalPersist() + // StorageModeNone intentionally suppresses the terminal event; its + // status remains persistable by explicit policy rather than being + // classified as an AppendEvent failure. + terminalPersist(true) } r.conversationEventMu.Lock() conversationLocked = true @@ -5553,12 +5618,27 @@ func (r *Runner) transitionTerminal( if r.terminalTransitionHook != nil { r.terminalTransitionHook(runID, status, eventType) } + r.mu.RLock() + state := r.runs[runID] + r.mu.RUnlock() + if state == nil { + return false + } + state.statusMu.Lock() + defer state.statusMu.Unlock() + r.mu.RLock() + current := r.runs[runID] + available := current == state && !state.terminated + r.mu.RUnlock() + if !available { + return false + } committed := false var finalRun Run prepared := false - if !r.emitWithTerminalCommit(runID, eventType, payload, func() { + if !r.emitWithTerminalCommit(runID, eventType, payload, func(eventPersisted bool) { finalRun, prepared = r.statusRunSnapshot(runID, status, output, runErr) - if prepared { + if prepared && eventPersisted { r.storeUpdateRunSnapshot(finalRun) } }, func() { @@ -5761,17 +5841,28 @@ func (r *Runner) storeCreateRun(run Run) { } } -func (r *Runner) storeUpdateRunSnapshot(run Run) { +func (r *Runner) storeUpdateRunSnapshot(run Run) bool { rc := r.configForRun(run.ID) if rc.Store == nil { - return + return true } sr := runToStoreRun(run) - if err := rc.Store.UpdateRun(context.Background(), sr); err != nil { + ctx, cancel := context.WithTimeout(context.Background(), r.terminalStoreTimeoutDuration()) + defer cancel() + if err := rc.Store.UpdateRun(ctx, sr); err != nil { if rc.Logger != nil { rc.Logger.Error("store: UpdateRun failed", "run_id", run.ID, "error", err) } + return false + } + return true +} + +func (r *Runner) terminalStoreTimeoutDuration() time.Duration { + if r.terminalStoreTimeout > 0 { + return r.terminalStoreTimeout } + return terminalEventStoreTimeout } func shouldPersistWorkflowRecap(status RunStatus) bool { @@ -5798,7 +5889,7 @@ func (r *Runner) storeAppendEvent(ev Event, seq uint64) bool { Payload: string(payloadJSON), Timestamp: ev.Timestamp, } - ctx, cancel := context.WithTimeout(context.Background(), terminalEventStoreTimeout) + ctx, cancel := context.WithTimeout(context.Background(), r.terminalStoreTimeoutDuration()) defer cancel() if err := rc.Store.AppendEvent(ctx, se); err != nil { if rc.Logger != nil { diff --git a/internal/harness/runner_event_journal.go b/internal/harness/runner_event_journal.go index 7cdea320..74763529 100644 --- a/internal/harness/runner_event_journal.go +++ b/internal/harness/runner_event_journal.go @@ -179,10 +179,15 @@ func (j *eventJournal) prepareLocked(state *runState, runID string, eventType Ev return delivery, true } -func (j *eventJournal) persistTerminal(delivery eventDispatch) { - if j.runner.storeAppendEvent(delivery.event, delivery.eventSeq) { +func (j *eventJournal) persistTerminalEvent(delivery eventDispatch) bool { + persisted := j.runner.storeAppendEvent(delivery.event, delivery.eventSeq) + if persisted { j.runner.markTerminalEventPersisted(delivery.runID) } + return persisted +} + +func (j *eventJournal) recordTerminalConversation(delivery eventDispatch) { j.runner.recordConversationEvent(delivery.conversationID, delivery.event) } @@ -193,7 +198,8 @@ func (j *eventJournal) fanoutTerminal(delivery eventDispatch) { } func (j *eventJournal) publishTerminal(delivery eventDispatch) { - j.persistTerminal(delivery) + j.persistTerminalEvent(delivery) + j.recordTerminalConversation(delivery) j.fanoutTerminal(delivery) } @@ -201,6 +207,7 @@ func (j *eventJournal) dispatch(delivery eventDispatch) { if delivery.dropped { if delivery.closeRecorder != nil { delivery.closeRecorder() + j.waitForRecorderDrain(delivery, j.runner.configForRun(delivery.runID)) } return } @@ -241,16 +248,7 @@ func (j *eventJournal) dispatch(delivery eventDispatch) { } } delivery.closeRecorder() - drainTimer := time.NewTimer(recorderDrainTimeout) - defer drainTimer.Stop() - select { - case <-delivery.recorderDone: - case <-drainTimer.C: - if rc.Logger != nil { - rc.Logger.Error("rollout recorder: drain timeout exceeded, JSONL may be incomplete", - "run_id", delivery.runID, "timeout", recorderDrainTimeout) - } - } + j.waitForRecorderDrain(delivery, rc) } return } @@ -258,3 +256,19 @@ func (j *eventJournal) dispatch(delivery eventDispatch) { // Non-terminal recorder events are queued in prepareLocked while the runner // lock is held so terminal close cannot overtake them. } + +func (j *eventJournal) waitForRecorderDrain(delivery eventDispatch, rc RunnerConfig) { + if delivery.recorderDone == nil { + return + } + drainTimer := time.NewTimer(recorderDrainTimeout) + defer drainTimer.Stop() + select { + case <-delivery.recorderDone: + case <-drainTimer.C: + if rc.Logger != nil { + rc.Logger.Error("rollout recorder: drain timeout exceeded, JSONL may be incomplete", + "run_id", delivery.runID, "timeout", recorderDrainTimeout) + } + } +} diff --git a/internal/harness/runner_terminal_atomicity_test.go b/internal/harness/runner_terminal_atomicity_test.go index efdd6856..4071359b 100644 --- a/internal/harness/runner_terminal_atomicity_test.go +++ b/internal/harness/runner_terminal_atomicity_test.go @@ -256,15 +256,15 @@ func TestTerminalConversationFanoutCannotBeOvertaken(t *testing.T) { t.Fatal("terminal transition did not reach pre-dispatch barrier") } - // The replay-to-live mutex must remain held from terminal persistence - // through terminal fanout. Before the fix this lock was available here, - // allowing a later same-conversation event to overtake the terminal event. - if runner.conversationEventMu.TryLock() { - runner.conversationEventMu.Unlock() + // Slow terminal persistence/recorder/status work must not monopolize the + // global replay-to-live mutex. Same-conversation ordering is now carried by + // the narrower keyed sequence lock for the complete terminal transition. + if !runner.conversationEventMu.TryLock() { close(releaseDispatch) <-terminalDone - t.Fatal("conversation event lock released before terminal fanout") + t.Fatal("global conversation event lock held during terminal I/O") } + runner.conversationEventMu.Unlock() laterStarted := make(chan struct{}) laterDone := make(chan struct{}) @@ -274,6 +274,13 @@ func TestTerminalConversationFanoutCannotBeOvertaken(t *testing.T) { close(laterDone) }() <-laterStarted + select { + case <-laterDone: + close(releaseDispatch) + <-terminalDone + t.Fatal("later same-conversation event overtook terminal fanout") + default: + } close(releaseDispatch) if won := <-terminalDone; !won { t.Fatal("terminal transition did not win") diff --git a/internal/harness/runner_terminal_failure_policy_test.go b/internal/harness/runner_terminal_failure_policy_test.go new file mode 100644 index 00000000..537047c0 --- /dev/null +++ b/internal/harness/runner_terminal_failure_policy_test.go @@ -0,0 +1,487 @@ +package harness + +import ( + "context" + "errors" + "fmt" + "sync" + "testing" + "time" + + "go-agent-harness/internal/forensics/redaction" + "go-agent-harness/internal/rollout" + runstore "go-agent-harness/internal/store" +) + +func TestTerminalAppendDoesNotBlockUnrelatedConversationOrAllowSameConversationOvertake(t *testing.T) { + store := &blockingTerminalAppendStore{ + Store: runstore.NewMemoryStore(), + started: make(chan struct{}), + release: make(chan struct{}), + } + var releaseOnce sync.Once + releaseStore := func() { releaseOnce.Do(func() { close(store.release) }) } + t.Cleanup(releaseStore) + + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{Store: store}) + const ( + terminalRunID = "blocked-terminal-append" + sameRunID = "same-conversation-later" + otherRunID = "unrelated-conversation" + terminalConv = "terminal-conversation" + ) + for runID, convID := range map[string]string{ + terminalRunID: terminalConv, + sameRunID: terminalConv, + otherRunID: "other-conversation", + } { + run := Run{ID: runID, ConversationID: convID, Status: RunStatusRunning} + runner.runs[runID] = &runState{run: run, subscribers: make(map[chan Event]struct{})} + runner.storeCreateRun(run) + } + + history, stream, unsubscribe, err := runner.SubscribeConversation(terminalConv) + if err != nil { + t.Fatalf("SubscribeConversation: %v", err) + } + defer unsubscribe() + if len(history) != 0 { + t.Fatalf("initial history=%v, want empty", terminalAtomicityEventTypes(history)) + } + + store.setBlockRunID(terminalRunID) + terminalDone := make(chan bool, 1) + go func() { + terminalDone <- runner.transitionTerminal( + terminalRunID, RunStatusCompleted, "done", "", + EventRunCompleted, map[string]any{"output": "done"}, + ) + }() + select { + case <-store.started: + case <-time.After(2 * time.Second): + t.Fatal("terminal AppendEvent did not block") + } + + otherDone := make(chan struct{}) + go func() { + runner.emit(otherRunID, EventAssistantMessage, map[string]any{"content": "other"}) + close(otherDone) + }() + select { + case <-otherDone: + case <-time.After(200 * time.Millisecond): + t.Fatal("unrelated conversation emit blocked behind terminal AppendEvent") + } + + sameStarted := make(chan struct{}) + sameDone := make(chan struct{}) + go func() { + close(sameStarted) + runner.emit(sameRunID, EventAssistantMessage, map[string]any{"content": "later"}) + close(sameDone) + }() + <-sameStarted + select { + case <-sameDone: + t.Fatal("same-conversation event overtook blocked terminal AppendEvent") + default: + } + + releaseStore() + if won := <-terminalDone; !won { + t.Fatal("terminal transition did not commit") + } + select { + case <-sameDone: + case <-time.After(2 * time.Second): + t.Fatal("same-conversation event stayed blocked after terminal publication") + } + + got := make([]Event, 0, 2) + for len(got) < 2 { + select { + case event := <-stream: + got = append(got, event) + case <-time.After(2 * time.Second): + t.Fatalf("conversation stream=%v, want terminal then later", terminalAtomicityEventTypes(got)) + } + } + if got[0].Type != EventRunCompleted || got[1].Type != EventAssistantMessage { + t.Fatalf("conversation order=%v, want run.completed then assistant.message", + terminalAtomicityEventTypes(got)) + } +} + +func TestTerminalAppendFailureNeverPersistsTerminalStatusButStillPublishesInMemory(t *testing.T) { + store := &terminalFailureStore{ + Store: runstore.NewMemoryStore(), + failAppendEvent: true, + } + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{Store: store}) + run := Run{ID: "append-failure", ConversationID: "append-failure-conv", Status: RunStatusRunning} + runner.runs[run.ID] = &runState{run: run, subscribers: make(map[chan Event]struct{})} + runner.storeCreateRun(run) + history, stream, unsubscribe, err := runner.Subscribe(run.ID) + if err != nil { + t.Fatalf("Subscribe: %v", err) + } + defer unsubscribe() + if len(history) != 0 { + t.Fatalf("initial history=%v, want empty", terminalAtomicityEventTypes(history)) + } + if won := runner.transitionTerminal( + run.ID, RunStatusCompleted, "done", "", + EventRunCompleted, map[string]any{"output": "done"}, + ); !won { + t.Fatal("terminal transition did not commit after append failure") + } + requireTerminalSubscriberEvent(t, stream, EventRunCompleted) + current, _ := runner.GetRun(run.ID) + if current.Status != RunStatusCompleted { + t.Fatalf("in-memory status=%s, want completed after append failure", current.Status) + } + + stored, err := store.Store.GetRun(context.Background(), run.ID) + if err != nil { + t.Fatalf("store.GetRun: %v", err) + } + if stored.Status == runstore.RunStatusCompleted { + t.Fatal("durable terminal status was written after terminal AppendEvent failed") + } + replayHistory, _, replayUnsubscribe, err := runner.Subscribe(run.ID) + if err != nil { + t.Fatalf("Subscribe: %v", err) + } + replayUnsubscribe() + if !containsEventType(replayHistory, EventRunCompleted) { + t.Fatal("in-memory replay did not publish run.completed after bounded append failure") + } +} + +func TestTerminalStatusUpdateFailureLeavesDurableRunNonTerminalAndPublishesInMemory(t *testing.T) { + store := &terminalFailureStore{ + Store: runstore.NewMemoryStore(), + failUpdateRun: true, + } + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{Store: store}) + run := Run{ID: "status-failure", ConversationID: "status-failure-conv", Status: RunStatusRunning} + runner.runs[run.ID] = &runState{run: run, subscribers: make(map[chan Event]struct{})} + runner.storeCreateRun(run) + _, stream, unsubscribe, err := runner.Subscribe(run.ID) + if err != nil { + t.Fatalf("Subscribe: %v", err) + } + defer unsubscribe() + if won := runner.transitionTerminal( + run.ID, RunStatusCompleted, "done", "", + EventRunCompleted, map[string]any{"output": "done"}, + ); !won { + t.Fatal("terminal transition did not commit after status update failure") + } + requireTerminalSubscriberEvent(t, stream, EventRunCompleted) + current, _ := runner.GetRun(run.ID) + if current.Status != RunStatusCompleted { + t.Fatalf("in-memory status=%s, want completed after status update failure", current.Status) + } + + stored, err := store.Store.GetRun(context.Background(), run.ID) + if err != nil { + t.Fatalf("store.GetRun: %v", err) + } + if stored.Status == runstore.RunStatusCompleted { + t.Fatal("durable run unexpectedly became terminal after UpdateRun failure") + } + events, err := store.Store.GetEvents(context.Background(), run.ID, -1) + if err != nil { + t.Fatalf("store.GetEvents: %v", err) + } + foundTerminal := false + for _, event := range events { + if event.EventType == string(EventRunCompleted) { + foundTerminal = true + } + } + if !foundTerminal { + t.Fatal("durable terminal event missing when only UpdateRun failed") + } +} + +func TestDelayedNonTerminalStatusCannotOverwriteTerminalTransition(t *testing.T) { + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{}) + const runID = "status-vs-terminal" + runner.runs[runID] = &runState{ + run: Run{ID: runID, ConversationID: "status-vs-terminal-conv", Status: RunStatusRunning}, + subscribers: make(map[chan Event]struct{}), + } + + waitingPrepared := make(chan struct{}) + releaseWaiting := make(chan struct{}) + runner.statusBeforeCommitHook = func(gotRunID string, status RunStatus) { + if gotRunID == runID && status == RunStatusWaitingForUser { + close(waitingPrepared) + <-releaseWaiting + } + } + waitingDone := make(chan struct{}) + go func() { + runner.setStatus(runID, RunStatusWaitingForUser, "", "") + close(waitingDone) + }() + <-waitingPrepared + + terminalAttempted := make(chan struct{}) + runner.terminalTransitionHook = func(gotRunID string, status RunStatus, _ EventType) { + if gotRunID == runID && status == RunStatusCompleted { + close(terminalAttempted) + } + } + terminalDone := make(chan bool, 1) + go func() { + terminalDone <- runner.transitionTerminal( + runID, RunStatusCompleted, "done", "", EventRunCompleted, map[string]any{"output": "done"}, + ) + }() + <-terminalAttempted + close(releaseWaiting) + <-waitingDone + if won := <-terminalDone; !won { + t.Fatal("terminal transition did not commit") + } + + current, ok := runner.GetRun(runID) + if !ok { + t.Fatal("run disappeared") + } + if current.Status != RunStatusCompleted { + t.Fatalf("delayed non-terminal status overwrote terminal status: got %s", current.Status) + } +} + +func TestTerminalStatusUpdateTimeoutStillPublishesAndDoesNotBlockUnrelatedConversation(t *testing.T) { + store := &contextBlockingTerminalStatusStore{ + Store: runstore.NewMemoryStore(), + started: make(chan struct{}), + forceRelease: make(chan struct{}), + } + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{Store: store}) + runner.terminalStoreTimeout = 25 * time.Millisecond + const ( + terminalRunID = "terminal-status-timeout" + otherRunID = "terminal-status-timeout-other" + ) + for runID, convID := range map[string]string{ + terminalRunID: "terminal-status-timeout-conv", + otherRunID: "terminal-status-timeout-other-conv", + } { + run := Run{ID: runID, ConversationID: convID, Status: RunStatusRunning} + runner.runs[runID] = &runState{run: run, subscribers: make(map[chan Event]struct{})} + runner.storeCreateRun(run) + } + store.blockRunID = terminalRunID + _, terminalStream, unsubscribe, err := runner.Subscribe(terminalRunID) + if err != nil { + t.Fatalf("Subscribe: %v", err) + } + defer unsubscribe() + + terminalDone := make(chan bool, 1) + go func() { + terminalDone <- runner.transitionTerminal( + terminalRunID, RunStatusCompleted, "done", "", + EventRunCompleted, map[string]any{"output": "done"}, + ) + }() + select { + case <-store.started: + case <-time.After(2 * time.Second): + t.Fatal("terminal UpdateRun did not block") + } + + otherDone := make(chan struct{}) + go func() { + runner.emit(otherRunID, EventAssistantMessage, map[string]any{"content": "other"}) + close(otherDone) + }() + select { + case <-otherDone: + case <-time.After(200 * time.Millisecond): + t.Fatal("unrelated conversation blocked behind terminal UpdateRun") + } + + select { + case won := <-terminalDone: + if !won { + t.Fatal("terminal transition did not publish after UpdateRun timeout") + } + case <-time.After(200 * time.Millisecond): + close(store.forceRelease) + t.Fatal("terminal transition did not recover from bounded UpdateRun timeout") + } + current, _ := runner.GetRun(terminalRunID) + if current.Status != RunStatusCompleted { + t.Fatalf("in-memory status=%s, want completed after UpdateRun timeout", current.Status) + } + requireTerminalSubscriberEvent(t, terminalStream, EventRunCompleted) +} + +func TestRedactedTerminalWaitsForRecorderDrainBeforeStatus(t *testing.T) { + pipeline := redaction.NewPipeline( + redaction.NewRedactor(nil), + redaction.EventClassConfig{string(EventRunCompleted): redaction.StorageModeNone}, + ) + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{RedactionPipeline: pipeline}) + const runID = "redacted-recorder-drain" + recorderDone := make(chan struct{}) + recorderClosed := make(chan struct{}) + var closeOnce sync.Once + runner.runs[runID] = &runState{ + run: Run{ID: runID, ConversationID: "redacted-recorder-drain-conv", Status: RunStatusRunning}, + subscribers: make(map[chan Event]struct{}), + recorderCh: make(chan rollout.RecordableEvent, 1), + recorderDone: recorderDone, + closeRecorderOnce: func() { + closeOnce.Do(func() { + close(recorderClosed) + }) + }, + } + + terminalDone := make(chan bool, 1) + go func() { + terminalDone <- runner.transitionTerminal( + runID, RunStatusCompleted, "done", "", EventRunCompleted, map[string]any{"output": "done"}, + ) + }() + select { + case <-recorderClosed: + case <-time.After(2 * time.Second): + t.Fatal("redacted terminal did not close recorder") + } + current, _ := runner.GetRun(runID) + if current.Status == RunStatusCompleted { + close(recorderDone) + <-terminalDone + t.Fatal("redacted terminal status became visible before recorder drain") + } + close(recorderDone) + if won := <-terminalDone; !won { + t.Fatal("redacted terminal transition did not commit") + } +} + +func TestConversationSequenceLockReclaimedAfterContention(t *testing.T) { + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{}) + unlockFirst := runner.lockConversationSequence("reclaim") + waiterDone := make(chan struct{}) + go func() { + unlockWaiter := runner.lockConversationSequence("reclaim") + unlockWaiter() + close(waiterDone) + }() + waitForConversationSequenceRefs(t, runner, "reclaim", 2) + unlockFirst() + select { + case <-waiterDone: + case <-time.After(2 * time.Second): + t.Fatal("conversation sequence waiter did not finish") + } + + runner.conversationSequenceMu.Lock() + remaining := len(runner.conversationSequence) + runner.conversationSequenceMu.Unlock() + if remaining != 0 { + t.Fatalf("conversation sequence entries=%d, want 0 after owners and waiters release", remaining) + } + + for i := 0; i < 100; i++ { + unlock := runner.lockConversationSequence(fmt.Sprintf("distinct-%d", i)) + unlock() + } + runner.conversationSequenceMu.Lock() + remaining = len(runner.conversationSequence) + runner.conversationSequenceMu.Unlock() + if remaining != 0 { + t.Fatalf("conversation sequence entries=%d, want 0 after distinct-key releases", remaining) + } +} + +func waitForConversationSequenceRefs(t *testing.T, runner *Runner, key string, want int) { + t.Helper() + deadline := time.Now().Add(2 * time.Second) + for { + runner.conversationSequenceMu.Lock() + entry := runner.conversationSequence[key] + got := 0 + if entry != nil { + got = entry.refs + } + runner.conversationSequenceMu.Unlock() + if got == want { + return + } + if time.Now().After(deadline) { + t.Fatalf("conversation sequence refs=%d, want %d", got, want) + } + time.Sleep(time.Millisecond) + } +} + +func requireTerminalSubscriberEvent(t *testing.T, stream <-chan Event, want EventType) { + t.Helper() + select { + case event := <-stream: + if event.Type != want { + t.Fatalf("subscriber event=%s, want %s", event.Type, want) + } + case <-time.After(2 * time.Second): + t.Fatalf("timed out waiting for subscriber event %s", want) + } +} + +type terminalFailureStore struct { + runstore.Store + failAppendEvent bool + failUpdateRun bool +} + +func (s *terminalFailureStore) AppendEvent(ctx context.Context, event *runstore.Event) error { + if s.failAppendEvent && IsTerminalEvent(EventType(event.EventType)) { + return errors.New("terminal append failed") + } + return s.Store.AppendEvent(ctx, event) +} + +func (s *terminalFailureStore) UpdateRun(ctx context.Context, run *runstore.Run) error { + if s.failUpdateRun && isTerminalStoreStatus(run.Status) { + return errors.New("terminal status update failed") + } + return s.Store.UpdateRun(ctx, run) +} + +type contextBlockingTerminalStatusStore struct { + runstore.Store + blockRunID string + started chan struct{} + startedOnce sync.Once + forceRelease chan struct{} +} + +func (s *contextBlockingTerminalStatusStore) UpdateRun(ctx context.Context, run *runstore.Run) error { + if run.ID == s.blockRunID && isTerminalStoreStatus(run.Status) { + s.startedOnce.Do(func() { close(s.started) }) + select { + case <-ctx.Done(): + return ctx.Err() + case <-s.forceRelease: + return errors.New("forced release") + } + } + return s.Store.UpdateRun(ctx, run) +} + +func isTerminalStoreStatus(status runstore.RunStatus) bool { + return status == runstore.RunStatusCompleted || + status == runstore.RunStatusFailed || + status == runstore.RunStatus("cancelled") +} From f62ca93db68630be5f7a4f827d9d87c5c5669fbd Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 20:06:50 +0200 Subject: [PATCH 4/8] fix: retain terminal truth until fully durable --- docs/logs/engineering-log.md | 37 +- docs/logs/long-term-thinking-log.md | 17 +- docs/logs/observational-log.md | 18 + docs/logs/system-log.md | 16 + ...minal-status-event-atomicity-impact-map.md | 69 ++- ...67-terminal-status-event-atomicity-plan.md | 63 ++- docs/plans/INDEX.md | 4 +- docs/plans/active-plan.md | 14 +- internal/harness/runner.go | 232 +++++++++- internal/harness/runner_prune_test.go | 429 +++++++++++++++++- internal/harness/types.go | 4 +- internal/server/http_runs.go | 10 + .../server/http_terminal_atomicity_test.go | 62 +++ 13 files changed, 907 insertions(+), 68 deletions(-) diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 1261a02b..3ba17515 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -33,6 +33,7 @@ `-count=5`; harness vet passed; and unchanged foreground non-TTY `./scripts/test-regression.sh` passed at 85.6% total coverage with zero uncovered functions. + ## 2026-07-31 (Terminal Status/Event Atomicity — Issue #1067) - Symptom: aggregate race load exposed `RunStatusFailed` from `GetRun` while @@ -74,15 +75,37 @@ overtake; delayed non-terminal status cannot overwrite terminal; explicit terminal redaction waits for recorder drain; and contended/distinct keyed locks reclaim to zero. +- Exact-head retention cause: the terminal event success marker made a run + eligible for pruning even when the matching final `UpdateRun` failed, because + that return value was discarded. The truthful in-memory terminal state could + be evicted while the durable row remained running. Both append- and + status-failure exceptions could also accumulate without an admission bound. +- Retention/admission fix: terminal event resolution and terminal status + persistence are tracked separately. Store-backed pruning requires both; + `StorageModeNone` is explicit event suppression plus durable status, while + no-store runs remain process-local. Both unresolved append and status states + count toward `MaxCompletedRetention`. At the cap, Start/Continue retry only + status gaps under one shared deadline of at most 250 ms and otherwise return + `TerminalDurabilityBackpressureError`; their HTTP routes map it to 503 + `terminal_durability_unavailable`. +- Recovery and boundedness: no recovery store I/O holds Runner, status, + event-journal, or conversation locks. Status overwrite retries are safe and + immediately restore the completed-retention bound before reopening admission + once acknowledged. Ambiguous failed appends are protected but never retried + because a third-party store may have applied the append. + Already-admitted work finishes and remains visible; admission closes at the + cap so permanent failure growth stops at that finite admitted population. +- Exact-head regressions: retention 1 preserves several already-admitted + UpdateRun-failed completions while durable rows stay non-terminal; concurrent + admissions reject during outage and recover under race; one blocked retry + proves the shared deadline and unlocked state/journal access; append failure, + StorageModeNone, no-store, Continue error precedence, and both HTTP 503 routes + are pinned. - Verification: the expanded terminal suite and HTTP replay passed normal/race at `-count=100`; complete `internal/harness` + `internal/server` normal/race - and affected `go vet` passed. The first final full-regression invocation - passed normal and race, then returned red during its coverage stage with the - failure diagnostic lost in the command's oversized coverage output. The - unchanged full coverage command passed immediately afterward and - `coveragegate` reported 85.6% total with zero uncovered functions. A fresh - uninterrupted `./scripts/test-regression.sh` then passed normal, race, and - coverage at the same 85.6%/zero-function threshold. + and affected `go vet` passed. The final uninterrupted foreground non-TTY + `./scripts/test-regression.sh` passed normal, race, and + `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/long-term-thinking-log.md b/docs/logs/long-term-thinking-log.md index b442653f..6cd618dd 100644 --- a/docs/logs/long-term-thinking-log.md +++ b/docs/logs/long-term-thinking-log.md @@ -28,6 +28,7 @@ normal/race x100, complete harness race x5, harness vet, and the unchanged repository regression gate pass. The local commit is ready for parent promotion; PR #1069 remains open and unmerged pending hosted reruns. + ## 2026-07-31 (Terminal Status/Event Atomicity — Issue #1067) - Command intent: repair the aggregate-load Runner race where `GetRun` exposes @@ -46,16 +47,24 @@ - Guardrails: preserve out-of-lock bounded store writes, terminal sealing, recorder drain order, cleanup order, causal/error snapshots, SSE IDs, and unrelated conversation responsiveness. Do not claim a cross-record store - transaction the interface cannot provide. + transaction the interface cannot provide. Never evict truthful terminal state + without both event and status durability, and never trade that protection for + unbounded memory growth during permanent store failure. - Outcome: one winner-only transition now publishes terminal ledger history before matching in-memory status and subscriber fanout. Retained terminal status persistence is attempted only after event append reports success; append/status failures have explicit bounded live-availability behavior. Shared per-run status serialization prevents a delayed non-terminal overwrite, and refcounted per-conversation sequencing avoids both overtaking and lock-map - growth. Focused normal/race stress, affected normal/race/vet, and HTTP replay - plus the unchanged full repository regression are green on the final review - diff; hosted gates remain pending parent promotion. + growth. Exact-head retention hardening now tracks event and status durability + separately, requires both before pruning, and closes new admission when the + combined unresolved backlog reaches `MaxCompletedRetention`. Status recovery + uses one unlocked deadline capped at 250 ms; Start/Continue expose typed HTTP + 503 while no-store and intentional StorageModeNone policies remain distinct. + Successful status recovery immediately restores the retention bound before + reopening admission. The added focused normal/race and real HTTP mapping + tests, affected normal/race/vet, and the unchanged foreground repository gate + are green at 85.7% coverage with zero uncovered production functions. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index 6990d172..851bc075 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -22,6 +22,7 @@ Use this file for observations about system behavior without immediately prescri - Cleanup observation: a failure-safe bounded fixture must unblock provider calls before invoking `Shutdown`; otherwise cleanup can wait on the very run the fixture still holds blocked. + ## 2026-07-31 (Terminal Run Publication Window) - Concurrency observation: a terminal event can be prepared under the Runner @@ -49,6 +50,23 @@ Use this file for observations about system behavior without immediately prescri accounting. Deleting only after owners and queued waiters release prevents a second lock generation for the same key and avoids an unbounded conversation map. +- Retention observation: event append success alone is insufficient proof that + a terminal state can fall back to the store. Pruning also needs acknowledged + terminal status persistence; otherwise fallback resurrects a non-terminal + durable row after evicting the only truthful process-local result. +- Outage observation: protecting unpersisted truth and bounding memory require + one admission boundary. Both ambiguous event appends and failed status + updates consume it; already-admitted runs may finish above the numeric cap, + but later admissions stop growth once the outage is observed. +- Recovery observation: `UpdateRun` is an idempotent overwrite and can be + retried under one shared short context. `AppendEvent` is not safe to retry + after an ambiguous third-party error because the append may already exist. + Once status retries succeed, pruning newly durable candidates immediately + restores the retention bound before another admission is accepted. +- Policy observation: no-store and `StorageModeNone` are distinct. No-store has + no durable fallback and stays process-local; StorageModeNone intentionally + resolves the event side while its final status can still make safe pruning + possible. ## 2026-07-31 (Source-Workflow Dual-Error Arbitration) diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index 020fc6d0..7961b9c0 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -17,6 +17,7 @@ - Compatibility/failure modes: no API, config, persistence, client, provider, or tool contract changes; existing queue-drain, timeout, and idempotency behavior remains the rollback boundary. + ## 2026-07-31 (Terminal Run Transition Publication — Issue #1067) - System/component: `Runner.transitionTerminal`, `Runner.emit`, and @@ -47,6 +48,21 @@ delayed non-terminal writes cannot overwrite terminal state. The per-conversation sequence lock counts queued waiters and deletes idle keys; external terminal I/O never holds the global conversation journal mutex. +- Retention/admission boundary: store-backed terminal pruning requires event + persistence (or intentional StorageModeNone suppression) plus acknowledged + final status persistence. Both unresolved event and status records consume + the `MaxCompletedRetention` durability backlog. Once full, StartRun and + ContinueRun retry status-only gaps under one shared deadline capped at 250 ms + with no store I/O under Runner/status/journal/conversation locks, then return + typed fail-closed backpressure if unresolved. +- API/recovery boundary: the two run-admission HTTP routes map typed durability + backpressure to 503 `terminal_durability_unavailable`; Continue validates + missing/non-completed sources first and revalidates before its single-winner + mutation. Successful status retry immediately prunes newly durable candidates + back to the configured retention limit before reopening admission. Ambiguous + append errors remain blocked until process/operator recovery rather than + risking a duplicate forensic event. No-store runs intentionally remain + process-local and ungated. ## 2026-07-31 (Source-Workflow Terminal Error Arbitration) diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md index a1ffb4b0..dfac440c 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md @@ -5,15 +5,17 @@ - Task / issue: #1067, terminal status visible before matching replay event. - Plan: `2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md`. - Owner: Codex. -- Status: review hardening implemented and fully verified locally; hosted - checks pending. +- Status: exact-head durability-retention hardening implemented and verified + locally through focused stress, affected normal/race/vet, and the unchanged + full repository regression gate; hosted checks remain pending promotion. ## Current Ownership, Callers, and Data Flow - Entry points: `completeRun`, `failRun`, `failRunMaxSteps`, `failRunMaxTurns`, and `cancelledRun`. - Source of truth: `Runner` owns `runState.run.Status`, `runState.events`, - `runState.terminated`, recorder channels, and run subscribers; + `runState.terminated`, terminal event/status durability markers, recorder + channels, and run subscribers; `eventJournal` owns append/store/fanout ordering. - Callers/consumers: step-engine completion/provider/tool/budget/cancellation paths; `GetRun`; `Subscribe`; run HTTP/SSE routes; CLI, TUI, and macOS @@ -26,12 +28,17 @@ ## Config, API, CLI, and Tools -- Config/env/defaults: none. +- Config/env/defaults: `MaxCompletedRetention` retains its value/default and now + also bounds the unresolved store-backed terminal durability backlog. - Endpoints/request/response/wire formats: unchanged `Run`, `Event`, event IDs, - SSE names, payload schema, and HTTP routes. + SSE names, payload schema, and HTTP routes. When the durability backlog is at + its cap after bounded recovery, `POST /v1/runs` and + `POST /v1/runs/{id}/continue` return HTTP 503 with + `terminal_durability_unavailable`. - CLI/tools/integrations: no command changes; terminal polling and stream consumers gain a stronger ordering guarantee. -- Error states: unchanged completed/failed/cancelled values and payloads. +- Error states: completed/failed/cancelled values and payloads are unchanged; + `TerminalDurabilityBackpressureError` is the typed degraded-admission error. ## Persistence and Compatibility @@ -49,8 +56,12 @@ and drained before terminal transition returns. An explicitly suppressed `StorageModeNone` terminal also closes and drains the recorder before status visibility even though no terminal event is appended. -- Compatibility: additive ordering guarantee only; event/status values and - replay IDs remain stable. +- Retention: a store-backed terminal state is prunable only after event + persistence (or explicit `StorageModeNone` suppression) and final status + persistence are both acknowledged. No-store states remain process-local and + outside durable pruning/backpressure. +- Compatibility: event/status values and replay IDs remain stable. The new 503 + is an intentional fail-closed availability change during persistence outage. - Mixed-version behavior: process-local; older daemons retain the race until upgraded, with no data migration. @@ -62,6 +73,9 @@ so a delayed running/waiting write cannot overwrite terminal state. - Cancellation/retries/cleanup: cooperative cancellation and idempotency stay unchanged; workspace/tool/MCP cleanup remains before terminal publication. + Status-only durability gaps retry safely as idempotent `UpdateRun` overwrites + under one total deadline of at most 250 ms. Ambiguous failed event appends are + counted but not retried because a third-party store may have applied them. - Locks/resources: terminal store/recorder waits remain outside `Runner.mu` and the global conversation journal lock. A refcounted target-conversation lock prevents same-conversation overtaking while unrelated journals progress, and @@ -72,29 +86,44 @@ documented exception: it seals and publishes status without replaying the intentionally suppressed event. - Failure/recovery: append and status writes use bounded contexts and failures - remain non-fatal to the live Runner. In-memory replay/status/fanout remain - authoritative for that process; persisted-before-prune guards stay intact. - No two-way durable atomicity is claimed without a transactional store API. + remain non-fatal to already-admitted work. Both failure classes count toward + the same finite admission gate. At the configured cap, Start/Continue retries + recoverable status gaps without holding Runner/status/conversation locks, + then rejects admission if the backlog remains full. Already-admitted work may + temporarily exceed the numeric cap but the excess is bounded by the finite + active/queued population admitted before outage detection. No two-way durable + atomicity is claimed without a transactional store API. A successful status + retry prunes newly durable candidates immediately, restoring the configured + completed-retention bound before admission reopens. ## Product and Integration Surfaces - Server/runtime: `GetRun` terminal now implies immediate `Subscribe` replay - contains the matching event. + contains the matching event. Start/Continue expose the explicit degraded 503; + Continue preserves not-found/non-completed source error precedence. - TUI/web/macOS/other clients: terminal badges, failure text, exit codes, and transcript state no longer disagree during the publication window; no client code changes. - Provider/model/tool catalogs/routing: none; provider failure is only a caller. -- External systems/automation: cron/callback/workflow semantics unchanged. +- External systems/automation: internal StartRun callers inherit the typed + fail-closed error through their existing error paths; cron/callback/workflow + request schemas and successful semantics are unchanged. - UX/accessibility/focus/motion: no visual or interaction change. ## Deployment and Operations - Deployment/migrations/flags: ordinary daemon rollout; no migration or flag. - Observability: deterministic regression records transition phases without - logging prompts, event payload secrets, or credentials. -- Rollback: revert if terminal fanout deadlocks, unrelated `GetRun` blocks, - cleanup order changes, recorder output truncates, or cancellation regresses. -- Runbooks/operator docs: no public/operator command changes. + logging prompts, event payload secrets, or credentials. Operators can + correlate store append/update errors with 503 + `terminal_durability_unavailable`; successful status retry reopens admission. +- Rollback: revert if healthy stores spuriously return 503, the total retry + exceeds 250 ms, source error precedence changes, terminal fanout deadlocks, + or unrelated Runner/conversation work blocks. During a real store outage, + stop new producers and preserve the process before rollback because removing + the gate reintroduces truthful-state eviction or unbounded protected memory. +- Runbooks/operator docs: no command changes; the issue and implementation logs + carry the degraded-mode recovery policy. ## Regression Tests @@ -108,6 +137,12 @@ overtaking; append error prevents terminal status persistence; status update error/timeout preserves live publication; retained and suppressed terminal recorder paths drain before status visibility. +- Retention/admission: several already-admitted completions remain visible at + retention 1 when final status updates fail and their durable rows remain + non-terminal; append- and status-pending runs both close admission at the cap; + concurrent callers reject during outage and recover after status persistence; + the retry uses one unlocked deadline; StorageModeNone and no-store policies + remain explicit. - Integration: HTTP poll immediately followed by run SSE replay for all three statuses. - Exact gates: focused normal/race stress `-count=100`; harness/server diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md index 9483f304..113d6b8e 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md @@ -15,22 +15,31 @@ cleanup ordering, and the explicit `StorageModeNone` terminal-redaction policy. The store API has no cross-record transaction, so promise the testable one-way invariant rather than two-way event/status atomicity. +- Exact-head review finding: terminal event success was tracked for pruning but + terminal status update success was discarded. A failed `UpdateRun` could + therefore make pruning evict truthful live state while the durable row stayed + non-terminal; permanent append/update failures could also grow protected + memory without an admission bound. ## Scope - In scope: one shared Runner terminal-transition seam for completed, failed, cancelled, max-step failed, and max-turn failed paths; deterministic - concurrency and replay regressions; real HTTP poll-then-replay proof. + concurrency and replay regressions; event/status-aware safe pruning; bounded + degraded admission and recovery; explicit Start/Continue HTTP 503 mapping; + real HTTP poll-then-replay proof. - Out of scope: PR #1060/#1055 changes, cron/callback behavior, conversation cursor redesign, GUI visual changes, provider routing, schemas, and workflow timing issue #1049. ## Documentation Contract -- Feature status: review hardening implemented and fully verified locally; - hosted checks pending. -- Public docs affected: none; existing terminal event/status wire formats stay - unchanged. +- Feature status: exact-head durability-retention hardening implemented and + verified locally through focused stress, affected normal/race/vet, and the + unchanged full repository regression gate. +- Public API behavior: event/status wire formats stay unchanged. During a full + terminal durability backlog, Start/Continue now return documented HTTP 503 + `terminal_durability_unavailable` after bounded recovery fails. - Spec docs before code: this plan and its linked impact map. - Implementation notes after code: engineering, observational, system, and long-term logs plus the plans index and active plan. @@ -51,6 +60,15 @@ update error or context timeout after a successful append, keep the durable run non-terminal while the live Runner and subscribers complete. For an explicit `StorageModeNone` drop, drain the recorder before status visibility. +- Retention/admission controls: with retention 1, pre-admit several runs and + fail terminal `UpdateRun`; every truthful terminal state must remain in + memory while durable rows remain non-terminal. Count both append- and + status-pending states toward one gate; reject concurrent Start admissions and + Continue admission with a typed error/HTTP 503 at the cap; recover concurrent + callers after status persistence returns; preserve source error precedence, + intentional StorageModeNone suppression, and no-store behavior. Pin one + shared retry deadline of at most 250 ms with no store I/O under Runner, + status, event-journal, or conversation locks. - Concurrency control: race competing terminal transitions and require the winning status to match the single sealed terminal event; hold a terminal at the pre-fanout boundary and prove a later same-conversation event cannot @@ -78,6 +96,12 @@ - [x] Confirm the unchanged repository regression gate on the final diff. - [x] Prove the HTTP poll-then-replay path. - [x] Update all required logs and documentation status. +- [x] Track terminal status durability separately and require event plus status + resolution before store-backed pruning. +- [x] Add finite append/status backlog admission, bounded status recovery, typed + errors, and Start/Continue HTTP 503 mappings. +- [x] Prove concurrent outage/recovery, unlocked deadline, StorageModeNone, and + no-store behavior. - [ ] Open one closing PR, push its exact head, and request `@codex` review. - [ ] Confirm hosted checks are green; do not merge. @@ -109,6 +133,18 @@ of the global conversation mutex, preserve target-conversation sequencing, drain retained and suppressed terminal recorders, and reclaim idle keyed sequence locks. +- Risk: protecting event/status-pending terminal states from pruning could make + a permanent store outage consume memory without bound. +- Mitigation: both failure classes consume the `MaxCompletedRetention` backlog. + At the cap, new admissions retry status-only gaps under one shared deadline + and otherwise fail closed. Already-admitted work may finish and remain visible, + but growth stops at the finite population admitted before outage detection. + Ambiguous append failures are never replayed in-process. +- Risk: degraded admission could mask normal Continue errors or block unrelated + state while retrying. +- Mitigation: validate unknown/non-completed sources before the global gate, + revalidate for the single-winner mutation, map only the typed error to 503, + and prove the retry holds no Runner/status/conversation lock. - Risk: an explicit terminal `StorageModeNone` policy intentionally removes the matching event from replay. - Mitigation: preserve and test the existing redaction exception and scope the @@ -126,15 +162,20 @@ overwrote terminal status; context-blocking final status persistence stranded the transition; an explicit terminal redaction drop exposed status before recorder drain; and keyed sequence entries were never reclaimed. +- Exact-head P1 reds: at retention 1, append-pending admission remained open; + status-update-failed terminal runs were pruned despite non-terminal durable + rows; and both Start/Continue mapped the new typed degraded state to 400. +- Exact-head focused green: append/status pending runs remain visible, both + close admission at the cap, 16 concurrent callers reject then recover under + race, successful status recovery immediately restores the retention bound, + status recovery uses one unlocked total deadline, Start/Continue return the + explicit 503, and StorageModeNone/no-store controls pass. - Focused current green: all terminal publication/failure-policy regressions and HTTP replay passed normal and race at `-count=100`. - Affected current green: complete harness/server normal and race passed; affected `go vet` passed. - Real path: HTTP terminal polling followed immediately by Last-Event-ID run SSE replay passed for completed, failed, and cancelled. -- Repository: a fresh uninterrupted foreground non-TTY - `./scripts/test-regression.sh` passed normal, race, and coverage - (`total=85.6%`, `zero-functions=0`). Its immediately preceding invocation - passed normal/race but returned red in coverage without retaining the hidden - diagnostic; the unchanged coverage command and gate then passed before the - complete clean rerun. +- Repository: the final uninterrupted foreground non-TTY + `./scripts/test-regression.sh` passed normal, race, and coverage with + `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. diff --git a/docs/plans/INDEX.md b/docs/plans/INDEX.md index 8750582c..b9db2386 100644 --- a/docs/plans/INDEX.md +++ b/docs/plans/INDEX.md @@ -2,8 +2,8 @@ - `2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md` — Issue #1068 plan for deterministic instance-scoped Runner dispatcher shutdown verification. - `2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md` — Cross-surface impact map for Issue #1068 lifecycle isolation. -- `2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md` — Issue #1067 plan for linearizable terminal status, event, persistence, and replay publication. -- `2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md` — Cross-surface impact map for Issue #1067 Runner lifecycle ordering. +- `2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md` — Issue #1067 plan for linearizable terminal publication, safe durability-aware pruning, and bounded degraded admission. +- `2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md` — Cross-surface impact map for Issue #1067 Runner lifecycle, persistence, retention, and 503 recovery behavior. - `2026-07-31-issue-1062-provider-key-matrix-health-wait-plan.md` — Issue #1062 plan for a contention-tolerant provider API-key matrix startup wait. - `2026-07-31-issue-1062-provider-key-matrix-health-wait-impact-map.md` — Cross-surface impact map for Issue #1062. - `2026-07-31-issue-1064-workflow-exit-precedence-plan.md` — Issue #1064 deterministic source-workflow process-exit diagnostic precedence repair. diff --git a/docs/plans/active-plan.md b/docs/plans/active-plan.md index bee6df68..a45b1afb 100644 --- a/docs/plans/active-plan.md +++ b/docs/plans/active-plan.md @@ -4,12 +4,14 @@ Current status: Issue #1067 terminal publication atomicity is implemented on isolated branch `codex/issue-1067-terminal-status-event-atomicity`. Post-review hardening now defines and tests the one-way durable failure contract, bounded store waits, per-run status serialization, per-conversation lock reclamation, -and recorder drain for suppressed terminal events. Focused and affected-package -gates and the unchanged full repository regression are green on the branch -rebased to current `main`. Open PR #1070 still points at its older head and is -intentionally unpushed pending parent composition with #1055. PR #1060 remains -excluded; hosted checks remain pending until the parent promotes the composed -head. +recorder drain for suppressed terminal events, event-plus-status safe pruning, +and finite fail-closed admission during terminal persistence outage. The new +durability-retention focused suite, affected-package normal/race/vet, and the +full foreground repository regression gate pass on the exact local head at +85.7% coverage with zero uncovered production functions. Open PR #1070 still +points at its older head and is intentionally unpushed pending parent +composition with #1055. PR #1060 remains excluded; hosted checks remain pending +until the parent promotes the composed head. Current status: Issue #1023 anytime contextual `/feedback` intake is implemented test-first and verified in its isolated worktree; targeted, full normal/race, diff --git a/internal/harness/runner.go b/internal/harness/runner.go index 0ec0327a..62b5cd49 100644 --- a/internal/harness/runner.go +++ b/internal/harness/runner.go @@ -104,8 +104,10 @@ type runState struct { // run.failed, or run.cancelled) has been emitted. Any subsequent emit() call // returns immediately to prevent post-terminal streaming callbacks from // appending events after the forensic record is closed. - terminated bool - terminalEventPersisted bool + terminated bool + terminalEventPersisted bool + terminalEventSuppressed bool + terminalStatusPersisted bool // terminalMu serializes the complete terminal-helper lifecycle so only the // event winner may run terminal audit/profile/cleanup side effects. terminalMu sync.Mutex @@ -223,6 +225,24 @@ var ( ErrRunnerClosed = errors.New("runner is closed") ) +// TerminalDurabilityBackpressureError is returned by StartRun and ContinueRun +// when terminal runs whose event or final status has not been durably +// acknowledged reach MaxCompletedRetention. New admissions fail closed so +// already-admitted runs can finish without allowing an unbounded in-memory +// durability backlog. +type TerminalDurabilityBackpressureError struct { + Pending int + Limit int +} + +func (e *TerminalDurabilityBackpressureError) Error() string { + return fmt.Sprintf( + "terminal durability backlog reached retention limit: %d pending, limit %d", + e.Pending, + e.Limit, + ) +} + // steeringBufferSize is the capacity of the per-run steering message channel. const steeringBufferSize = 10 @@ -242,7 +262,10 @@ const recorderDrainTimeout = 30 * time.Second // the model returns 0 completion_tokens with empty content. const maxEmptyRetries = 3 -const terminalEventStoreTimeout = 5 * time.Second +const ( + terminalEventStoreTimeout = 5 * time.Second + terminalDurabilityAdmissionMaxDuration = 250 * time.Millisecond +) const ( defaultMaxCompletedRetention = 32 @@ -543,26 +566,133 @@ type retainedRunCandidate struct { updatedAt time.Time } +type terminalStatusRetry struct { + run Run +} + +func completedRetentionLimit(rc RunnerConfig) int { + if rc.MaxCompletedRetention > 0 { + return rc.MaxCompletedRetention + } + return defaultMaxCompletedRetention +} + +func runStateHasPersistentStore(state *runState, fallback RunnerConfig) bool { + if state != nil && state.config != nil { + return state.config.Store != nil + } + return fallback.Store != nil +} + +func terminalEventDurabilityResolved(state *runState) bool { + return state != nil && (state.terminalEventPersisted || state.terminalEventSuppressed) +} + +func terminalDurabilityComplete(state *runState) bool { + return terminalEventDurabilityResolved(state) && state.terminalStatusPersisted +} + +// terminalDurabilityBacklog snapshots the number of store-backed terminal runs +// which cannot yet be safely evicted. Status-only gaps are safe to retry with +// the same terminal Run snapshot because UpdateRun is an idempotent overwrite. +// Unacknowledged event appends are counted for backpressure but are not retried: +// a third-party store may have applied an append before returning an error, so +// retrying could duplicate the forensic event. +func (r *Runner) terminalDurabilityBacklog(rc RunnerConfig) (int, []terminalStatusRetry) { + r.mu.RLock() + defer r.mu.RUnlock() + + pending := 0 + retries := make([]terminalStatusRetry, 0) + for _, state := range r.runs { + if state == nil || !isTerminalRunStatus(state.run.Status) || !runStateHasPersistentStore(state, rc) { + continue + } + if terminalDurabilityComplete(state) { + continue + } + pending++ + if terminalEventDurabilityResolved(state) && !state.terminalStatusPersisted { + retries = append(retries, terminalStatusRetry{run: state.run}) + } + } + return pending, retries +} + +// ensureTerminalDurabilityCapacity retries recoverable status-only gaps under +// one small total deadline, then rejects admission if the unresolved backlog +// still reaches the retention cap. Store I/O occurs after terminalDurabilityBacklog +// releases Runner.mu and without status, conversation, or journal locks. +func (r *Runner) ensureTerminalDurabilityCapacity(preserveRunID string) error { + rc := r.snapshotConfig() + if rc.Store == nil { + return nil + } + limit := completedRetentionLimit(rc) + pending, retries := r.terminalDurabilityBacklog(rc) + if pending < limit { + return nil + } + + recovered := false + if len(retries) > 0 { + timeout := r.terminalStoreTimeoutDuration() + if timeout > terminalDurabilityAdmissionMaxDuration { + timeout = terminalDurabilityAdmissionMaxDuration + } + ctx, cancel := context.WithTimeout(context.Background(), timeout) + for _, retry := range retries { + if ctx.Err() != nil { + break + } + if r.storeUpdateRunSnapshotContext(ctx, retry.run) { + r.markTerminalStatusPersisted(retry.run) + recovered = true + } + } + cancel() + } + if recovered { + // Recovery turns protected terminal states into safe durable candidates. + // Restore the retention window immediately, without store I/O under the + // lock. ContinueRun preserves its source while still counting it toward + // the quota so the source survives long enough for the revalidated handoff. + r.pruneCompletedRunsPreserving(preserveRunID) + } + + pending, _ = r.terminalDurabilityBacklog(rc) + if pending >= limit { + return &TerminalDurabilityBackpressureError{Pending: pending, Limit: limit} + } + return nil +} + func (r *Runner) pruneCompletedRuns() { + r.pruneCompletedRunsPreserving("") +} + +func (r *Runner) pruneCompletedRunsPreserving(preserveRunID string) { r.mu.Lock() defer r.mu.Unlock() - r.pruneCompletedRunsLocked() + r.pruneCompletedRunsLockedPreserving(preserveRunID) } func (r *Runner) pruneCompletedRunsLocked() { + r.pruneCompletedRunsLockedPreserving("") +} + +func (r *Runner) pruneCompletedRunsLockedPreserving(preserveRunID string) { rc := r.snapshotConfig() if rc.Store == nil { return } - limit := rc.MaxCompletedRetention - if limit <= 0 { - limit = defaultMaxCompletedRetention - } + limit := completedRetentionLimit(rc) candidates := make([]retainedRunCandidate, 0) for runID, state := range r.runs { - if state == nil || !isTerminalRunStatus(state.run.Status) || !state.terminalEventPersisted { + if state == nil || !isTerminalRunStatus(state.run.Status) || + !runStateHasPersistentStore(state, rc) || !terminalDurabilityComplete(state) { continue } if len(state.subscribers) == 0 { @@ -587,8 +717,15 @@ func (r *Runner) pruneCompletedRunsLocked() { }) toDelete := len(candidates) - limit - for i := 0; i < toDelete; i++ { - delete(r.runs, candidates[i].id) + for _, candidate := range candidates { + if toDelete == 0 { + break + } + if candidate.id == preserveRunID { + continue + } + delete(r.runs, candidate.id) + toDelete-- } } @@ -1012,6 +1149,13 @@ func (r *Runner) StartRun(req RunRequest) (Run, error) { } } + // A terminal persistence outage must not turn the retention exceptions into + // unbounded memory growth. This check runs after request validation and + // ownership checks but before recorder creation or run-state admission. + if err := r.ensureTerminalDurabilityCapacity(""); err != nil { + return Run{}, err + } + // Create rollout recorder before acquiring the run lock so that any // filesystem error is surfaced at start time rather than mid-run. var rec *rollout.Recorder @@ -1591,10 +1735,12 @@ func (r *Runner) GetRun(runID string) (Run, bool) { // transcript. // // Errors: -// - ErrRunNotFound — the source run does not exist. -// - ErrRunNotCompleted — the source run has not reached RunStatusCompleted +// - ErrRunNotFound — the source run does not exist. +// - ErrRunNotCompleted — the source run has not reached RunStatusCompleted // (it is still running, queued, waiting for user, or has failed). -// - validation error — message is empty. +// - TerminalDurabilityBackpressureError — unresolved terminal persistence +// reached the configured in-memory retention cap. +// - validation error — message is empty. // // The method is safe for concurrent use. Only one goroutine can successfully // continue a given completed run: the first to acquire the lock transitions @@ -1630,6 +1776,30 @@ func (r *Runner) ContinueRunWithOptions(runID string, req ContinueRunRequest) (R } } + // Preserve source error precedence while degraded: an unknown or + // non-completed source is still a 404/409 rather than being masked by the + // runner-wide durability admission gate. The source is revalidated under + // the write lock below so concurrent continuations remain single-winner. + r.mu.RLock() + source, sourceOK := r.runs[runID] + if !sourceOK { + r.mu.RUnlock() + return Run{}, ErrRunNotFound + } + if source.run.Status != RunStatusCompleted { + r.mu.RUnlock() + return Run{}, ErrRunNotCompleted + } + if source.continued { + r.mu.RUnlock() + return Run{}, fmt.Errorf("run %q has already been continued", runID) + } + r.mu.RUnlock() + + if err := r.ensureTerminalDurabilityCapacity(runID); err != nil { + return Run{}, err + } + // Atomically check that the run exists and is completed, then immediately // stamp it with RunStatusRunning to prevent any other goroutine from also // starting a continuation. All snapshot values are read under the same @@ -5563,6 +5733,7 @@ func (r *Runner) emitWithTerminalCommit( // StorageModeNone intentionally suppresses the terminal event; its // status remains persistable by explicit policy rather than being // classified as an AppendEvent failure. + r.markTerminalEventSuppressed(runID) terminalPersist(true) } r.conversationEventMu.Lock() @@ -5636,14 +5807,18 @@ func (r *Runner) transitionTerminal( committed := false var finalRun Run prepared := false + statusPersisted := false if !r.emitWithTerminalCommit(runID, eventType, payload, func(eventPersisted bool) { finalRun, prepared = r.statusRunSnapshot(runID, status, output, runErr) if prepared && eventPersisted { - r.storeUpdateRunSnapshot(finalRun) + statusPersisted = r.storeUpdateRunSnapshot(finalRun) } }, func() { if prepared { committed = r.commitStatusSnapshot(runID, finalRun) + if committed && statusPersisted { + r.markTerminalStatusPersisted(finalRun) + } } }) { return false @@ -5842,13 +6017,17 @@ func (r *Runner) storeCreateRun(run Run) { } func (r *Runner) storeUpdateRunSnapshot(run Run) bool { + ctx, cancel := context.WithTimeout(context.Background(), r.terminalStoreTimeoutDuration()) + defer cancel() + return r.storeUpdateRunSnapshotContext(ctx, run) +} + +func (r *Runner) storeUpdateRunSnapshotContext(ctx context.Context, run Run) bool { rc := r.configForRun(run.ID) if rc.Store == nil { return true } sr := runToStoreRun(run) - ctx, cancel := context.WithTimeout(context.Background(), r.terminalStoreTimeoutDuration()) - defer cancel() if err := rc.Store.UpdateRun(ctx, sr); err != nil { if rc.Logger != nil { rc.Logger.Error("store: UpdateRun failed", "run_id", run.ID, "error", err) @@ -5909,6 +6088,25 @@ func (r *Runner) markTerminalEventPersisted(runID string) { } } +func (r *Runner) markTerminalEventSuppressed(runID string) { + r.mu.Lock() + defer r.mu.Unlock() + if state := r.runs[runID]; state != nil { + state.terminalEventSuppressed = true + } +} + +func (r *Runner) markTerminalStatusPersisted(run Run) { + r.mu.Lock() + defer r.mu.Unlock() + state := r.runs[run.ID] + if state == nil || !isTerminalRunStatus(state.run.Status) || + state.run.Status != run.Status || !state.run.UpdatedAt.Equal(run.UpdatedAt) { + return + } + state.terminalStatusPersisted = true +} + // storeAppendNewMessages appends any messages in the current run state that // have not yet been persisted to the store. It tracks how many messages have // already been stored via state.storedMsgCount and appends only the new tail. diff --git a/internal/harness/runner_prune_test.go b/internal/harness/runner_prune_test.go index 43291ec6..33b0286b 100644 --- a/internal/harness/runner_prune_test.go +++ b/internal/harness/runner_prune_test.go @@ -5,9 +5,11 @@ import ( "errors" "fmt" "sync" + "sync/atomic" "testing" "time" + "go-agent-harness/internal/forensics/redaction" runstore "go-agent-harness/internal/store" ) @@ -39,26 +41,412 @@ func TestRunner_PruneCompletedRunsFromMemory(t *testing.T) { } func TestRunner_PruneWaitsForTerminalEventPersistence(t *testing.T) { - runner := NewRunner(staticContentProvider{content: "done"}, NewRegistry(), RunnerConfig{ + release := make(chan struct{}) + runner := NewRunner(&blockingProvider{blocker: release}, NewRegistry(), RunnerConfig{ DefaultModel: "test-model", MaxSteps: 1, MaxCompletedRetention: 1, Store: &terminalAppendFailStore{Store: runstore.NewMemoryStore()}, }) + runIDs := make([]string, 0, 3) for i := 0; i < 3; i++ { run, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("unpersisted %d", i)}) if err != nil { t.Fatalf("StartRun: %v", err) } - waitForStatus(t, runner, run.ID, RunStatusCompleted) + runIDs = append(runIDs, run.ID) + } + close(release) + for _, runID := range runIDs { + waitForStatus(t, runner, runID, RunStatusCompleted) } runner.mu.RLock() - defer runner.mu.RUnlock() if got := len(runner.runs); got != 3 { + runner.mu.RUnlock() t.Fatalf("pruned terminal runs before terminal events persisted: got %d, want 3", got) } + runner.mu.RUnlock() + + _, err := runner.StartRun(RunRequest{Prompt: "must fail closed"}) + requireTerminalDurabilityBackpressure(t, err, 3, 1) + + runner.mu.Lock() + runner.runs["noncompleted-source"] = &runState{ + run: Run{ID: "noncompleted-source", Status: RunStatusRunning}, + subscribers: make(map[chan Event]struct{}), + } + runner.mu.Unlock() + if _, err := runner.ContinueRun("missing-source", "continue"); !errors.Is(err, ErrRunNotFound) { + t.Fatalf("ContinueRun missing source error=%v, want ErrRunNotFound before backpressure", err) + } + if _, err := runner.ContinueRun("noncompleted-source", "continue"); !errors.Is(err, ErrRunNotCompleted) { + t.Fatalf("ContinueRun noncompleted source error=%v, want ErrRunNotCompleted before backpressure", err) + } +} + +func TestRunner_PruneWaitsForTerminalStatusPersistence(t *testing.T) { + release := make(chan struct{}) + store := &terminalFailureStore{ + Store: runstore.NewMemoryStore(), + failUpdateRun: true, + } + runner := NewRunner(&blockingProvider{blocker: release}, NewRegistry(), RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + Store: store, + }) + + runIDs := make([]string, 0, 3) + for i := 0; i < 3; i++ { + run, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("status pending %d", i)}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + runIDs = append(runIDs, run.ID) + } + close(release) + for _, runID := range runIDs { + waitForStatus(t, runner, runID, RunStatusCompleted) + } + + runner.mu.RLock() + if got := len(runner.runs); got != 3 { + runner.mu.RUnlock() + t.Fatalf("pruned terminal runs before terminal statuses persisted: got %d, want 3", got) + } + runner.mu.RUnlock() + + for _, runID := range runIDs { + stored, err := store.Store.GetRun(context.Background(), runID) + if err != nil { + t.Fatalf("GetRun(%s): %v", runID, err) + } + if isTerminalStoreStatus(stored.Status) { + t.Fatalf("durable run %s status=%s, want non-terminal after UpdateRun failure", runID, stored.Status) + } + } + + _, err := runner.StartRun(RunRequest{Prompt: "must fail closed"}) + requireTerminalDurabilityBackpressure(t, err, 3, 1) +} + +func TestRunner_TerminalStatusPersistenceRecoveryAllowsConcurrentAdmissions(t *testing.T) { + store := &recoveringTerminalStatusStore{Store: runstore.NewMemoryStore()} + store.fail.Store(true) + runner := NewRunner(staticContentProvider{content: "done"}, NewRegistry(), RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + Store: store, + }) + + first, err := runner.StartRun(RunRequest{Prompt: "create pending terminal status"}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + waitForStatus(t, runner, first.ID, RunStatusCompleted) + + const callers = 16 + rejectStart := make(chan struct{}) + rejectErrs := make(chan error, callers) + for i := 0; i < callers; i++ { + go func(i int) { + <-rejectStart + _, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("still unavailable %d", i)}) + rejectErrs <- err + }(i) + } + close(rejectStart) + for i := 0; i < callers; i++ { + requireTerminalDurabilityBackpressure(t, <-rejectErrs, 1, 1) + } + + store.fail.Store(false) + start := make(chan struct{}) + errs := make(chan error, callers) + for i := 0; i < callers; i++ { + go func(i int) { + <-start + _, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("recovered %d", i)}) + errs <- err + }(i) + } + close(start) + for i := 0; i < callers; i++ { + if err := <-errs; err != nil { + t.Fatalf("concurrent recovered StartRun %d: %v", i, err) + } + } + + ctx, cancel := context.WithTimeout(context.Background(), 4*time.Second) + defer cancel() + if err := runner.Shutdown(ctx); err != nil { + t.Fatalf("Shutdown: %v", err) + } + if got := store.successfulTerminalUpdates.Load(); got == 0 { + t.Fatal("recovery never persisted a pending terminal status") + } +} + +func TestRunner_TerminalStatusRecoveryImmediatelyRestoresRetentionWindow(t *testing.T) { + release := make(chan struct{}) + store := &recoveringTerminalStatusStore{Store: runstore.NewMemoryStore()} + store.fail.Store(true) + runner := NewRunner(&blockingProvider{blocker: release}, NewRegistry(), RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + Store: store, + }) + + runIDs := make([]string, 0, 3) + for i := 0; i < 3; i++ { + run, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("recover and prune %d", i)}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + runIDs = append(runIDs, run.ID) + } + close(release) + for _, runID := range runIDs { + waitForStatus(t, runner, runID, RunStatusCompleted) + } + + store.fail.Store(false) + if err := runner.ensureTerminalDurabilityCapacity(""); err != nil { + t.Fatalf("ensureTerminalDurabilityCapacity after recovery: %v", err) + } + runner.mu.RLock() + retained := len(runner.runs) + runner.mu.RUnlock() + if retained != 1 { + t.Fatalf("recovered terminal states retained=%d, want exact retention window 1", retained) + } + for _, runID := range runIDs { + stored, err := store.GetRun(context.Background(), runID) + if err != nil { + t.Fatalf("store.GetRun(%s): %v", runID, err) + } + if stored.Status != runstore.RunStatusCompleted { + t.Fatalf("stored run %s status=%s, want completed after recovery", runID, stored.Status) + } + } + + if _, err := runner.StartRun(RunRequest{Prompt: "admitted after bounded recovery"}); err != nil { + t.Fatalf("StartRun after recovery: %v", err) + } +} + +func TestRunner_TerminalStatusRecoveryPreservesContinuationSource(t *testing.T) { + release := make(chan struct{}) + store := &recoveringTerminalStatusStore{Store: runstore.NewMemoryStore()} + store.fail.Store(true) + runner := NewRunner(&blockingProvider{blocker: release}, NewRegistry(), RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + Store: store, + }) + + runIDs := make([]string, 0, 3) + for i := 0; i < 3; i++ { + run, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("continuation recovery %d", i)}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + runIDs = append(runIDs, run.ID) + } + close(release) + for _, runID := range runIDs { + waitForStatus(t, runner, runID, RunStatusCompleted) + } + + store.fail.Store(false) + continued, err := runner.ContinueRun(runIDs[0], "continue after persistence recovery") + if err != nil { + t.Fatalf("ContinueRun after recovery: %v", err) + } + if continued.ID == "" { + t.Fatal("ContinueRun returned an empty run ID") + } +} + +func TestRunner_TerminalDurabilityAdmissionRetryUsesSingleUnlockedDeadline(t *testing.T) { + release := make(chan struct{}) + store := &blockingAdmissionRecoveryStore{ + Store: runstore.NewMemoryStore(), + started: make(chan struct{}), + } + runner := NewRunner(&blockingProvider{blocker: release}, NewRegistry(), RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + Store: store, + }) + runner.terminalStoreTimeout = 200 * time.Millisecond + + runIDs := make([]string, 0, 3) + for i := 0; i < 3; i++ { + run, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("deadline pending %d", i)}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + runIDs = append(runIDs, run.ID) + } + close(release) + for _, runID := range runIDs { + waitForStatus(t, runner, runID, RunStatusCompleted) + } + + const unrelatedID = "admission-lock-control" + runner.mu.Lock() + runner.runs[unrelatedID] = &runState{ + run: Run{ + ID: unrelatedID, + ConversationID: "admission-lock-control-conversation", + Status: RunStatusRunning, + }, + subscribers: make(map[chan Event]struct{}), + } + runner.mu.Unlock() + runner.storeCreateRun(Run{ID: unrelatedID, ConversationID: "admission-lock-control-conversation", Status: RunStatusRunning}) + + store.block.Store(true) + admissionDone := make(chan error, 1) + startedAt := time.Now() + go func() { + _, err := runner.StartRun(RunRequest{Prompt: "bounded blocked retry"}) + admissionDone <- err + }() + select { + case <-store.started: + case <-time.After(2 * time.Second): + t.Fatal("admission recovery did not reach UpdateRun") + } + + runner.mu.RLock() + pendingStates := make([]*runState, 0, len(runIDs)) + for _, runID := range runIDs { + pendingStates = append(pendingStates, runner.runs[runID]) + } + runner.mu.RUnlock() + for i, state := range pendingStates { + if state == nil || !state.statusMu.TryLock() { + t.Fatalf("pending status lock %d held during admission store I/O", i) + } + state.statusMu.Unlock() + } + + getDone := make(chan struct{}) + go func() { + _, _ = runner.GetRun(unrelatedID) + close(getDone) + }() + select { + case <-getDone: + case <-time.After(100 * time.Millisecond): + t.Fatal("GetRun blocked behind admission recovery store I/O") + } + + emitDone := make(chan struct{}) + go func() { + runner.emit(unrelatedID, EventAssistantMessage, map[string]any{"content": "unrelated"}) + close(emitDone) + }() + select { + case <-emitDone: + case <-time.After(100 * time.Millisecond): + t.Fatal("conversation event journal blocked behind admission recovery store I/O") + } + + select { + case err := <-admissionDone: + requireTerminalDurabilityBackpressure(t, err, 3, 1) + if elapsed := time.Since(startedAt); elapsed >= 500*time.Millisecond { + t.Fatalf("admission retry took %s, want one shared 200ms deadline rather than per-run waits", elapsed) + } + case <-time.After(time.Second): + t.Fatal("admission retry exceeded its shared deadline") + } +} + +func TestRunner_PruneTreatsStorageModeNoneAsIntentionalEventSuppression(t *testing.T) { + pipeline := redaction.NewPipeline( + redaction.NewRedactor(nil), + redaction.EventClassConfig{string(EventRunCompleted): redaction.StorageModeNone}, + ) + store := runstore.NewMemoryStore() + runner := NewRunner(staticContentProvider{content: "done"}, NewRegistry(), RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + RedactionPipeline: pipeline, + Store: store, + }) + + for i := 0; i < 3; i++ { + run, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("suppressed %d", i)}) + if err != nil { + t.Fatalf("StartRun %d: %v", i, err) + } + waitForStatus(t, runner, run.ID, RunStatusCompleted) + stored, err := store.GetRun(context.Background(), run.ID) + if err != nil { + t.Fatalf("store.GetRun(%s): %v", run.ID, err) + } + if stored.Status != runstore.RunStatusCompleted { + t.Fatalf("stored status=%s, want completed", stored.Status) + } + } + + waitForRunnerPrune(t, runner, func() bool { + runner.mu.RLock() + defer runner.mu.RUnlock() + return len(runner.runs) <= 1 + }) +} + +func TestRunner_NoStorePreservesInMemoryTerminalRunsWithoutBackpressure(t *testing.T) { + runner := NewRunner(staticContentProvider{content: "done"}, NewRegistry(), RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + }) + + for i := 0; i < 3; i++ { + run, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("memory only %d", i)}) + if err != nil { + t.Fatalf("StartRun %d: %v", i, err) + } + waitForStatus(t, runner, run.ID, RunStatusCompleted) + } + runner.mu.RLock() + retained := len(runner.runs) + runner.mu.RUnlock() + if retained != 3 { + t.Fatalf("no-store retained runs=%d, want 3", retained) + } + if _, err := runner.StartRun(RunRequest{Prompt: "no-store remains available"}); err != nil { + t.Fatalf("no-store StartRun unexpectedly backpressured: %v", err) + } +} + +func requireTerminalDurabilityBackpressure( + t *testing.T, + err error, + wantPending, wantLimit int, +) { + t.Helper() + var backpressure *TerminalDurabilityBackpressureError + if !errors.As(err, &backpressure) { + t.Fatalf("error=%v, want TerminalDurabilityBackpressureError", err) + } + if backpressure.Pending != wantPending || backpressure.Limit != wantLimit { + t.Fatalf("backpressure=%+v, want pending=%d limit=%d", backpressure, wantPending, wantLimit) + } } type terminalAppendFailStore struct{ runstore.Store } @@ -70,6 +458,41 @@ func (s *terminalAppendFailStore) AppendEvent(_ context.Context, event *runstore return s.Store.AppendEvent(context.Background(), event) } +type recoveringTerminalStatusStore struct { + runstore.Store + fail atomic.Bool + successfulTerminalUpdates atomic.Int64 +} + +func (s *recoveringTerminalStatusStore) UpdateRun(ctx context.Context, run *runstore.Run) error { + if isTerminalStoreStatus(run.Status) { + if s.fail.Load() { + return errors.New("terminal status store unavailable") + } + s.successfulTerminalUpdates.Add(1) + } + return s.Store.UpdateRun(ctx, run) +} + +type blockingAdmissionRecoveryStore struct { + runstore.Store + block atomic.Bool + started chan struct{} + startedOnce sync.Once +} + +func (s *blockingAdmissionRecoveryStore) UpdateRun(ctx context.Context, run *runstore.Run) error { + if !isTerminalStoreStatus(run.Status) { + return s.Store.UpdateRun(ctx, run) + } + if s.block.Load() { + s.startedOnce.Do(func() { close(s.started) }) + <-ctx.Done() + return ctx.Err() + } + return errors.New("terminal status store unavailable") +} + func TestRunner_PruneKeepsCompletedRunWithActiveSubscriber(t *testing.T) { t.Parallel() diff --git a/internal/harness/types.go b/internal/harness/types.go index 51661e12..acb1a2de 100644 --- a/internal/harness/types.go +++ b/internal/harness/types.go @@ -623,7 +623,9 @@ type RunnerConfig struct { // immediately (the legacy unbounded behaviour). WorkerPoolSize int // MaxCompletedRetention caps completed/failed/cancelled run states retained - // in memory after terminal events are persisted and subscribers drain. + // in memory after terminal event and status durability are resolved and + // subscribers drain. When unresolved store-backed terminal durability reaches + // this cap, new run admissions fail closed until status persistence recovers. // 0 uses the default retention window. MaxCompletedRetention int // MaxConversationRetention caps the in-memory conversation transcript mirror. diff --git a/internal/server/http_runs.go b/internal/server/http_runs.go index 91326df3..d327ab30 100644 --- a/internal/server/http_runs.go +++ b/internal/server/http_runs.go @@ -64,6 +64,11 @@ func (s *Server) handlePostRun(w http.ResponseWriter, r *http.Request) { run, err := s.runner.StartRun(req) if err != nil { + var durabilityErr *harness.TerminalDurabilityBackpressureError + if errors.As(err, &durabilityErr) { + writeError(w, http.StatusServiceUnavailable, "terminal_durability_unavailable", err.Error()) + return + } writeError(w, http.StatusBadRequest, "invalid_request", err.Error()) return } @@ -703,6 +708,11 @@ func (s *Server) handleRunContinue(w http.ResponseWriter, r *http.Request, runID Permissions: req.Permissions, }) if err != nil { + var durabilityErr *harness.TerminalDurabilityBackpressureError + if errors.As(err, &durabilityErr) { + writeError(w, http.StatusServiceUnavailable, "terminal_durability_unavailable", err.Error()) + return + } if errors.Is(err, harness.ErrRunNotFound) { writeError(w, http.StatusNotFound, "not_found", fmt.Sprintf("run %q not found", runID)) return diff --git a/internal/server/http_terminal_atomicity_test.go b/internal/server/http_terminal_atomicity_test.go index 7bcb1413..59532043 100644 --- a/internal/server/http_terminal_atomicity_test.go +++ b/internal/server/http_terminal_atomicity_test.go @@ -13,6 +13,7 @@ import ( "time" "go-agent-harness/internal/harness" + runstore "go-agent-harness/internal/store" ) func TestTerminalStatusPollImmediatelyReplaysMatchingTerminalEvent(t *testing.T) { @@ -115,6 +116,57 @@ func TestTerminalStatusPollImmediatelyReplaysMatchingTerminalEvent(t *testing.T) } } +func TestTerminalDurabilityBackpressureMapsStartAndContinueToServiceUnavailable(t *testing.T) { + store := &httpTerminalStatusFailStore{Store: runstore.NewMemoryStore()} + runner := harness.NewRunner(&terminalHTTPProvider{ + result: harness.CompletionResult{Content: "done"}, + }, harness.NewRegistry(), harness.RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + Store: store, + }) + ts := httptest.NewServer(New(runner)) + t.Cleanup(func() { + ts.Close() + _ = runner.Shutdown(context.Background()) + }) + + runID := startTerminalHTTPRun(t, ts) + waitForRunStatus(t, ts, runID, string(harness.RunStatusCompleted)) + + tests := []struct { + name string + url string + }{ + {name: "start", url: ts.URL + "/v1/runs"}, + {name: "continue", url: ts.URL + "/v1/runs/" + runID + "/continue"}, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + res, err := http.Post(tt.url, "application/json", bytes.NewBufferString(`{"prompt":"blocked admission"}`)) + if err != nil { + t.Fatalf("POST: %v", err) + } + defer res.Body.Close() + var response struct { + Error struct { + Code string `json:"code"` + } `json:"error"` + } + if err := json.NewDecoder(res.Body).Decode(&response); err != nil { + t.Fatalf("decode response: %v", err) + } + if res.StatusCode != http.StatusServiceUnavailable { + t.Fatalf("status=%d code=%q, want 503", res.StatusCode, response.Error.Code) + } + if response.Error.Code != "terminal_durability_unavailable" { + t.Fatalf("error code=%q, want terminal_durability_unavailable", response.Error.Code) + } + }) + } +} + type terminalHTTPProvider struct { result harness.CompletionResult err error @@ -122,6 +174,16 @@ type terminalHTTPProvider struct { hang bool } +type httpTerminalStatusFailStore struct{ runstore.Store } + +func (s *httpTerminalStatusFailStore) UpdateRun(ctx context.Context, run *runstore.Run) error { + if run.Status == runstore.RunStatusCompleted || run.Status == runstore.RunStatusFailed || + run.Status == runstore.RunStatus("cancelled") { + return errors.New("terminal status persistence unavailable") + } + return s.Store.UpdateRun(ctx, run) +} + func (p *terminalHTTPProvider) Complete(ctx context.Context, _ harness.CompletionRequest) (harness.CompletionResult, error) { if p.started != nil { select { From 5f106bef74923d875a899b789688989f2d1ee256 Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 20:34:09 +0200 Subject: [PATCH 5/8] fix: reserve continuation sources during recovery --- docs/logs/engineering-log.md | 25 ++++-- docs/logs/long-term-thinking-log.md | 14 ++- docs/logs/observational-log.md | 7 ++ docs/logs/system-log.md | 7 ++ ...minal-status-event-atomicity-impact-map.md | 10 ++- ...67-terminal-status-event-atomicity-plan.md | 30 ++++++- docs/plans/active-plan.md | 9 +- internal/harness/runner.go | 69 +++++++++++---- internal/harness/runner_prune_test.go | 85 +++++++++++++++++++ internal/harness/runner_test.go | 5 ++ 10 files changed, 225 insertions(+), 36 deletions(-) diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 3ba17515..05baea29 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -101,11 +101,26 @@ proves the shared deadline and unlocked state/journal access; append failure, StorageModeNone, no-store, Continue error precedence, and both HTTP 503 routes are pinned. -- Verification: the expanded terminal suite and HTTP replay passed normal/race - at `-count=100`; complete `internal/harness` + `internal/server` normal/race - and affected `go vet` passed. The final uninterrupted foreground non-TTY - `./scripts/test-regression.sh` passed normal, race, and - `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. +- Concurrent review red: a phase hook paused Continue immediately after its + completed-source validation. A concurrent Start recovered three pending + statuses, pruned the oldest validated source at retention 1, and the resumed + Continue deterministically failed with `run not found`. +- Concurrent review fix: validation now increments an in-state continuation + reservation under `Runner.mu`. The one shared completed-run prune candidate + filter excludes reserved sources for every caller. A defer releases on every + success/error path and immediately re-prunes; the existing later write-lock + `continued` check still chooses exactly one continuation winner. Recovery + store I/O remains outside Runner/status/journal/conversation locks. +- Gate-test correction: full race exposed one test treating terminal replay as + proof status had already committed. The one-way contract is the reverse: + terminal status implies replay, while replay may lead status. The test now + waits independently for failed status and retains both replay/status checks. +- Verification: the concurrent red is green with cleanup and single-winner + controls normal/race at `-count=100`; the expanded durability harness and HTTP + suites pass normal/race at `-count=100`; complete `internal/harness` plus + `internal/server` normal/race and affected `go vet` pass. The final direct + foreground non-TTY `./scripts/test-regression.sh` passes normal, full race, + and `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/long-term-thinking-log.md b/docs/logs/long-term-thinking-log.md index 6cd618dd..c0f42913 100644 --- a/docs/logs/long-term-thinking-log.md +++ b/docs/logs/long-term-thinking-log.md @@ -41,7 +41,9 @@ statuses; one shared lifecycle seam makes terminal ledger/store publication precede status visibility while preserving recorder order; immediate Subscribe and HTTP SSE replay agree; focused stress, affected race/vet, full - regression, and hosted checks pass on one unmerged closing PR. + regression, and hosted checks pass on one unmerged closing PR. Concurrent + Start recovery/pruning must not evict a completed source after Continue has + validated it but before that continuation performs its single-winner commit. - Non-goals: conversation cursor redesign, cron/callback behavior, client UI, provider routing, schemas, or workflow timing changes. - Guardrails: preserve out-of-lock bounded store writes, terminal sealing, @@ -62,9 +64,13 @@ uses one unlocked deadline capped at 250 ms; Start/Continue expose typed HTTP 503 while no-store and intentional StorageModeNone policies remain distinct. Successful status recovery immediately restores the retention bound before - reopening admission. The added focused normal/race and real HTTP mapping - tests, affected normal/race/vet, and the unchanged foreground repository gate - are green at 85.7% coverage with zero uncovered production functions. + reopening admission. A temporary in-state reservation now protects a + validated Continue source from every prune caller across unlocked recovery; + release on all exits restores the retention policy without weakening the + existing single-winner check. Focused normal/race and real HTTP mapping tests + plus affected normal/race/vet are green. The unchanged foreground repository + gate passes normal, full race, and 85.7% coverage with zero uncovered + production functions on the final follow-up diff. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index 851bc075..0d6696c4 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -67,6 +67,13 @@ Use this file for observations about system behavior without immediately prescri no durable fallback and stays process-local; StorageModeNone intentionally resolves the event side while its final status can still make safe pruning possible. +- Continuation observation: preserving a source only in Continue's own recovery + prune is insufficient because concurrent Start recovery calls the same prune + policy without that local argument. A reservation stored on the source and + checked by the shared candidate filter protects it across every prune caller. +- Contract observation: terminal replay can lead the later status commit during + event-first publication. Tests that assert both must wait independently for + status; only terminal status is guaranteed to imply matching replay. ## 2026-07-31 (Source-Workflow Dual-Error Arbitration) diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index 7961b9c0..158b63ab 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -63,6 +63,13 @@ append errors remain blocked until process/operator recovery rather than risking a duplicate forensic event. No-store runs intentionally remain process-local and ungated. +- Continuation reservation boundary: source validation and reservation are one + `Runner.mu` mutation; unlocked durability recovery follows; the existing + write-lock revalidation remains the only single-winner mutation. The shared + prune candidate filter excludes nonzero reservations regardless of caller. + Deferred release decrements the in-state counter and immediately invokes the + shared lock-held prune policy, so no keyed side map or stale reservation entry + survives success, backpressure, revalidation loss, or dispatch failure. ## 2026-07-31 (Source-Workflow Terminal Error Arbitration) diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md index dfac440c..05b2bef4 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md @@ -70,7 +70,10 @@ - Concurrency: the winning terminal event seals the ledger before status is updated; competing terminal helpers cannot overwrite it with a mismatched status. Every status snapshot/persist/commit sequence shares a per-run mutex, - so a delayed running/waiting write cannot overwrite terminal state. + so a delayed running/waiting write cannot overwrite terminal state. A + validated Continue source requires a temporary in-state reservation across + unlocked durability recovery so a concurrent Start prune cannot remove it + before the existing single-winner continuation commit. - Cancellation/retries/cleanup: cooperative cancellation and idempotency stay unchanged; workspace/tool/MCP cleanup remains before terminal publication. Status-only durability gaps retry safely as idempotent `UpdateRun` overwrites @@ -141,8 +144,9 @@ retention 1 when final status updates fail and their durable rows remain non-terminal; append- and status-pending runs both close admission at the cap; concurrent callers reject during outage and recover after status persistence; - the retry uses one unlocked deadline; StorageModeNone and no-store policies - remain explicit. + the retry uses one unlocked deadline; concurrent Start recovery cannot prune + a reserved Continue source; reservation cleanup and single-winner behavior + remain bounded; StorageModeNone and no-store policies remain explicit. - Integration: HTTP poll immediately followed by run SSE replay for all three statuses. - Exact gates: focused normal/race stress `-count=100`; harness/server diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md index 113d6b8e..9ce8adfc 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md @@ -20,6 +20,11 @@ therefore make pruning evict truthful live state while the durable row stayed non-terminal; permanent append/update failures could also grow protected memory without an admission bound. +- Exact-head concurrent review finding: Continue validated its completed source, + released `Runner.mu`, and performed bounded durability recovery before its + single-winner mutation. A concurrent Start recovery could prune that source + through the shared prune path, turning a valid continuation into a spurious + `ErrRunNotFound`. ## Scope @@ -69,6 +74,11 @@ intentional StorageModeNone suppression, and no-store behavior. Pin one shared retry deadline of at most 250 ms with no store I/O under Runner, status, event-journal, or conversation locks. +- Continuation reservation control: deterministically block Continue's first + recovery write after source validation, let a concurrent Start recover and + prune, then require Continue to retain its source through the single-winner + handoff. The reservation must apply to every completed-run prune caller and + release on all success/error paths without holding locks across store I/O. - Concurrency control: race competing terminal transitions and require the winning status to match the single sealed terminal event; hold a terminal at the pre-fanout boundary and prove a later same-conversation event cannot @@ -145,6 +155,12 @@ - Mitigation: validate unknown/non-completed sources before the global gate, revalidate for the single-winner mutation, map only the typed error to 503, and prove the retry holds no Runner/status/conversation lock. +- Risk: validation followed by unlocked recovery lets another admission's prune + delete the continuation source before revalidation. +- Mitigation: reserve the validated source under `Runner.mu`, exclude reserved + sources in the shared prune implementation used by every caller, and release + plus re-prune on every return path. The reservation does not grant the + continuation winner status; the existing write-lock revalidation still does. - Risk: an explicit terminal `StorageModeNone` policy intentionally removes the matching event from replay. - Mitigation: preserve and test the existing redaction exception and scope the @@ -165,17 +181,27 @@ - Exact-head P1 reds: at retention 1, append-pending admission remained open; status-update-failed terminal runs were pruned despite non-terminal durable rows; and both Start/Continue mapped the new typed degraded state to 400. +- Exact-head concurrent P1 red: a phase hook paused Continue after source + validation, concurrent Start recovery pruned that oldest source at retention + 1, and resumed Continue failed deterministically with `run not found`. - Exact-head focused green: append/status pending runs remain visible, both close admission at the cap, 16 concurrent callers reject then recover under race, successful status recovery immediately restores the retention bound, status recovery uses one unlocked total deadline, Start/Continue return the explicit 503, and StorageModeNone/no-store controls pass. +- Concurrent focused green: the source reservation is respected by the shared + prune path, releases after backpressure, and preserves exactly one continuation + winner. The new regression, cleanup control, and existing winner control pass + normal/race at `-count=100`. - Focused current green: all terminal publication/failure-policy regressions and HTTP replay passed normal and race at `-count=100`. - Affected current green: complete harness/server normal and race passed; affected `go vet` passed. - Real path: HTTP terminal polling followed immediately by Last-Event-ID run SSE replay passed for completed, failed, and cancelled. -- Repository: the final uninterrupted foreground non-TTY - `./scripts/test-regression.sh` passed normal, race, and coverage with +- Gate-test review: the complete race gate exposed a replay-first test that read + status before the later commit. Its independent failed-status wait now matches + the one-way contract, and the affected race gate passes. +- Repository: the final direct foreground non-TTY + `./scripts/test-regression.sh` passed normal, full race, and coverage with `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. diff --git a/docs/plans/active-plan.md b/docs/plans/active-plan.md index a45b1afb..679c6730 100644 --- a/docs/plans/active-plan.md +++ b/docs/plans/active-plan.md @@ -5,10 +5,11 @@ isolated branch `codex/issue-1067-terminal-status-event-atomicity`. Post-review hardening now defines and tests the one-way durable failure contract, bounded store waits, per-run status serialization, per-conversation lock reclamation, recorder drain for suppressed terminal events, event-plus-status safe pruning, -and finite fail-closed admission during terminal persistence outage. The new -durability-retention focused suite, affected-package normal/race/vet, and the -full foreground repository regression gate pass on the exact local head at -85.7% coverage with zero uncovered production functions. Open PR #1070 still +finite fail-closed admission during terminal persistence outage, and a +prune-wide reservation for validated continuation sources. The concurrent red, +durability-retention focused suite, affected-package normal/race/vet, and full +foreground repository gate pass at 85.7% coverage with zero uncovered +production functions. Open PR #1070 still points at its older head and is intentionally unpushed pending parent composition with #1055. PR #1060 remains excluded; hosted checks remain pending until the parent promotes the composed head. diff --git a/internal/harness/runner.go b/internal/harness/runner.go index 62b5cd49..a14c4f28 100644 --- a/internal/harness/runner.go +++ b/internal/harness/runner.go @@ -96,6 +96,10 @@ type runState struct { // continued is set to true once ContinueRun has been called on this run, // preventing a second continuation without mutating the run's terminal Status. continued bool + // continuationReservations protects a validated completed source from every + // completed-run prune path while ContinueRun performs unlocked durability + // recovery and its later single-winner mutation. It is guarded by Runner.mu. + continuationReservations int // snapshotBuilder collects a rolling window of tool calls and messages for // error context snapshots. Non-nil only when ErrorChainEnabled is set in // RunnerConfig. @@ -391,6 +395,9 @@ type Runner struct { // statusBeforeCommitHook is a test seam invoked after a non-terminal status // snapshot is prepared and before it is committed. statusBeforeCommitHook func(string, RunStatus) + // continuationAfterValidationHook is a test seam invoked after ContinueRun + // validates its source and releases Runner.mu, before durability recovery. + continuationAfterValidationHook func(string) // terminalStoreTimeout overrides the bounded terminal store timeout in // deterministic tests. Zero uses terminalEventStoreTimeout. terminalStoreTimeout time.Duration @@ -695,7 +702,7 @@ func (r *Runner) pruneCompletedRunsLockedPreserving(preserveRunID string) { !runStateHasPersistentStore(state, rc) || !terminalDurabilityComplete(state) { continue } - if len(state.subscribers) == 0 { + if len(state.subscribers) == 0 && state.continuationReservations == 0 { candidates = append(candidates, retainedRunCandidate{ id: runID, updatedAt: state.run.UpdatedAt, @@ -1776,25 +1783,18 @@ func (r *Runner) ContinueRunWithOptions(runID string, req ContinueRunRequest) (R } } - // Preserve source error precedence while degraded: an unknown or - // non-completed source is still a 404/409 rather than being masked by the - // runner-wide durability admission gate. The source is revalidated under - // the write lock below so concurrent continuations remain single-winner. - r.mu.RLock() - source, sourceOK := r.runs[runID] - if !sourceOK { - r.mu.RUnlock() - return Run{}, ErrRunNotFound - } - if source.run.Status != RunStatusCompleted { - r.mu.RUnlock() - return Run{}, ErrRunNotCompleted + // Preserve source error precedence while degraded and reserve the validated + // source before releasing Runner.mu. The reservation is not the continuation + // winner decision: concurrent continuations still revalidate and compete on + // state.continued under the write lock below. It only prevents every shared + // prune path from deleting the source during unlocked durability recovery. + if err := r.reserveContinuationSource(runID); err != nil { + return Run{}, err } - if source.continued { - r.mu.RUnlock() - return Run{}, fmt.Errorf("run %q has already been continued", runID) + defer r.releaseContinuationSource(runID) + if r.continuationAfterValidationHook != nil { + r.continuationAfterValidationHook(runID) } - r.mu.RUnlock() if err := r.ensureTerminalDurabilityCapacity(runID); err != nil { return Run{}, err @@ -1979,6 +1979,39 @@ func (r *Runner) ContinueRunWithOptions(runID string, req ContinueRunRequest) (R return newRun, nil } +func (r *Runner) reserveContinuationSource(runID string) error { + r.mu.Lock() + defer r.mu.Unlock() + + state, ok := r.runs[runID] + if !ok { + return ErrRunNotFound + } + if state.run.Status != RunStatusCompleted { + return ErrRunNotCompleted + } + if state.continued { + return fmt.Errorf("run %q has already been continued", runID) + } + state.continuationReservations++ + return nil +} + +func (r *Runner) releaseContinuationSource(runID string) { + r.mu.Lock() + defer r.mu.Unlock() + + state := r.runs[runID] + if state == nil || state.continuationReservations == 0 { + return + } + state.continuationReservations-- + // A reservation is a temporary pruning exception. Re-run the shared prune + // policy immediately on release so success, backpressure, validation races, + // and dispatch failure cannot leave the retention window inflated. + r.pruneCompletedRunsLocked() +} + // GetRunSummary computes a telemetry summary for a completed (or failed) run // by scanning the run's event history. Returns ErrRunNotFound if the run does // not exist, or an error if the run is still in progress. diff --git a/internal/harness/runner_prune_test.go b/internal/harness/runner_prune_test.go index 33b0286b..e4c9e1ab 100644 --- a/internal/harness/runner_prune_test.go +++ b/internal/harness/runner_prune_test.go @@ -71,6 +71,14 @@ func TestRunner_PruneWaitsForTerminalEventPersistence(t *testing.T) { _, err := runner.StartRun(RunRequest{Prompt: "must fail closed"}) requireTerminalDurabilityBackpressure(t, err, 3, 1) + _, err = runner.ContinueRun(runIDs[0], "valid source must also fail closed") + requireTerminalDurabilityBackpressure(t, err, 3, 1) + runner.mu.RLock() + reservations := runner.runs[runIDs[0]].continuationReservations + runner.mu.RUnlock() + if reservations != 0 { + t.Fatalf("continuation reservations after backpressure=%d, want 0", reservations) + } runner.mu.Lock() runner.runs["noncompleted-source"] = &runState{ @@ -274,6 +282,83 @@ func TestRunner_TerminalStatusRecoveryPreservesContinuationSource(t *testing.T) } } +func TestRunner_ConcurrentStartRecoveryCannotPruneValidatedContinuationSource(t *testing.T) { + releaseProvider := make(chan struct{}) + store := &recoveringTerminalStatusStore{Store: runstore.NewMemoryStore()} + store.fail.Store(true) + runner := NewRunner(&blockingProvider{blocker: releaseProvider}, NewRegistry(), RunnerConfig{ + DefaultModel: "test-model", + MaxSteps: 1, + MaxCompletedRetention: 1, + Store: store, + }) + + runIDs := make([]string, 0, 3) + for i := 0; i < 3; i++ { + run, err := runner.StartRun(RunRequest{Prompt: fmt.Sprintf("concurrent continuation recovery %d", i)}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + runIDs = append(runIDs, run.ID) + } + close(releaseProvider) + for _, runID := range runIDs { + waitForStatus(t, runner, runID, RunStatusCompleted) + } + + // Make the continuation source the deterministic first prune candidate. + base := time.Now().UTC().Add(-time.Hour) + runner.mu.Lock() + for i, runID := range runIDs { + runner.runs[runID].run.UpdatedAt = base.Add(time.Duration(i) * time.Minute) + } + runner.mu.Unlock() + + validated := make(chan struct{}) + releaseContinue := make(chan struct{}) + runner.continuationAfterValidationHook = func(gotRunID string) { + if gotRunID != runIDs[0] { + return + } + close(validated) + <-releaseContinue + } + store.fail.Store(false) + + type continueResult struct { + run Run + err error + } + continueDone := make(chan continueResult, 1) + go func() { + run, err := runner.ContinueRun(runIDs[0], "continue after concurrent recovery") + continueDone <- continueResult{run: run, err: err} + }() + select { + case <-validated: + case <-time.After(2 * time.Second): + t.Fatal("ContinueRun did not reach the post-validation boundary") + } + + if _, err := runner.StartRun(RunRequest{Prompt: "concurrent recovery admission"}); err != nil { + close(releaseContinue) + t.Fatalf("concurrent StartRun recovery: %v", err) + } + close(releaseContinue) + + select { + case result := <-continueDone: + if result.err != nil { + t.Fatalf("ContinueRun after concurrent Start recovery: %v", result.err) + } + if result.run.ID == "" { + t.Fatal("ContinueRun returned an empty run ID") + } + case <-time.After(2 * time.Second): + t.Fatal("ContinueRun did not finish after concurrent recovery") + } +} + func TestRunner_TerminalDurabilityAdmissionRetryUsesSingleUnlockedDeadline(t *testing.T) { release := make(chan struct{}) store := &blockingAdmissionRecoveryStore{ diff --git a/internal/harness/runner_test.go b/internal/harness/runner_test.go index ab66ca52..3644b4cb 100644 --- a/internal/harness/runner_test.go +++ b/internal/harness/runner_test.go @@ -1999,6 +1999,11 @@ func TestRunnerFailsWhenClientFactoryErrors_NoFallback(t *testing.T) { if err != nil { t.Fatalf("collect events: %v", err) } + // A terminal event can be present in replay while its matching status is + // still completing the event-first publication sequence. Wait for the + // independently asserted status instead of treating replay as the inverse + // of the public status-implies-replay guarantee. + waitForStatus(t, runner, run.ID, RunStatusFailed) state, ok := runner.GetRun(run.ID) if !ok { From 8757e8a36bf0192950fc810424b3ac1afd04ca74 Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 21:18:42 +0200 Subject: [PATCH 6/8] test: wait for terminal status after event collection --- docs/logs/engineering-log.md | 23 +++++++ docs/logs/long-term-thinking-log.md | 11 +++- docs/logs/observational-log.md | 5 ++ docs/logs/system-log.md | 5 ++ ...minal-status-event-atomicity-impact-map.md | 4 ++ ...67-terminal-status-event-atomicity-plan.md | 32 ++++++++-- docs/plans/active-plan.md | 12 ++-- internal/harness/runner_meta_test.go | 12 ++-- .../harness/runner_terminal_atomicity_test.go | 64 +++++++++++++++++++ internal/harness/runner_test.go | 46 +++++++++++-- 10 files changed, 194 insertions(+), 20 deletions(-) diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 05baea29..6a28f622 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -121,6 +121,29 @@ `internal/server` normal/race and affected `go vet` pass. The final direct foreground non-TTY `./scripts/test-regression.sh` passes normal, full race, and `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. +- Hosted settled-helper symptom: exact rebased race run `30656467482` failed + `TestRunnerHookErrorFailOpen` because `collectRunEvents` returned terminal + replay history before the valid later status commit; the immediate `GetRun` + still reported `running`. +- Audit/cause: 215 `collectRunEvents` references, its sole configurable-timeout + caller, and 79 `collectEvents` snapshot references were reviewed. No shared + collector caller intentionally observes the event-leading-status window. + Exact ordering regressions use direct phase hooks/subscriptions; snapshot + consumers either wait separately or intentionally inspect nonterminal state. +- Deterministic red/fix: a pre-status terminal barrier made replay visible and + failed the old collector immediately with `returned before terminal status + commit`. Both collector variants now preserve event assertions and then poll + for any terminal status within the same total deadline. A missing status is a + timeout failure rather than a false settled result; production order is + unchanged. +- Hosted-equivalent verification: the collector, all hook scenarios, and the + configurable-timeout caller pass normal/race at `-count=100`; `make + test-race` passes. The final outside-sandbox foreground + `TMPDIR=/private/tmp GOCACHE=/private/tmp/gocode-go-cache + ./scripts/test-regression.sh` passes normal, full race, and + `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. GitHub + comment publication was blocked by external-write safety review and was not + retried; this repository evidence records the run. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/long-term-thinking-log.md b/docs/logs/long-term-thinking-log.md index c0f42913..ea624f4f 100644 --- a/docs/logs/long-term-thinking-log.md +++ b/docs/logs/long-term-thinking-log.md @@ -44,6 +44,9 @@ regression, and hosted checks pass on one unmerged closing PR. Concurrent Start recovery/pruning must not evict a completed source after Continue has validated it but before that continuation performs its single-winner commit. + Test helpers that promise a collected terminal run must preserve event + assertions while independently requiring the later terminal status, without + weakening the production event-first order or direct barrier regressions. - Non-goals: conversation cursor redesign, cron/callback behavior, client UI, provider routing, schemas, or workflow timing changes. - Guardrails: preserve out-of-lock bounded store writes, terminal sealing, @@ -70,7 +73,13 @@ existing single-winner check. Focused normal/race and real HTTP mapping tests plus affected normal/race/vet are green. The unchanged foreground repository gate passes normal, full race, and 85.7% coverage with zero uncovered - production functions on the final follow-up diff. + production functions on the prior follow-up diff. After hosted race run + `30656467482`, the shared test collector now treats terminal history plus the + later terminal status as its settled boundary under one total deadline. The + event-first production contract and direct phase tests remain unchanged; + affected normal/race x100 and hosted-equivalent `make test-race` pass. The + final outside-sandbox foreground repository gate passes normal, full race, + and 85.7% coverage with zero uncovered production functions. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index 0d6696c4..a37e5f9e 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -74,6 +74,11 @@ Use this file for observations about system behavior without immediately prescri - Contract observation: terminal replay can lead the later status commit during event-first publication. Tests that assert both must wait independently for status; only terminal status is guaranteed to imply matching replay. +- Helper-audit observation: aggregate race load repeatedly finds stale tests + when a helper named as event collection is treated implicitly as run + settlement. Shared callers all want settlement, while intentional window + probes use direct `Subscribe`; encoding the distinction once in the test + helper prevents the next immediate-`GetRun` variant without changing replay. ## 2026-07-31 (Source-Workflow Dual-Error Arbitration) diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index 158b63ab..c6e42e5e 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -70,6 +70,11 @@ Deferred release decrements the in-state counter and immediately invokes the shared lock-held prune policy, so no keyed side map or stale reservation entry survives success, backpressure, revalidation loss, or dispatch failure. +- Test settlement boundary: `collectRunEvents` and its configurable-timeout + variant retain terminal history exactly, then use the remaining shared + deadline to require any terminal `GetRun` status. This is test-only and does + not move the production commit or fanout boundaries. Direct phase tests bypass + the settled helper and continue observing the intentional publication window. ## 2026-07-31 (Source-Workflow Terminal Error Arbitration) diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md index 05b2bef4..b0be820c 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md @@ -149,6 +149,10 @@ remain bounded; StorageModeNone and no-store policies remain explicit. - Integration: HTTP poll immediately followed by run SSE replay for all three statuses. +- Test helpers: terminal event/history assertions remain unchanged; shared + settled-run collectors independently await any terminal status under their + existing total deadline. Direct transition-window tests keep raw Subscribe + and phase barriers. - Exact gates: focused normal/race stress `-count=100`; harness/server normal/race/vet; unchanged foreground non-TTY regression; hosted checks. diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md index 9ce8adfc..a392a1be 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md @@ -25,6 +25,11 @@ single-winner mutation. A concurrent Start recovery could prune that source through the shared prune path, turning a valid continuation into a spurious `ErrRunNotFound`. +- Hosted aggregate review finding: race run `30656467482` exposed another stale + test assumption in `TestRunnerHookErrorFailOpen`: `collectRunEvents` returned + terminal replay history while the valid later completed-status commit was + still in progress. The helper's 215 references and its configurable-timeout + equivalent were audited; no caller intentionally observes that window. ## Scope @@ -32,15 +37,16 @@ cancelled, max-step failed, and max-turn failed paths; deterministic concurrency and replay regressions; event/status-aware safe pruning; bounded degraded admission and recovery; explicit Start/Continue HTTP 503 mapping; - real HTTP poll-then-replay proof. + real HTTP poll-then-replay proof; test-helper settlement semantics that keep + terminal event collection and terminal status waiting distinct. - Out of scope: PR #1060/#1055 changes, cron/callback behavior, conversation cursor redesign, GUI visual changes, provider routing, schemas, and workflow timing issue #1049. ## Documentation Contract -- Feature status: exact-head durability-retention hardening implemented and - verified locally through focused stress, affected normal/race/vet, and the +- Feature status: durability-retention hardening remains implemented; the + hosted settled-helper repair passes focused stress, `make test-race`, and the unchanged full repository regression gate. - Public API behavior: event/status wire formats stay unchanged. During a full terminal durability backlog, Start/Continue now return documented HTTP 503 @@ -79,6 +85,10 @@ prune, then require Continue to retain its source through the single-winner handoff. The reservation must apply to every completed-run prune caller and release on all success/error paths without holding locks across store I/O. +- Settled collection control: pause terminal publication after replay history is + visible but before status commit, call the shared event collector, and prove + it does not return until a terminal status is independently observable. Keep + one total bounded deadline and retain the exact collected event assertions. - Concurrency control: race competing terminal transitions and require the winning status to match the single sealed terminal event; hold a terminal at the pre-fanout boundary and prove a later same-conversation event cannot @@ -202,6 +212,18 @@ - Gate-test review: the complete race gate exposed a replay-first test that read status before the later commit. Its independent failed-status wait now matches the one-way contract, and the affected race gate passes. +- Hosted settled-helper red: race run `30656467482` reproduced the next stale + immediate-status assumption in `TestRunnerHookErrorFailOpen`. A deterministic + pre-status barrier then proved the shared collector returned terminal history + while status remained running. +- Helper audit/green: all 215 shared collector references, the configurable + timeout variant, and the separate snapshot helper family were classified. + No shared collector consumer requires the transition window. Settlement now + preserves event history and independently requires terminal status within one + total deadline; the deterministic test, hook family, and timeout caller pass + normal/race at `-count=100`, and hosted-equivalent `make test-race` passes. - Repository: the final direct foreground non-TTY - `./scripts/test-regression.sh` passed normal, full race, and coverage with - `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. + `TMPDIR=/private/tmp GOCACHE=/private/tmp/gocode-go-cache + ./scripts/test-regression.sh` passed normal, full race, and coverage with + `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)` on the + settled-helper diff. diff --git a/docs/plans/active-plan.md b/docs/plans/active-plan.md index 679c6730..eae01c49 100644 --- a/docs/plans/active-plan.md +++ b/docs/plans/active-plan.md @@ -9,10 +9,14 @@ finite fail-closed admission during terminal persistence outage, and a prune-wide reservation for validated continuation sources. The concurrent red, durability-retention focused suite, affected-package normal/race/vet, and full foreground repository gate pass at 85.7% coverage with zero uncovered -production functions. Open PR #1070 still -points at its older head and is intentionally unpushed pending parent -composition with #1055. PR #1060 remains excluded; hosted checks remain pending -until the parent promotes the composed head. +production functions on the prior follow-up. PR #1070 reached rebased head +`5f106bef`, where hosted race run `30656467482` exposed a stale settled-test +assumption; the audited shared event +collector now independently awaits terminal status under the same deadline. +Affected normal/race x100, hosted-equivalent `make test-race`, and the final +outside-sandbox foreground repository gate pass at 85.7% coverage with zero +uncovered production functions. The test-only repair remains local and +unpushed; PR #1060 remains excluded and no merge is authorized. Current status: Issue #1023 anytime contextual `/feedback` intake is implemented test-first and verified in its isolated worktree; targeted, full normal/race, diff --git a/internal/harness/runner_meta_test.go b/internal/harness/runner_meta_test.go index 9c65a6f9..9f2069b4 100644 --- a/internal/harness/runner_meta_test.go +++ b/internal/harness/runner_meta_test.go @@ -585,6 +585,7 @@ func TestRunnerConcurrentMetaMessageInjection(t *testing.T) { // collectRunEventsWithTimeout is like collectRunEvents but with configurable timeout. func collectRunEventsWithTimeout(runner *Runner, runID string, timeout time.Duration) ([]Event, error) { + deadline := time.Now().Add(timeout) history, stream, cancel, err := runner.Subscribe(runID) if err != nil { return nil, err @@ -593,21 +594,22 @@ func collectRunEventsWithTimeout(runner *Runner, runID string, timeout time.Dura events := append([]Event(nil), history...) if hasTerminalEvent(events) { - return events, nil + return settleCollectedRunEvents(runner, runID, events, deadline) } - timer := time.After(timeout) + timer := time.NewTimer(time.Until(deadline)) + defer timer.Stop() for { select { case ev, ok := <-stream: if !ok { - return events, nil + return settleCollectedRunEvents(runner, runID, events, deadline) } events = append(events, ev) if IsTerminalEvent(ev.Type) { - return events, nil + return settleCollectedRunEvents(runner, runID, events, deadline) } - case <-timer: + case <-timer.C: return nil, context.DeadlineExceeded } } diff --git a/internal/harness/runner_terminal_atomicity_test.go b/internal/harness/runner_terminal_atomicity_test.go index 4071359b..977babf0 100644 --- a/internal/harness/runner_terminal_atomicity_test.go +++ b/internal/harness/runner_terminal_atomicity_test.go @@ -309,6 +309,70 @@ func TestTerminalConversationFanoutCannotBeOvertaken(t *testing.T) { } } +func TestCollectRunEventsWaitsForTerminalStatusAfterReplay(t *testing.T) { + reached := make(chan struct{}) + release := make(chan struct{}) + t.Cleanup(func() { + select { + case <-release: + default: + close(release) + } + }) + + runner := NewRunner(staticContentProvider{content: "done"}, NewRegistry(), RunnerConfig{}) + runner.terminalBeforeDispatchHook = func(_ string, eventType EventType) { + if eventType != EventRunCompleted { + return + } + close(reached) + <-release + } + run, err := runner.StartRun(RunRequest{Prompt: "settled event collection"}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + select { + case <-reached: + case <-time.After(2 * time.Second): + t.Fatal("terminal publication did not reach the pre-status barrier") + } + + started := make(chan struct{}) + collected := make(chan error, 1) + go func() { + close(started) + events, err := collectRunEvents(t, runner, run.ID) + if err == nil && !containsEventType(events, EventRunCompleted) { + err = fmt.Errorf("collected events missing %s", EventRunCompleted) + } + collected <- err + }() + <-started + select { + case err := <-collected: + t.Fatalf("collectRunEvents returned before terminal status commit: %v", err) + case <-time.After(100 * time.Millisecond): + } + + current, ok := runner.GetRun(run.ID) + if !ok { + t.Fatalf("GetRun(%q) returned not found", run.ID) + } + if isTerminalRunStatus(current.Status) { + t.Fatalf("status=%s before releasing terminal commit, want non-terminal", current.Status) + } + close(release) + select { + case err := <-collected: + if err != nil { + t.Fatalf("collectRunEvents after terminal status commit: %v", err) + } + case <-time.After(2 * time.Second): + t.Fatal("collectRunEvents did not return after terminal status commit") + } +} + type terminalCancellationProvider struct { started chan struct{} } diff --git a/internal/harness/runner_test.go b/internal/harness/runner_test.go index 3644b4cb..9513dffb 100644 --- a/internal/harness/runner_test.go +++ b/internal/harness/runner_test.go @@ -739,8 +739,13 @@ func TestRunnerFailedRunIncludesPartialUsageTotals(t *testing.T) { } } +// collectRunEvents preserves terminal event/history collection and also waits +// for the independently published terminal status. Event-first publication may +// expose replay before status; most callers use this helper as a settled-run +// boundary. The phase-ordering tests use direct Subscribe barriers instead. func collectRunEvents(t *testing.T, runner *Runner, runID string) ([]Event, error) { t.Helper() + deadline := time.Now().Add(4 * time.Second) history, stream, cancel, err := runner.Subscribe(runID) if err != nil { @@ -750,26 +755,57 @@ func collectRunEvents(t *testing.T, runner *Runner, runID string) ([]Event, erro events := append([]Event(nil), history...) if hasTerminalEvent(events) { - return events, nil + return settleCollectedRunEvents(runner, runID, events, deadline) } - timeout := time.After(4 * time.Second) + timeout := time.NewTimer(time.Until(deadline)) + defer timeout.Stop() for { select { case ev, ok := <-stream: if !ok { - return events, nil + return settleCollectedRunEvents(runner, runID, events, deadline) } events = append(events, ev) if IsTerminalEvent(ev.Type) { - return events, nil + return settleCollectedRunEvents(runner, runID, events, deadline) } - case <-timeout: + case <-timeout.C: return nil, context.DeadlineExceeded } } } +func settleCollectedRunEvents( + runner *Runner, + runID string, + events []Event, + deadline time.Time, +) ([]Event, error) { + for { + run, ok := runner.GetRun(runID) + if !ok { + return events, fmt.Errorf("run %q disappeared before terminal status settled", runID) + } + if isTerminalRunStatus(run.Status) { + return events, nil + } + remaining := time.Until(deadline) + if remaining <= 0 { + return events, fmt.Errorf( + "run %q terminal event collected before status settled: %w", + runID, + context.DeadlineExceeded, + ) + } + wait := 5 * time.Millisecond + if remaining < wait { + wait = remaining + } + time.Sleep(wait) + } +} + func hasTerminalEvent(events []Event) bool { for _, ev := range events { if IsTerminalEvent(ev.Type) { From 5b4eb8535b4762fd87f663148c1b4e5b9fe35e06 Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 21:37:35 +0200 Subject: [PATCH 7/8] test: require matching terminal event settlement --- docs/logs/engineering-log.md | 21 ++++++ docs/logs/long-term-thinking-log.md | 8 +- docs/logs/observational-log.md | 7 ++ docs/logs/system-log.md | 10 ++- ...minal-status-event-atomicity-impact-map.md | 8 +- ...67-terminal-status-event-atomicity-plan.md | 26 ++++++- docs/plans/active-plan.md | 7 +- internal/harness/runner_meta_test.go | 22 +----- .../harness/runner_terminal_atomicity_test.go | 75 +++++++++++++++++-- internal/harness/runner_test.go | 59 ++++++++++++++- 10 files changed, 199 insertions(+), 44 deletions(-) diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 6a28f622..e33e4da9 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -144,6 +144,27 @@ `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)`. GitHub comment publication was blocked by external-write safety review and was not retried; this repository evidence records the run. +- Exact-head helper review: commit `8757e8a3` still let settlement succeed when + a closed stream had no terminal event, or when the sole terminal event did + not match the later terminal status. This was a P1 test-integrity defect, not + a production-path defect: it could mask the exact #1067 invariant across the + shared collector callers. +- Review TDD reds: a completed run plus closed stream containing only + `run.started` returned success, and failed status plus `run.completed` + returned success. Both failures were immediate and deterministic. +- Review fix: the test-only subscribed-stream core now requires exactly one + terminal event and requires its completed/failed/cancelled meaning to match + the observed terminal status. Event slices remain unchanged on success and + error, and both event collection and status settlement consume the original + single deadline. The phase regression now waits for an explicit settlement + entry signal before proving the collector cannot return ahead of status. +- Review verification: the two regressions, explicit settlement barrier, hook + family, and configurable-timeout caller pass normal/race at `-count=100`. + Outside-sandbox `make test-race` passes. The authoritative foreground + `TMPDIR=/private/tmp GOCACHE=/private/tmp/gocode-go-cache + ./scripts/test-regression.sh` passes normal, full race, and + `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)` on this exact + follow-up diff. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/long-term-thinking-log.md b/docs/logs/long-term-thinking-log.md index ea624f4f..5075fad9 100644 --- a/docs/logs/long-term-thinking-log.md +++ b/docs/logs/long-term-thinking-log.md @@ -79,7 +79,13 @@ event-first production contract and direct phase tests remain unchanged; affected normal/race x100 and hosted-equivalent `make test-race` pass. The final outside-sandbox foreground repository gate passes normal, full race, - and 85.7% coverage with zero uncovered production functions. + and 85.7% coverage with zero uncovered production functions. Exact-head + review then hardened the helper boundary again: settlement now requires + exactly one terminal event whose meaning matches terminal status, and the + phase regression proves it entered settlement before asserting non-return. + Focused normal/race x100, hosted-equivalent race, and the final foreground + repository gate pass; coverage remains 85.7% with zero uncovered production + functions on this follow-up diff. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index a37e5f9e..480d6ad9 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -79,6 +79,13 @@ Use this file for observations about system behavior without immediately prescri settlement. Shared callers all want settlement, while intentional window probes use direct `Subscribe`; encoding the distinction once in the test helper prevents the next immediate-`GetRun` variant without changing replay. +- Settlement observation: waiting for any terminal status is insufficient if + the collected transcript is absent or contradictory. A settled test result + requires exactly one terminal event whose completed/failed/cancelled meaning + matches status; stream closure is not evidence of transcript completeness. +- Synchronization observation: a timed non-return assertion is meaningful only + after the tested goroutine proves it reached the intended blocking phase. An + explicit settlement-entry handshake removes scheduler delay as a false pass. ## 2026-07-31 (Source-Workflow Dual-Error Arbitration) diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index c6e42e5e..b5da337e 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -71,10 +71,12 @@ shared lock-held prune policy, so no keyed side map or stale reservation entry survives success, backpressure, revalidation loss, or dispatch failure. - Test settlement boundary: `collectRunEvents` and its configurable-timeout - variant retain terminal history exactly, then use the remaining shared - deadline to require any terminal `GetRun` status. This is test-only and does - not move the production commit or fanout boundaries. Direct phase tests bypass - the settled helper and continue observing the intentional publication window. + variant retain terminal history exactly, require exactly one terminal event, + then use the remaining shared deadline to require the matching terminal + `GetRun` status. Closed streams without a terminal event and contradictory + event/status pairs fail explicitly. This is test-only and does not move the + production commit or fanout boundaries. Direct phase tests bypass the settled + helper and continue observing the intentional publication window. ## 2026-07-31 (Source-Workflow Terminal Error Arbitration) diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md index b0be820c..2249a954 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-impact-map.md @@ -150,9 +150,11 @@ - Integration: HTTP poll immediately followed by run SSE replay for all three statuses. - Test helpers: terminal event/history assertions remain unchanged; shared - settled-run collectors independently await any terminal status under their - existing total deadline. Direct transition-window tests keep raw Subscribe - and phase barriers. + settled-run collectors require exactly one terminal event and independently + await its matching status under their existing total deadline. Stream close + without terminal history and event/status mismatch are explicit failures. + Direct transition-window tests keep raw Subscribe and phase barriers; their + non-return proof uses an explicit settlement-entry handshake. - Exact gates: focused normal/race stress `-count=100`; harness/server normal/race/vet; unchanged foreground non-TTY regression; hosted checks. diff --git a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md index a392a1be..c5a7b16d 100644 --- a/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md +++ b/docs/plans/2026-07-31-issue-1067-terminal-status-event-atomicity-plan.md @@ -30,6 +30,11 @@ terminal replay history while the valid later completed-status commit was still in progress. The helper's 215 references and its configurable-timeout equivalent were audited; no caller intentionally observes that window. +- Exact-head helper review finding: commit `8757e8a3` accepted any terminal + status after collection, even if stream closure supplied no terminal event or + the collected terminal event contradicted status. Its phase regression also + used a timed non-return window without proving the goroutine entered + settlement first. ## Scope @@ -46,8 +51,8 @@ ## Documentation Contract - Feature status: durability-retention hardening remains implemented; the - hosted settled-helper repair passes focused stress, `make test-race`, and the - unchanged full repository regression gate. + exact-head settled-helper validation repair passes focused normal/race stress, + hosted-equivalent race, and the full repository regression gate. - Public API behavior: event/status wire formats stay unchanged. During a full terminal durability backlog, Start/Continue now return documented HTTP 503 `terminal_durability_unavailable` after bounded recovery fails. @@ -87,8 +92,10 @@ release on all success/error paths without holding locks across store I/O. - Settled collection control: pause terminal publication after replay history is visible but before status commit, call the shared event collector, and prove - it does not return until a terminal status is independently observable. Keep - one total bounded deadline and retain the exact collected event assertions. + it reaches settlement and does not return until the matching terminal status + is independently observable. Reject closed streams without a terminal event + and terminal event/status mismatch. Keep one total bounded deadline and + retain the exact collected event assertions. - Concurrency control: race competing terminal transitions and require the winning status to match the single sealed terminal event; hold a terminal at the pre-fanout boundary and prove a later same-conversation event cannot @@ -222,6 +229,17 @@ preserves event history and independently requires terminal status within one total deadline; the deterministic test, hook family, and timeout caller pass normal/race at `-count=100`, and hosted-equivalent `make test-race` passes. +- Exact-head review reds: a completed run plus closed stream containing only + `run.started` returned success, and failed status plus `run.completed` + returned success. The phase regression's prior timed non-return check did not + prove its collector goroutine had entered settlement. +- Exact-head review green: the subscribed-stream core requires exactly one + terminal event and matches its meaning to status without changing the + collected slice or original total deadline. The phase test uses an explicit + settlement-entry signal. Both regressions, the phase test, hook family, and + configurable-timeout caller pass normal/race at `-count=100`; + hosted-equivalent `make test-race` and the authoritative full repository gate + pass on this follow-up diff. - Repository: the final direct foreground non-TTY `TMPDIR=/private/tmp GOCACHE=/private/tmp/gocode-go-cache ./scripts/test-regression.sh` passed normal, full race, and coverage with diff --git a/docs/plans/active-plan.md b/docs/plans/active-plan.md index eae01c49..af239221 100644 --- a/docs/plans/active-plan.md +++ b/docs/plans/active-plan.md @@ -15,7 +15,12 @@ assumption; the audited shared event collector now independently awaits terminal status under the same deadline. Affected normal/race x100, hosted-equivalent `make test-race`, and the final outside-sandbox foreground repository gate pass at 85.7% coverage with zero -uncovered production functions. The test-only repair remains local and +uncovered production functions. Exact-head review of local commit `8757e8a3` +then found the settled helper accepted missing or status-mismatched terminal +events and its phase test lacked an entry handshake. The test-only correction +requires exactly one matching terminal event and passes focused normal/race +x100, hosted-equivalent race, and the full repository gate at 85.7% coverage +with zero uncovered production functions. The repair remains local and unpushed; PR #1060 remains excluded and no merge is authorized. Current status: Issue #1023 anytime contextual `/feedback` intake is implemented diff --git a/internal/harness/runner_meta_test.go b/internal/harness/runner_meta_test.go index 9f2069b4..db9ae1c9 100644 --- a/internal/harness/runner_meta_test.go +++ b/internal/harness/runner_meta_test.go @@ -592,25 +592,5 @@ func collectRunEventsWithTimeout(runner *Runner, runID string, timeout time.Dura } defer cancel() - events := append([]Event(nil), history...) - if hasTerminalEvent(events) { - return settleCollectedRunEvents(runner, runID, events, deadline) - } - - timer := time.NewTimer(time.Until(deadline)) - defer timer.Stop() - for { - select { - case ev, ok := <-stream: - if !ok { - return settleCollectedRunEvents(runner, runID, events, deadline) - } - events = append(events, ev) - if IsTerminalEvent(ev.Type) { - return settleCollectedRunEvents(runner, runID, events, deadline) - } - case <-timer.C: - return nil, context.DeadlineExceeded - } - } + return collectSubscribedRunEvents(runner, runID, history, stream, deadline, nil) } diff --git a/internal/harness/runner_terminal_atomicity_test.go b/internal/harness/runner_terminal_atomicity_test.go index 977babf0..001472fb 100644 --- a/internal/harness/runner_terminal_atomicity_test.go +++ b/internal/harness/runner_terminal_atomicity_test.go @@ -309,6 +309,52 @@ func TestTerminalConversationFanoutCannotBeOvertaken(t *testing.T) { } } +func TestCollectSubscribedRunEventsRejectsClosedStreamWithoutTerminalEvent(t *testing.T) { + const runID = "closed-before-terminal-event" + runner := NewRunner(staticContentProvider{content: "unused"}, NewRegistry(), RunnerConfig{}) + runner.mu.Lock() + runner.runs[runID] = &runState{ + run: Run{ID: runID, Status: RunStatusCompleted}, + subscribers: make(map[chan Event]struct{}), + } + runner.mu.Unlock() + + stream := make(chan Event) + close(stream) + history := []Event{{RunID: runID, Type: EventRunStarted}} + events, err := collectSubscribedRunEvents( + runner, runID, history, stream, time.Now().Add(time.Second), nil, + ) + if err == nil { + t.Fatalf("closed stream without terminal event returned success: events=%v", eventTypes(events)) + } + if len(events) != 1 || events[0].Type != EventRunStarted { + t.Fatalf("closed-stream events = %v, want preserved history", eventTypes(events)) + } +} + +func TestCollectSubscribedRunEventsRejectsMismatchedTerminalEventAndStatus(t *testing.T) { + const runID = "mismatched-terminal-event-status" + runner := NewRunner(staticContentProvider{content: "unused"}, NewRegistry(), RunnerConfig{}) + runner.mu.Lock() + runner.runs[runID] = &runState{ + run: Run{ID: runID, Status: RunStatusFailed}, + subscribers: make(map[chan Event]struct{}), + } + runner.mu.Unlock() + + history := []Event{{RunID: runID, Type: EventRunCompleted}} + events, err := collectSubscribedRunEvents( + runner, runID, history, nil, time.Now().Add(time.Second), nil, + ) + if err == nil { + t.Fatalf("completed event with failed status returned success: events=%v", eventTypes(events)) + } + if len(events) != 1 || events[0].Type != EventRunCompleted { + t.Fatalf("mismatched-status events = %v, want preserved history", eventTypes(events)) + } +} + func TestCollectRunEventsWaitsForTerminalStatusAfterReplay(t *testing.T) { reached := make(chan struct{}) release := make(chan struct{}) @@ -338,21 +384,31 @@ func TestCollectRunEventsWaitsForTerminalStatusAfterReplay(t *testing.T) { t.Fatal("terminal publication did not reach the pre-status barrier") } - started := make(chan struct{}) + history, stream, cancel, err := runner.Subscribe(run.ID) + if err != nil { + t.Fatalf("Subscribe: %v", err) + } + defer cancel() + settlementEntered := make(chan struct{}) collected := make(chan error, 1) go func() { - close(started) - events, err := collectRunEvents(t, runner, run.ID) + events, err := collectSubscribedRunEvents( + runner, + run.ID, + history, + stream, + time.Now().Add(4*time.Second), + func() { close(settlementEntered) }, + ) if err == nil && !containsEventType(events, EventRunCompleted) { err = fmt.Errorf("collected events missing %s", EventRunCompleted) } collected <- err }() - <-started select { - case err := <-collected: - t.Fatalf("collectRunEvents returned before terminal status commit: %v", err) - case <-time.After(100 * time.Millisecond): + case <-settlementEntered: + case <-time.After(2 * time.Second): + t.Fatal("collector did not enter terminal settlement") } current, ok := runner.GetRun(run.ID) @@ -362,6 +418,11 @@ func TestCollectRunEventsWaitsForTerminalStatusAfterReplay(t *testing.T) { if isTerminalRunStatus(current.Status) { t.Fatalf("status=%s before releasing terminal commit, want non-terminal", current.Status) } + select { + case err := <-collected: + t.Fatalf("collector returned after settlement entry but before terminal status commit: %v", err) + default: + } close(release) select { case err := <-collected: diff --git a/internal/harness/runner_test.go b/internal/harness/runner_test.go index 9513dffb..dc4acefc 100644 --- a/internal/harness/runner_test.go +++ b/internal/harness/runner_test.go @@ -753,9 +753,20 @@ func collectRunEvents(t *testing.T, runner *Runner, runID string) ([]Event, erro } defer cancel() + return collectSubscribedRunEvents(runner, runID, history, stream, deadline, nil) +} + +func collectSubscribedRunEvents( + runner *Runner, + runID string, + history []Event, + stream <-chan Event, + deadline time.Time, + settlementStarted func(), +) ([]Event, error) { events := append([]Event(nil), history...) if hasTerminalEvent(events) { - return settleCollectedRunEvents(runner, runID, events, deadline) + return settleCollectedRunEvents(runner, runID, events, deadline, settlementStarted) } timeout := time.NewTimer(time.Until(deadline)) @@ -764,11 +775,11 @@ func collectRunEvents(t *testing.T, runner *Runner, runID string) ([]Event, erro select { case ev, ok := <-stream: if !ok { - return settleCollectedRunEvents(runner, runID, events, deadline) + return settleCollectedRunEvents(runner, runID, events, deadline, settlementStarted) } events = append(events, ev) if IsTerminalEvent(ev.Type) { - return settleCollectedRunEvents(runner, runID, events, deadline) + return settleCollectedRunEvents(runner, runID, events, deadline, settlementStarted) } case <-timeout.C: return nil, context.DeadlineExceeded @@ -781,13 +792,30 @@ func settleCollectedRunEvents( runID string, events []Event, deadline time.Time, + settlementStarted func(), ) ([]Event, error) { + if settlementStarted != nil { + settlementStarted() + } + eventStatus, err := collectedTerminalRunStatus(events) + if err != nil { + return events, fmt.Errorf("run %q terminal settlement: %w", runID, err) + } for { run, ok := runner.GetRun(runID) if !ok { return events, fmt.Errorf("run %q disappeared before terminal status settled", runID) } if isTerminalRunStatus(run.Status) { + if run.Status != eventStatus { + return events, fmt.Errorf( + "run %q terminal status %q does not match collected terminal event status %q; events=%v", + runID, + run.Status, + eventStatus, + eventTypes(events), + ) + } return events, nil } remaining := time.Until(deadline) @@ -806,6 +834,31 @@ func settleCollectedRunEvents( } } +func collectedTerminalRunStatus(events []Event) (RunStatus, error) { + var terminalStatus RunStatus + for _, event := range events { + var status RunStatus + switch event.Type { + case EventRunCompleted: + status = RunStatusCompleted + case EventRunFailed: + status = RunStatusFailed + case EventRunCancelled: + status = RunStatusCancelled + default: + continue + } + if terminalStatus != "" { + return "", fmt.Errorf("collected multiple terminal events: %v", eventTypes(events)) + } + terminalStatus = status + } + if terminalStatus == "" { + return "", fmt.Errorf("collected events contain no terminal event: %v", eventTypes(events)) + } + return terminalStatus, nil +} + func hasTerminalEvent(events []Event) bool { for _, ev := range events { if IsTerminalEvent(ev.Type) { From b45b4334aea593704581ed5c0b38a95b942e3193 Mon Sep 17 00:00:00 2001 From: Dennison Date: Sat, 1 Aug 2026 01:10:33 +0200 Subject: [PATCH 8/8] fix(harness): keep live nonterminal status moving --- docs/logs/engineering-log.md | 10 +++++ internal/harness/runner.go | 6 +-- .../runner_terminal_failure_policy_test.go | 40 +++++++++++++++++++ 3 files changed, 53 insertions(+), 3 deletions(-) diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 463efaec..7828a5ae 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -197,6 +197,16 @@ ./scripts/test-regression.sh` passes normal, full race, and `coveragegate: PASS (total=85.7%, min=80.0%, zero-functions=0)` on this exact follow-up diff. +- Promotion integration regression: the semantic merge with #1054 initially + persisted every non-terminal status before committing it in memory. A failed + best-effort `UpdateRun` therefore left an executing run visibly stale; the + AskUser broker could own a live pending question while API, TUI, and GUI + still saw `running` instead of `waiting_for_user`. A deterministic failing + store test reproduced `queued` after a requested transition to `running`. + The unified per-run status lock now commits live non-terminal state first, + retaining the persistence attempt and false return so strict + waiting-status/event publication can retry without making the pending prompt + invisible. Terminal transitions retain their event-before-status contract. ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/internal/harness/runner.go b/internal/harness/runner.go index 84c1c498..0f814c02 100644 --- a/internal/harness/runner.go +++ b/internal/harness/runner.go @@ -4583,15 +4583,15 @@ func (r *Runner) updateStatusContext( if ctx.Err() != nil { return false } + if !r.commitStatusSnapshot(runID, finalRun) { + return false + } persistCtx, cancel := context.WithTimeout(ctx, r.terminalStoreTimeoutDuration()) persisted := r.storeUpdateRunSnapshotContext(persistCtx, finalRun) cancel() if !persisted { return false } - if !r.commitStatusSnapshot(runID, finalRun) { - return false - } if afterPersist != nil { // Keep statusMu held through its corresponding lifecycle event so // terminal mutation/publication cannot overtake a waiting transition. diff --git a/internal/harness/runner_terminal_failure_policy_test.go b/internal/harness/runner_terminal_failure_policy_test.go index 537047c0..5662a5bc 100644 --- a/internal/harness/runner_terminal_failure_policy_test.go +++ b/internal/harness/runner_terminal_failure_policy_test.go @@ -13,6 +13,46 @@ import ( runstore "go-agent-harness/internal/store" ) +type failingNonTerminalStatusStore struct { + *runstore.MemoryStore +} + +func (s *failingNonTerminalStatusStore) UpdateRun(ctx context.Context, run *runstore.Run) error { + if run.Status == runstore.RunStatusRunning { + return errors.New("nonterminal status persistence failed") + } + return s.MemoryStore.UpdateRun(ctx, run) +} + +func TestNonTerminalStatusPersistenceFailureKeepsLiveStateMoving(t *testing.T) { + store := &failingNonTerminalStatusStore{MemoryStore: runstore.NewMemoryStore()} + runner := NewRunner(&stubProvider{}, NewRegistry(), RunnerConfig{Store: store}) + t.Cleanup(func() { _ = runner.Shutdown(context.Background()) }) + const runID = "nonterminal-status-write-failure" + run := Run{ID: runID, ConversationID: "nonterminal-status-write-failure-conv", Status: RunStatusQueued} + runner.runs[runID] = &runState{run: run, subscribers: make(map[chan Event]struct{})} + if err := store.CreateRun(context.Background(), runToStoreRun(run)); err != nil { + t.Fatalf("CreateRun: %v", err) + } + + runner.setStatus(runID, RunStatusRunning, "", "") + + current, ok := runner.GetRun(runID) + if !ok { + t.Fatal("run disappeared") + } + if current.Status != RunStatusRunning { + t.Fatalf("in-memory status = %q, want running despite best-effort store failure", current.Status) + } + stored, err := store.GetRun(context.Background(), runID) + if err != nil { + t.Fatalf("GetRun: %v", err) + } + if stored.Status != runstore.RunStatusQueued { + t.Fatalf("durable status = %q, want queued after injected write failure", stored.Status) + } +} + func TestTerminalAppendDoesNotBlockUnrelatedConversationOrAllowSameConversationOvertake(t *testing.T) { store := &blockingTerminalAppendStore{ Store: runstore.NewMemoryStore(),