From a3d8f734728e9362bcdc61c0fef5ec6d0d5419bd Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 17:14:11 +0200 Subject: [PATCH 1/2] Fix dispatcher shutdown test isolation --- docs/logs/engineering-log.md | 23 +++++ docs/logs/long-term-thinking-log.md | 21 +++++ docs/logs/observational-log.md | 13 +++ docs/logs/system-log.md | 14 +++ ...ispatcher-shutdown-isolation-impact-map.md | 86 +++++++++++++++++++ ...1068-dispatcher-shutdown-isolation-plan.md | 85 ++++++++++++++++++ docs/plans/INDEX.md | 2 + docs/plans/active-plan.md | 7 ++ internal/harness/runner.go | 11 ++- internal/harness/runner_shutdown_test.go | 75 +++++++++------- 10 files changed, 303 insertions(+), 34 deletions(-) create mode 100644 docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md create mode 100644 docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index ad8ff7ee..a9ea8520 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -1,5 +1,28 @@ # Engineering Log +## 2026-07-31 (Runner Dispatcher Shutdown Isolation — Issue #1068) + +- Symptom: `go test -race ./internal/harness -count=5` failed four of five + repetitions because `TestRunnerWithoutShutdownLeaksDispatcher` found some + `poolDispatcher` frame after its target Runner's `Shutdown` returned. +- Cause: the test scanned all goroutine stacks by shared function name. Other + parallel harness tests legitimately kept bounded Runners alive, so the + assertion had no target identity. The production path already closes the + target's `done` channel and waits its `dispatcherWG` before returning. +- TDD red: a deterministic two-Runner fixture kept a control Runner alive, + shut down the target, and failed the old global-absence assertion immediately. +- Fix: replace target lifecycle inference with a narrow per-Runner dispatcher + exit hook invoked immediately before the existing `dispatcherWG.Done`. + The test blocks that exact target hook, proves `Shutdown` cannot return, + releases it, then proves Shutdown returns while the control's global stack + frame remains visible. +- Compatibility: queue draining, inflight accounting, cancellation timeout, + idempotency, and production shutdown ordering are unchanged. +- Verification: focused normal/race passed at `-count=100`; complete harness + race passed at `-count=5`; harness/server normal, race, and vet passed; and + unchanged foreground non-TTY `./scripts/test-regression.sh` passed at 85.6% + total coverage with zero uncovered functions. + ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) - Symptom: hosted race run `30583930460` failed diff --git a/docs/logs/long-term-thinking-log.md b/docs/logs/long-term-thinking-log.md index a7729e92..5ecd49a2 100644 --- a/docs/logs/long-term-thinking-log.md +++ b/docs/logs/long-term-thinking-log.md @@ -1,5 +1,26 @@ # Long-Term Thinking Log +## 2026-07-31 (Runner Dispatcher Shutdown Isolation — Issue #1068) + +- Command intent: independently classify and repair the 4/5 aggregate race + failure without combining remote cron or terminal-publication work. +- User intent: make shutdown proof identify the exact Runner so CI neither + hides a real goroutine leak nor blocks on a healthy unrelated Runner. +- Success definition: a deterministic two-Runner control proves target exit + while a control dispatcher stays live; focused through hosted gates pass on + one unmerged closing PR. +- Non-goals: PR #1060, PR #1055, issue #1067, worker-pool redesign, or longer sleeps. +- Guardrails: strict red-green TDD, preserve `done`/`dispatcherWG` ownership, + queue drain, active cancellation, idempotency, and exact regression commands. +- Next verification step: capture aggregate race red evidence, then add the + deterministic instance-scoped test before changing production code. +- Root-cause outcome: the exact aggregate command reproduced 4/5 failures and + the two-Runner red failed deterministically, classifying the defect as a + process-global test false positive rather than a runtime Runner leak. +- Implementation outcome: target exit identity now comes from a hook ordered + immediately before the existing instance wait-group completion; production + shutdown ordering and queue accounting remain unchanged. + ## 2026-07-31 (Provider-Key Matrix Health Wait — Issue #1062) - Command intent: isolate and clear the hosted race blocker first observed on diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index 8243b280..bdb9aeae 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -2,6 +2,19 @@ Use this file for observations about system behavior without immediately prescribing code changes. +## 2026-07-31 (Runner Dispatcher Identity Under Parallel Load) + +- Aggregate observation: the original full-package race command reproduced the + reported 4/5 failure rate, while the same Runner's instance-owned wait group + completed normally. +- Identity observation: a function-name match in `runtime.Stack(all=true)` can + establish that some dispatcher exists, but cannot establish which Runner + owns it. Keeping a second Runner alive makes that ambiguity deterministic. +- Ordering observation: blocking the target dispatcher's final defer prevents + its wait-group completion and therefore prevents target `Shutdown` from + returning; releasing that exact hook permits return even while the control + dispatcher remains live. + ## 2026-07-31 (Source-Workflow Dual-Error Arbitration) - Process observation: a child can exit non-zero while closing its stdin also diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index 060153f4..bddf2934 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -1,5 +1,19 @@ # System Log +## 2026-07-31 (Runner Dispatcher Shutdown Identity) + +- System/component: bounded `internal/harness.Runner`, `poolDispatcher`, + `done`, and `dispatcherWG`. +- Ownership/order: each Runner closes only its own `done`; its dispatcher calls + an optional narrow test hook and then `dispatcherWG.Done`; Shutdown waits + that same instance wait group after inflight work is accounted for. +- Test boundary: one target Runner's hook supplies lifecycle identity while a + second control Runner remains live. Process-global stack inspection is used + only to prove the control still exists, never to classify target cleanup. +- 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 (Source-Workflow Terminal Error Arbitration) - System/component: `internal/workflow.SourceManager.runSourceWorkflow` and its diff --git a/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md b/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md new file mode 100644 index 00000000..58caa634 --- /dev/null +++ b/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md @@ -0,0 +1,86 @@ +# Cross-Surface Impact Map: Issue #1068 Dispatcher Shutdown Isolation + +## Task + +- Task / issue: GitHub #1068 +- Plan link: `2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md` +- Owner: isolated issue #1068 branch +- Status: implemented and locally verified; promotion pending + +## Current Ownership, Callers, and Data Flow + +- Entry points: `NewRunner` starts `poolDispatcher` when `WorkerPoolSize > 0`; + callers terminate it through `Runner.Shutdown`. +- Owning packages/types/functions and source of truth: `Runner.done` signals + exit and `Runner.dispatcherWG` is the instance-owned completion contract. +- Callers, consumers, events, and downstream data: daemon/app shutdown and + harness tests; no event or persisted-data flow changes. +- Similar abstractions searched: `inflight`, `shutdownOnce`, worker-pool tests, + and process-wide goroutine helpers in `runner_shutdown_test.go`. +- Search evidence: `rg -n "poolDispatcher|dispatcherWG|Shutdown|runnerGoroutineStackContains" internal/harness`. +- Duplication/ownership conclusion: the wait group already owns instance + completion; the global stack substring is a parallel and unsafe assertion. + +## Config, API, CLI, and Tools + +- User-facing config added or changed: none; `WorkerPoolSize` behavior is retained. +- Defaults / fallbacks: none changed. +- Environment variables, config files, or saved settings touched: none. +- Endpoints, request fields, response fields, or server wiring affected: none. +- CLI commands, tools, wire formats, or integrations affected: none. +- Error states / validation changes: none. + +## Persistence and Compatibility + +- Schemas, migrations, caches, generated data, or ownership changes: none. +- Backward/forward compatibility and versioning: shutdown remains idempotent + and preserves queue-drain and timeout behavior. +- Partial rollout and mixed-version behavior: not applicable; local lifecycle only. + +## Lifecycle, Security, and Reliability + +- Concurrency, cancellation, retries, cleanup, and resource ownership: primary + surface; target dispatcher completion must be distinguished from unrelated + Runner dispatchers while `done`, `inflight`, and `dispatcherWG` ordering stays intact. +- Authentication, authorization, permissions, trust, privacy, and secrets: + none; search found no auth or data boundary in this lifecycle path. +- Failure modes, recovery, idempotency, and data repair: guard against a false + leak report, a real lingering dispatcher, deadlock, or early return; no data repair. + +## Product and Integration Surfaces + +- Server/runtime: more trustworthy bounded Runner shutdown verification. +- TUI/web/macOS/other clients: no direct contract; app/daemon termination benefits indirectly. +- Provider/model/tool catalog and routing: none; no provider or catalog calls change. +- External systems and automation: GitHub race/full regression gates only. +- UX states, keyboard/focus/accessibility/motion: none; no UI code involved. + +## Deployment and Operations + +- Deployment/migration order and feature flags: separate PR; no migration or flag. +- Logs, metrics, traces, alerts, and support diagnostics: test failure identifies + target/control identity instead of a shared function name. +- Rollback triggers and recovery steps: revert if shutdown deadlocks, latency + regresses, or queue accounting fails. +- Runbooks and operator docs: no operator command changes. + +## Regression Tests + +- Characterization and first expected red test: two live bounded Runners prove + target instance exit while the old global scan remains positive. +- New acceptance tests required: `TestRunnerDispatcherShutdownIsInstanceScoped`. +- Edge, negative, failure, lifecycle, and security tests: existing queue drain, + active cancellation timeout, idempotent shutdown, and unbounded-mode tests. +- Integration/e2e/real-path proof: full harness package race stress and repository regression. +- Cross-surface regressions to guard: harness/server normal/race/vet. +- Exact targeted and full commands: issue #1068 verification plan, unchanged. + +## Documentation and Handoff + +- Specs/public docs before code: plan and impact map only; no public docs change. +- Implementation notes/logs/indexes after code: all four logs plus plans index and active plan. +- Training/onboarding/release notes: none; internal bug-fix PR evidence is sufficient. + +## Warning Check + +- Every impact heading is reconciled; `none` entries include the searched lifecycle rationale. diff --git a/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md b/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md new file mode 100644 index 00000000..de9d020b --- /dev/null +++ b/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md @@ -0,0 +1,85 @@ +# Issue #1068: Instance-Scoped Dispatcher Shutdown + +## Context + +- Governing GitHub issue: [#1068](https://github.com/dennisonbertram/go-code/issues/1068) +- Problem: the shutdown regression scans every process goroutine for the shared + `poolDispatcher` function name, so an unrelated live Runner can make a target + Runner look leaked after its own `Shutdown` has completed. +- User impact: the race gate can block independent changes and obscure a real + lifecycle leak. +- Constraints: strict red-green TDD; retain queue draining, cancellation, + idempotent shutdown, and the existing instance-owned wait-group contract; + do not touch PR #1060, PR #1055, or issue #1067. + +## Scope + +- In scope: reproduce the aggregate failure, add a deterministic two-Runner + control, make dispatcher lifecycle assertions instance-safe, and repair the + Runner seam only if the instance signal proves a runtime leak. +- Out of scope: worker-pool redesign, remote cron recovery, terminal event + publication, or generic goroutine accounting. + +## Documentation Contract + +- Feature status: `implemented` +- Public docs affected: none; no user-facing contract changes. +- Spec docs to update before code: this plan and its impact map. +- Implementation notes to add after code: engineering, observational, system, + and long-term-thinking logs. + +## Test Plan (TDD) + +- First red: a two-Runner regression keeps a control dispatcher live, shuts + down the target, proves the target's instance signal completed, and then + demonstrates that the old process-global substring assertion still reports + a dispatcher. +- Green contract: target `Shutdown` cannot return until the target dispatcher's + instance-owned exit signal completes; the control remains live until its own + cleanup. +- Stress: focused normal/race at `-count=100`, complete harness race at + `-count=5`, affected harness/server normal/race/vet, and unchanged foreground + non-TTY `./scripts/test-regression.sh`. + +## Cross-Surface Impact Map + +- See `2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md`. + +## Implementation Checklist + +- [x] Define acceptance criteria in tests. +- [x] Link a contract-complete structured GitHub issue before implementation. +- [x] Record current architecture, callers, consumers, and source-of-truth search evidence. +- [x] Document feature status and exact contract before code. +- [x] Complete and reconcile the cross-surface impact map before implementation. +- [x] Add characterization coverage before structural refactors (no structural refactor planned). +- [x] Write failing tests first. +- [x] Review ownership/copy semantics (no exported or copied mutable type changes). +- [x] Implement minimal code changes. +- [x] Refactor while tests remain green. +- [x] Update docs, status ledgers, and indexes. +- [x] Update engineering/system/observational logs as needed. +- [x] Run full test suite. +- [ ] Open a separate PR and leave it unmerged. + +## Verification Outcome + +- Red aggregate: `go test -race ./internal/harness -count=5` failed 4/5 + repetitions at the process-global post-Shutdown stack assertion. +- Red deterministic: the two-Runner control failed immediately when the old + assertion treated the live control dispatcher as the target's leak. +- Green focused: normal and race `-count=100` passed. +- Green aggregate: complete `internal/harness` race `-count=5` passed. +- Green affected: harness/server normal, race, and vet passed. +- Green repository: unchanged foreground non-TTY `./scripts/test-regression.sh` + passed at 85.6% total coverage with zero uncovered functions. + +## Risks and Mitigations + +- Risk: a test-only hook could become a second lifecycle source of truth. +- Mitigation: expose only a close-only signal tied to the same defer that calls + `dispatcherWG.Done`; `Shutdown` continues to own waiting through the existing + wait group. +- Risk: shutdown changes could deadlock queue draining or active-run timeout. +- Mitigation: preserve production ordering unless the deterministic instance + test proves it wrong, and rerun all existing shutdown/worker-pool regressions. diff --git a/docs/plans/INDEX.md b/docs/plans/INDEX.md index 948eea48..4e4177a2 100644 --- a/docs/plans/INDEX.md +++ b/docs/plans/INDEX.md @@ -1,5 +1,7 @@ # Plans Index +- `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-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 afccb67d..2c158abd 100644 --- a/docs/plans/active-plan.md +++ b/docs/plans/active-plan.md @@ -1,5 +1,11 @@ # Active Plan +Current status: Issue #1068 dispatcher shutdown isolation is implemented and +locally verified on a dedicated branch. The aggregate 4/5 red, deterministic +two-Runner red/green, focused stress, complete harness race x5, affected +normal/race/vet, and unchanged regression gate are recorded; separate PR and +hosted checks are pending. PR #1060, PR #1055, and issue #1067 remain excluded. + Current status: Issue #1023 anytime contextual `/feedback` intake is implemented test-first and verified in its isolated worktree; targeted, full normal/race, coverage-gate, and real TUI bundle checks pass, with merge pending. @@ -11,6 +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-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 388be4e9..f82640e0 100644 --- a/internal/harness/runner.go +++ b/internal/harness/runner.go @@ -339,6 +339,10 @@ type Runner struct { // poolDispatchHook is a test seam invoked after a queued item acquires a // worker token and before execute() is launched. poolDispatchHook func(queuedRun) + // poolDispatcherExitHook is a test seam invoked by the dispatcher goroutine + // immediately before it marks dispatcherWG done. It lets lifecycle tests + // identify one Runner without scanning process-global goroutine stacks. + poolDispatcherExitHook func() // 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 @@ -651,7 +655,12 @@ func (r *Runner) toolsForRun(runID string) *Registry { // r.inflight.Add(1) called by dispatchRun before enqueue, so we must call // r.inflight.Done() once per drained item to allow Shutdown's Wait to complete. func (r *Runner) poolDispatcher() { - defer r.dispatcherWG.Done() + defer func() { + if r.poolDispatcherExitHook != nil { + r.poolDispatcherExitHook() + } + r.dispatcherWG.Done() + }() for { if !r.poolDispatcherStep() { return diff --git a/internal/harness/runner_shutdown_test.go b/internal/harness/runner_shutdown_test.go index 3c0df988..a6dc07b9 100644 --- a/internal/harness/runner_shutdown_test.go +++ b/internal/harness/runner_shutdown_test.go @@ -229,29 +229,29 @@ func TestRunnerShutdownContinueRunRevertsSourceState(t *testing.T) { } } -// TestRunnerWithoutShutdownLeaksDispatcher is the control case: without -// Shutdown, the poolDispatcher goroutine stays alive, proving the stack-scan -// detector actually catches the parked goroutine. Shutdown is called at the -// end to clean up the test process so no goroutine leaks into other tests. -// -// Approach: poll the full goroutine stack dump (runtime.Stack(all=true)) for -// the "poolDispatcher" frame rather than relying on a fragile goroutine count, -// which is perturbed by the testing framework and the Go runtime itself. This -// is deterministic: the frame is present iff the goroutine is alive. -func TestRunnerWithoutShutdownLeaksDispatcher(t *testing.T) { - r := NewRunner(&shutdownStubProvider{}, nil, RunnerConfig{ +// TestRunnerDispatcherShutdownIsInstanceScoped keeps an unrelated bounded +// Runner alive while shutting down the target. This control makes a +// process-global poolDispatcher stack assertion deterministically expose its +// inability to identify which Runner owns the matching goroutine. +func TestRunnerDispatcherShutdownIsInstanceScoped(t *testing.T) { + target := NewRunner(&shutdownStubProvider{}, nil, RunnerConfig{ WorkerPoolSize: 4, DefaultModel: "gpt-4.1-mini", }) + targetAtExit := make(chan struct{}) + allowTargetExit := make(chan struct{}) + target.poolDispatcherExitHook = func() { + close(targetAtExit) + <-allowTargetExit + } + control := NewRunner(&shutdownStubProvider{}, nil, RunnerConfig{ + WorkerPoolSize: 4, + DefaultModel: "gpt-4.1-mini", + }) + t.Cleanup(func() { require.NoError(t, control.Shutdown(context.Background())) }) - // Run to terminal so the execute goroutine exits; only poolDispatcher stays. - run, err := r.StartRun(RunRequest{Prompt: "hello"}) - require.NoError(t, err) - _, err = collectRunEvents(t, r, run.ID) - require.NoError(t, err) - - // PART 1: assert that poolDispatcher is PRESENT before Shutdown. - // Poll up to 1 s for the goroutine to park in the select. + // Wait until at least one dispatcher is observable. The control remains live + // through the target assertion below. deadline := time.Now().Add(1 * time.Second) var present bool for time.Now().Before(deadline) { @@ -262,23 +262,32 @@ func TestRunnerWithoutShutdownLeaksDispatcher(t *testing.T) { time.Sleep(10 * time.Millisecond) } require.True(t, present, - "control assertion failed: poolDispatcher goroutine not found in stack dump before Shutdown; the leak detector would not catch a leak") + "control assertion failed: poolDispatcher goroutine not found before target Shutdown") - // PART 2: call Shutdown and assert that poolDispatcher is ABSENT afterwards. - require.NoError(t, r.Shutdown(context.Background())) + targetShutdown := make(chan error, 1) + go func() { targetShutdown <- target.Shutdown(context.Background()) }() - deadline = time.Now().Add(2 * time.Second) - var absent bool - for time.Now().Before(deadline) { - runtime.GC() - if !runnerGoroutineStackContains("poolDispatcher") { - absent = true - break - } - time.Sleep(20 * time.Millisecond) + select { + case <-targetAtExit: + case <-time.After(time.Second): + t.Fatal("target dispatcher did not reach its instance exit hook") + } + select { + case err := <-targetShutdown: + t.Fatalf("target Shutdown returned before its dispatcher exited: %v", err) + default: } - require.True(t, absent, - "poolDispatcher goroutine still present in stack dump after Shutdown; Shutdown did not clean it up") + + close(allowTargetExit) + select { + case err := <-targetShutdown: + require.NoError(t, err) + case <-time.After(time.Second): + t.Fatal("target Shutdown did not return after its dispatcher exited") + } + + require.True(t, runnerGoroutineStackContains("poolDispatcher"), + "live control Runner should demonstrate why process-global absence is not target identity") } // TestRunnerShutdownIdempotent verifies that calling Shutdown twice does not From e191ff16e42a2a15ab405485c85c566f7e1f7292 Mon Sep 17 00:00:00 2001 From: Dennison Date: Fri, 31 Jul 2026 18:07:39 +0200 Subject: [PATCH 2/2] Clean up bounded worker pool test runners --- docs/logs/engineering-log.md | 25 +++++-- docs/logs/long-term-thinking-log.md | 14 +++- docs/logs/observational-log.md | 8 +++ docs/logs/system-log.md | 4 ++ ...ispatcher-shutdown-isolation-impact-map.md | 15 ++-- ...1068-dispatcher-shutdown-isolation-plan.md | 33 +++++++-- docs/plans/active-plan.md | 12 ++-- internal/harness/runner_worker_pool_test.go | 71 ++++++++++++++++--- 8 files changed, 148 insertions(+), 34 deletions(-) diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index a9ea8520..123ff99e 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -5,23 +5,34 @@ - Symptom: `go test -race ./internal/harness -count=5` failed four of five repetitions because `TestRunnerWithoutShutdownLeaksDispatcher` found some `poolDispatcher` frame after its target Runner's `Shutdown` returned. -- Cause: the test scanned all goroutine stacks by shared function name. Other - parallel harness tests legitimately kept bounded Runners alive, so the - assertion had no target identity. The production path already closes the +- Cause: the test scanned all goroutine stacks by shared function name, so the + assertion had no target identity. Review then found a second defect: five + bounded construction sites in `runner_worker_pool_test.go` create seven + Runners per package repetition and omitted `Shutdown`, so their dispatchers + survived after their tests completed. The production path already closes a target's `done` channel and waits its `dispatcherWG` before returning. - TDD red: a deterministic two-Runner fixture kept a control Runner alive, shut down the target, and failed the old global-absence assertion immediately. +- Review TDD red: a bounded Runner returned from a subtest without its exact + dispatcher-exit hook firing; the parent then shut it down explicitly so the + red proof did not itself leak. - Fix: replace target lifecycle inference with a narrow per-Runner dispatcher exit hook invoked immediately before the existing `dispatcherWG.Done`. The test blocks that exact target hook, proves `Shutdown` cannot return, releases it, then proves Shutdown returns while the control's global stack frame remains visible. +- Review fix: a shared worker-pool test constructor now registers cleanup that + releases any blocked provider before calling bounded `Runner.Shutdown` with + a five-second diagnostic deadline. Every affected worker-pool fixture uses + that constructor; the cleanup regression itself blocks inside the provider + until cleanup establishes the required release-before-Shutdown ordering. - Compatibility: queue draining, inflight accounting, cancellation timeout, idempotency, and production shutdown ordering are unchanged. -- Verification: focused normal/race passed at `-count=100`; complete harness - race passed at `-count=5`; harness/server normal, race, and vet passed; and - unchanged foreground non-TTY `./scripts/test-regression.sh` passed at 85.6% - total coverage with zero uncovered functions. +- Verification: the cleanup regression passed normal/race; all worker-pool + tests passed normal/race at `-count=100`; complete harness race passed at + `-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 (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 5ecd49a2..8b6bcf45 100644 --- a/docs/logs/long-term-thinking-log.md +++ b/docs/logs/long-term-thinking-log.md @@ -15,11 +15,19 @@ - Next verification step: capture aggregate race red evidence, then add the deterministic instance-scoped test before changing production code. - Root-cause outcome: the exact aggregate command reproduced 4/5 failures and - the two-Runner red failed deterministically, classifying the defect as a - process-global test false positive rather than a runtime Runner leak. + the two-Runner red classified the target result as a process-global identity + false positive. Review found real adjacent test leaks as well: five bounded + worker-pool construction sites created seven Runners per repetition without + `Shutdown`, leaving dispatchers alive after those tests returned. - Implementation outcome: target exit identity now comes from a hook ordered immediately before the existing instance wait-group completion; production - shutdown ordering and queue accounting remain unchanged. + shutdown ordering and queue accounting remain unchanged. A shared bounded + test constructor releases blocked providers before Shutdown and owns cleanup + for every affected worker-pool fixture. +- Review-fix verification: deterministic cleanup normal/race, all worker-pool + 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 (Provider-Key Matrix Health Wait — Issue #1062) diff --git a/docs/logs/observational-log.md b/docs/logs/observational-log.md index bdb9aeae..69617900 100644 --- a/docs/logs/observational-log.md +++ b/docs/logs/observational-log.md @@ -7,6 +7,11 @@ Use this file for observations about system behavior without immediately prescri - Aggregate observation: the original full-package race command reproduced the reported 4/5 failure rate, while the same Runner's instance-owned wait group completed normally. +- Repetition observation: `go test -count=5` reuses one test process. Five + worker-pool construction sites created seven bounded Runners per repetition + without calling `Shutdown`; their dispatchers therefore outlived their tests + and contaminated later repetitions. They were real fixture leaks even though + they did not prove the target Runner leaked. - Identity observation: a function-name match in `runtime.Stack(all=true)` can establish that some dispatcher exists, but cannot establish which Runner owns it. Keeping a second Runner alive makes that ambiguity deterministic. @@ -14,6 +19,9 @@ Use this file for observations about system behavior without immediately prescri its wait-group completion and therefore prevents target `Shutdown` from returning; releasing that exact hook permits return even while the control dispatcher remains live. +- 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 (Source-Workflow Dual-Error Arbitration) diff --git a/docs/logs/system-log.md b/docs/logs/system-log.md index bddf2934..08dc4d65 100644 --- a/docs/logs/system-log.md +++ b/docs/logs/system-log.md @@ -10,6 +10,10 @@ - Test boundary: one target Runner's hook supplies lifecycle identity while a second control Runner remains live. Process-global stack inspection is used only to prove the control still exists, never to classify target cleanup. +- Worker-pool fixture boundary: the shared test constructor owns cleanup for + bounded test Runners. Its cleanup first releases provider gates, then calls + the public `Shutdown` boundary; this preserves the same production ownership + contract and prevents dispatchers surviving across `-count` repetitions. - Compatibility/failure modes: no API, config, persistence, client, provider, or tool contract changes; existing queue-drain, timeout, and idempotency behavior remains the rollback boundary. diff --git a/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md b/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md index 58caa634..585410db 100644 --- a/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md +++ b/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-impact-map.md @@ -5,7 +5,7 @@ - Task / issue: GitHub #1068 - Plan link: `2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md` - Owner: isolated issue #1068 branch -- Status: implemented and locally verified; promotion pending +- Status: review fix implemented and locally verified; promotion pending ## Current Ownership, Callers, and Data Flow @@ -20,6 +20,8 @@ - Search evidence: `rg -n "poolDispatcher|dispatcherWG|Shutdown|runnerGoroutineStackContains" internal/harness`. - Duplication/ownership conclusion: the wait group already owns instance completion; the global stack substring is a parallel and unsafe assertion. + Every bounded test fixture must also invoke the public `Shutdown` ownership + boundary instead of leaving its dispatcher alive after the test returns. ## Config, API, CLI, and Tools @@ -41,7 +43,9 @@ - Concurrency, cancellation, retries, cleanup, and resource ownership: primary surface; target dispatcher completion must be distinguished from unrelated - Runner dispatchers while `done`, `inflight`, and `dispatcherWG` ordering stays intact. + Runner dispatchers while `done`, `inflight`, and `dispatcherWG` ordering stays + intact. Worker-pool fixtures must release blocked providers before cleanup + calls `Shutdown`, including failure paths. - Authentication, authorization, permissions, trust, privacy, and secrets: none; search found no auth or data boundary in this lifecycle path. - Failure modes, recovery, idempotency, and data repair: guard against a false @@ -68,12 +72,15 @@ - Characterization and first expected red test: two live bounded Runners prove target instance exit while the old global scan remains positive. -- New acceptance tests required: `TestRunnerDispatcherShutdownIsInstanceScoped`. +- New acceptance tests required: `TestRunnerDispatcherShutdownIsInstanceScoped` + and `TestWorkerPoolTestRunnerCleanupStopsDispatcher`. - Edge, negative, failure, lifecycle, and security tests: existing queue drain, active cancellation timeout, idempotent shutdown, and unbounded-mode tests. - Integration/e2e/real-path proof: full harness package race stress and repository regression. - Cross-surface regressions to guard: harness/server normal/race/vet. -- Exact targeted and full commands: issue #1068 verification plan, unchanged. +- Exact targeted and full commands: cleanup regression normal/race, all + worker-pool tests normal/race at `-count=100`, complete harness race at + `-count=5`, harness vet, and the unchanged repository regression gate. ## Documentation and Handoff diff --git a/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md b/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md index de9d020b..8d5e277a 100644 --- a/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md +++ b/docs/plans/2026-07-31-issue-1068-dispatcher-shutdown-isolation-plan.md @@ -5,7 +5,10 @@ - Governing GitHub issue: [#1068](https://github.com/dennisonbertram/go-code/issues/1068) - Problem: the shutdown regression scans every process goroutine for the shared `poolDispatcher` function name, so an unrelated live Runner can make a target - Runner look leaked after its own `Shutdown` has completed. + Runner look leaked after its own `Shutdown` has completed. Review also proved + that five bounded worker-pool construction sites create seven Runners per + repetition and omit `Shutdown`, leaving real dispatchers alive across + `go test -count` repetitions. - User impact: the race gate can block independent changes and obscure a real lifecycle leak. - Constraints: strict red-green TDD; retain queue draining, cancellation, @@ -16,13 +19,15 @@ - In scope: reproduce the aggregate failure, add a deterministic two-Runner control, make dispatcher lifecycle assertions instance-safe, and repair the - Runner seam only if the instance signal proves a runtime leak. + Runner seam only if the instance signal proves a runtime leak; deterministically + prove and clean up every bounded worker-pool test fixture, releasing blocked + providers before shutdown. - Out of scope: worker-pool redesign, remote cron recovery, terminal event publication, or generic goroutine accounting. ## Documentation Contract -- Feature status: `implemented` +- Feature status: `implemented and locally verified; review-fix promotion pending` - Public docs affected: none; no user-facing contract changes. - Spec docs to update before code: this plan and its impact map. - Implementation notes to add after code: engineering, observational, system, @@ -34,6 +39,10 @@ down the target, proves the target's instance signal completed, and then demonstrates that the old process-global substring assertion still reports a dispatcher. +- Review red: a bounded Runner created inside a subtest must fire its exact + dispatcher-exit hook when fixture cleanup completes; before the shared + cleanup is added, the parent observes the dispatcher still live and then + explicitly shuts it down to keep the red itself leak-free. - Green contract: target `Shutdown` cannot return until the target dispatcher's instance-owned exit signal completes; the control remains live until its own cleanup. @@ -55,12 +64,12 @@ - [x] Add characterization coverage before structural refactors (no structural refactor planned). - [x] Write failing tests first. - [x] Review ownership/copy semantics (no exported or copied mutable type changes). -- [x] Implement minimal code changes. +- [x] Implement review-requested bounded-fixture cleanup. - [x] Refactor while tests remain green. - [x] Update docs, status ledgers, and indexes. - [x] Update engineering/system/observational logs as needed. -- [x] Run full test suite. -- [ ] Open a separate PR and leave it unmerged. +- [x] Rerun the full test suite for the review fix. +- [x] Update existing PR #1069 and leave it unmerged. ## Verification Outcome @@ -68,11 +77,23 @@ repetitions at the process-global post-Shutdown stack assertion. - Red deterministic: the two-Runner control failed immediately when the old assertion treated the live control dispatcher as the target's leak. +- Review finding: five pre-existing bounded construction sites in + `runner_worker_pool_test.go` created seven Runners per repetition and omitted + `Shutdown`; other bounded harness tests were audited and already own explicit + shutdown paths. +- Review red: `go test ./internal/harness -run + '^TestWorkerPoolTestRunnerCleanupStopsDispatcher$' -count=1` failed because + the bounded Runner's exact dispatcher-exit hook had not fired after subtest + cleanup; the test then explicitly released and shut down that Runner. +- Review green: the cleanup regression passed normal and race at `-count=1`; + all worker-pool tests passed normal and race at `-count=100`. - Green focused: normal and race `-count=100` passed. - Green aggregate: complete `internal/harness` race `-count=5` passed. - Green affected: harness/server normal, race, and vet passed. - Green repository: unchanged foreground non-TTY `./scripts/test-regression.sh` passed at 85.6% total coverage with zero uncovered functions. +- Promotion state: the review fix is committed locally for parent handoff; PR + #1069 remains open and unmerged, with no review-fix push performed here. ## Risks and Mitigations diff --git a/docs/plans/active-plan.md b/docs/plans/active-plan.md index 2c158abd..3b18253b 100644 --- a/docs/plans/active-plan.md +++ b/docs/plans/active-plan.md @@ -1,10 +1,12 @@ # Active Plan -Current status: Issue #1068 dispatcher shutdown isolation is implemented and -locally verified on a dedicated branch. The aggregate 4/5 red, deterministic -two-Runner red/green, focused stress, complete harness race x5, affected -normal/race/vet, and unchanged regression gate are recorded; separate PR and -hosted checks are pending. PR #1060, PR #1055, and issue #1067 remain excluded. +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 #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_worker_pool_test.go b/internal/harness/runner_worker_pool_test.go index fbd755fb..466677e8 100644 --- a/internal/harness/runner_worker_pool_test.go +++ b/internal/harness/runner_worker_pool_test.go @@ -97,6 +97,59 @@ func (p *seqRecordingProvider) Complete(_ context.Context, _ CompletionRequest) return CompletionResult{Content: "done"}, nil } +func newWorkerPoolTestRunner(t *testing.T, provider Provider, release func(), config RunnerConfig) *Runner { + t.Helper() + runner := NewRunner(provider, NewRegistry(), config) + t.Cleanup(func() { + if release != nil { + release() + } + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + if err := runner.Shutdown(ctx); err != nil { + t.Errorf("shutdown bounded worker-pool test Runner: %v", err) + } + }) + return runner +} + +func TestWorkerPoolTestRunnerCleanupStopsDispatcher(t *testing.T) { + dispatcherExited := make(chan struct{}) + var runner *Runner + provider := newCountingHeldProvider() + release := func() { + provider.releaseFirst() + provider.releaseRest() + } + + t.Run("bounded fixture", func(t *testing.T) { + runner = newWorkerPoolTestRunner(t, provider, release, RunnerConfig{ + DefaultModel: "gpt-4.1-mini", + WorkerPoolSize: 1, + }) + runner.poolDispatcherExitHook = func() { close(dispatcherExited) } + if _, err := runner.StartRun(RunRequest{Prompt: "blocked until cleanup"}); err != nil { + t.Fatalf("start blocked fixture run: %v", err) + } + select { + case <-provider.firstEntered: + case <-time.After(time.Second): + t.Fatal("blocked fixture run did not enter provider") + } + }) + + select { + case <-dispatcherExited: + return + default: + release() + if err := runner.Shutdown(context.Background()); err != nil { + t.Fatalf("clean leaked bounded Runner after red assertion: %v", err) + } + t.Fatal("bounded Runner dispatcher survived fixture cleanup because Shutdown was omitted") + } +} + // TestWorkerPool_QueuedStatusWhenPoolFull verifies that when more runs are // started than the pool size, the extras have RunStatusQueued. func TestWorkerPool_QueuedStatusWhenPoolFull(t *testing.T) { @@ -107,7 +160,7 @@ func TestWorkerPool_QueuedStatusWhenPoolFull(t *testing.T) { prov := newHeldProvider() - runner := NewRunner(prov, NewRegistry(), RunnerConfig{ + runner := newWorkerPoolTestRunner(t, prov, prov.unblockAll, RunnerConfig{ DefaultModel: "gpt-4.1-mini", MaxSteps: 1, WorkerPoolSize: poolSize, @@ -170,12 +223,12 @@ func TestWorkerPool_QueuedTransitionsToRunning(t *testing.T) { const poolSize = 1 prov := newCountingHeldProvider() - t.Cleanup(func() { + releaseProvider := func() { prov.releaseFirst() prov.releaseRest() - }) + } - runner := NewRunner(prov, NewRegistry(), RunnerConfig{ + runner := newWorkerPoolTestRunner(t, prov, releaseProvider, RunnerConfig{ DefaultModel: "gpt-4.1-mini", MaxSteps: 1, WorkerPoolSize: poolSize, @@ -230,7 +283,7 @@ func TestWorkerPool_ConfigurablePoolSize(t *testing.T) { total := poolSize + 2 prov := newHeldProvider() - runner := NewRunner(prov, NewRegistry(), RunnerConfig{ + runner := newWorkerPoolTestRunner(t, prov, prov.unblockAll, RunnerConfig{ DefaultModel: "gpt-4.1-mini", MaxSteps: 1, WorkerPoolSize: poolSize, @@ -339,7 +392,7 @@ func TestWorkerPool_PoolSize1Serializes(t *testing.T) { prov := newSeqRecordingProvider() - runner := NewRunner(prov, NewRegistry(), RunnerConfig{ + runner := newWorkerPoolTestRunner(t, prov, nil, RunnerConfig{ DefaultModel: "gpt-4.1-mini", MaxSteps: 1, WorkerPoolSize: 1, @@ -383,12 +436,12 @@ func TestWorkerPool_RunQueuedEventEmitted(t *testing.T) { t.Parallel() prov := newCountingHeldProvider() - t.Cleanup(func() { + releaseProvider := func() { prov.releaseFirst() prov.releaseRest() - }) + } - runner := NewRunner(prov, NewRegistry(), RunnerConfig{ + runner := newWorkerPoolTestRunner(t, prov, releaseProvider, RunnerConfig{ DefaultModel: "gpt-4.1-mini", MaxSteps: 1, WorkerPoolSize: 1,