diff --git a/BURNIN.md b/BURNIN.md index 5f0ef24..bef04eb 100644 --- a/BURNIN.md +++ b/BURNIN.md @@ -985,3 +985,111 @@ they are deliberately outside F20 and stay that way. Left running and untouched. Whatever it does from here is additional diagnostic evidence. Run 4 does not wait on it. + +## Run 4: failed conformance, 2026-08-27 + +Task `06G46P6KE25Y04VVF7VRZMHZ78`, issue `kami/test-e2e#4`, revision `1f5bf7e`. + +```text +run 4: failed conformance + +cause: +f25, claude rotationTick bypassed federatedTurn + +evidence: +phase-request.json existed +no WorkPhaseChanged followed +no boundary error was emitted + +additional defects: +f26 phase brief advertised invalid shortcut +f27 phase refusal was not delivered to agent +``` + +### What run 4 did prove + +The front half of the chain is clean, with no operator lifecycle intervention. + +| seq | at (UTC) | event | +|---|---|---| +| 370 | 13:11:29 | `TaskCreated` v1, 7 acceptance criteria | +| 371 | 13:11:30 | `TaskLeased` v2, epoch `06G46P6Q4EAPF7DFDBFBTA9RJC` | +| 372 | 13:11:33 | `TaskLaunchAcknowledged` v3 | + +Issue to confirmed launch: 4 seconds. F14 passes, against run 1 where ingest +set no acceptance at all. F15 and F17 pass again with +`confirmation=editor_cleared submit_attempts=1`. + +The agent wrote its request 25 seconds after launch: + +``` +/tmp/test-e2e-worktrees/06G46P6KE25Y04VVF7VRZMHZ78/.orchestra/phase-request.json +{"from": "frame", "to": "implement"} +``` + +The artifact half of F21 works. The reading half never ran. + +### F25, lifecycle: the turn boundary was unreachable on claude + +`rotationTick` returned early for this harness before reaching the boundary, +and `federatedTurn` has exactly one call site, below that return. + +```go +if w.harness == "claude" { + if err := w.advanceClaudeContextReset(ctx, id, s); err != nil { ... } + return +} +``` + +Introduced in `7f12c7f`. Consequences on the harness both burn-in runs used: +no phase request could ever be read, and **every human decision recorded +against a live claude session went undelivered**. + +This retracts an earlier claim in this ledger. F23's decisions do reach +`RemoteTurn`, but on claude the worker never asked, so run 3 had no +post-launch send path either. The statement that a comment on `#3` would have +produced a receipt was wrong. + +Fixed: claude runs the common boundary after its context reset. It still skips +the occupancy state machine, because it owns its own rollover. A turn boundary +is not a rotation. + +### F26, authority: the brief advertised an invalid shortcut + +The deployed brief rendered `Legal values for "to" from here: research, +implement`, listing every domain-legal move. The project's path allows only +`research`. The agent took the shortcut, reasonably. + +Fixed: the brief names one target and states that a wrong one comes back with +the right one. The project's path is Orchestra's to know. + +### F27, lifecycle: a refusal never reached the agent + +A refused request only reached `w.recordError`. The agent would rewrite the +same rejected file at every boundary with nothing telling it why, which is the +silent-loop shape this codebase keeps producing. + +Fixed: `federation.StatusError` makes a 409 classifiable. A refusal is +delivered through `sendPrompt`, so it travels under the F20 guarantee, and the +request file is cleared. A transport failure keeps the file and tells the agent +nothing, because it is not an answer. + +### Ledger + +``` +F6 closed +F14 closed +F15 closed by detection, transport fix pending live proof +F16 closed, both branches live-proven +F17 fixed, isolated live proof +F18 open observability, non-blocking +F19 fixed +F20 fixed, live proof still pending +F21 artifact half live-proven, reading half pending +F22 fixed, live proof pending +F23 closed as already implemented, undeliverable on claude until F25 +F24 open correctness, dormant on current topology +F25 fixed, tests only +F26 fixed, tests only +F27 fixed, tests only +``` diff --git a/cmd/orchestra-worker/main.go b/cmd/orchestra-worker/main.go index 4c5873f..3a7ef25 100644 --- a/cmd/orchestra-worker/main.go +++ b/cmd/orchestra-worker/main.go @@ -12,6 +12,7 @@ import ( "errors" "fmt" "log" + "net/http" "orchestra/internal/agentctx" "orchestra/internal/buildinfo" "orchestra/internal/continuity" @@ -609,6 +610,23 @@ func (w *worker) rotationTick(ctx context.Context, id string, s herdr.Session) { if err := w.advanceClaudeContextReset(ctx, id, s); err != nil { w.recordError(fmt.Errorf("Claude context reset %s: %w", id, err)) } + // A turn boundary is not a rotation. Claude owns its context rollover + // through the installed hook, which is why the occupancy state machine + // below is skipped, but phase requests and human decisions are carried + // at the boundary and returning here left both unreachable on this + // harness. Every decision recorded against a live Claude session went + // undelivered, and no phase request could ever be read. + t, ok := w.tasks[id] + if !ok { + w.recordError(fmt.Errorf("turn boundary %s: task cache missing", id)) + return + } + p, err := w.project(t) + if err != nil { + w.recordError(err) + return + } + w.federatedTurn(ctx, id, w.adapter(s, p.Remote), orchestrator.TurnContinue) return } t, ok := w.tasks[id] @@ -1727,6 +1745,22 @@ func (w *worker) rotateForPhase(ctx context.Context, id string, a herdr.Adapter, log.Printf("phase changed for %s: session rotating", id) } +// answerRefusedPhase tells the agent why its request was refused and drops the +// file so it can write a corrected one. The request survives a failed send, so +// the refusal is delivered at the next boundary instead of being lost. +func (w *worker) answerRefusedPhase(ctx context.Context, id string, s herdr.Session, path, reason string) { + text := "Orchestra refused your phase request: " + reason + + "\n\nWrite a corrected .orchestra/phase-request.json, or keep working in the current phase. Do not repeat the refused request." + if err := w.sendPrompt(ctx, s, text); err != nil { + w.recordError(fmt.Errorf("deliver phase refusal %s: %w", id, err)) + return + } + if err := os.Remove(path); err != nil { + w.recordError(fmt.Errorf("phase request %s: %w", id, err)) + } + log.Printf("phase request %s refused: %s", id, reason) +} + // requestPhase carries an agent's phase request to the coordinator (F21). // It reports whether the phase moved. // @@ -1786,6 +1820,15 @@ func (w *worker) requestPhase(ctx context.Context, id string, s herdr.Session) b phase, err := w.api.AdvancePhase(ctx, id, l.Epoch, op, req.From, req.To, artifact) if err != nil { w.recordError(fmt.Errorf("phase request %s: %w", id, err)) + // A refusal is an answer, and it names the phase the agent may ask + // for. Recording it only in worker health would leave the agent + // rewriting the same rejected file at every boundary with nothing + // telling it why, which is the silent-loop shape this codebase keeps + // producing. A transport failure is not an answer and is retried. + var status *federation.StatusError + if errors.As(err, &status) && status.Code == http.StatusConflict { + w.answerRefusedPhase(ctx, id, s, path, status.Body) + } return false } if phase == "" { diff --git a/cmd/orchestra-worker/phase_test.go b/cmd/orchestra-worker/phase_test.go index 9f9c459..d47fee3 100644 --- a/cmd/orchestra-worker/phase_test.go +++ b/cmd/orchestra-worker/phase_test.go @@ -199,29 +199,59 @@ func TestPhaseRequestRefusesAMalformedArtifact(t *testing.T) { } } -// A refused request keeps the pane's own state out of it: the file stays, so -// the same ask is retried under the same operation id once the reason clears. -func TestRefusedPhaseRequestIsRetried(t *testing.T) { - calls := 0 +// A refusal is an answer. The agent is told why, in the same confirmed +// delivery path every other Orchestra-originated input uses, and the request +// is cleared so it can write a corrected one instead of resending the same +// rejected file at every boundary. +func TestRefusedPhaseRequestIsAnsweredAndCleared(t *testing.T) { w, backend, wt, done := phaseWorker(t, func(rw http.ResponseWriter, r *http.Request) { - calls++ - if calls == 1 { - http.Error(rw, "conflict", http.StatusConflict) + if r.URL.Path == "/v1/federation/phase" { + http.Error(rw, "phase request refused: task may only move to \"research\", not \"implement\"", http.StatusConflict) return } - _ = json.NewEncoder(rw).Encode(map[string]string{"phase": "research"}) + rw.Write([]byte(`{"verdict":"continue"}`)) + }) + defer done() + writeRequest(t, wt, domain.WorkPhaseFrame, domain.WorkPhaseImplement) + + a := herdr.CLIAdapter{Backend: backend, Harness: "claude"} + w.federatedTurn(context.Background(), "task", a, "continue") + + if s := w.sessions["task"]; s.HandoffRequested { + t.Fatal("a refused request rotated the session") + } + if len(backend.prompts) == 0 || !strings.Contains(backend.prompts[0], `may only move to "research"`) { + t.Fatalf("the agent was not told why: %q", backend.prompts) + } + if _, err := os.Stat(filepath.Join(wt, ".orchestra", phaseRequestFile)); !os.IsNotExist(err) { + t.Fatal("the refused request survived, so the agent will resend it") + } +} + +// A coordinator that cannot be reached has not refused anything. Telling the +// agent its request was rejected would be a lie, and dropping the file would +// lose a request that is still valid. +func TestTransientPhaseFailureKeepsTheRequest(t *testing.T) { + w, backend, wt, done := phaseWorker(t, func(rw http.ResponseWriter, r *http.Request) { + if r.URL.Path == "/v1/federation/phase" { + http.Error(rw, "upstream down", http.StatusServiceUnavailable) + return + } + rw.Write([]byte(`{"verdict":"continue"}`)) }) defer done() writeRequest(t, wt, domain.WorkPhaseFrame, domain.WorkPhaseResearch) - a := herdr.CLIAdapter{Backend: backend, Harness: "claude"} + a := herdr.CLIAdapter{Backend: backend, Harness: "claude"} w.federatedTurn(context.Background(), "task", a, "continue") + if _, err := os.Stat(filepath.Join(wt, ".orchestra", phaseRequestFile)); err != nil { - t.Fatal("a refused request must survive for the retry") + t.Fatal("a transient failure discarded the request") } - w.federatedTurn(context.Background(), "task", a, "continue") - if s := w.sessions["task"]; !s.HandoffRequested { - t.Fatalf("the retry did not advance the phase: %+v", s) + for _, p := range backend.prompts { + if strings.Contains(p, "refused") { + t.Fatalf("a transient failure was reported to the agent as a refusal: %q", p) + } } } @@ -290,3 +320,42 @@ func TestDecisionNoticeStaysUndeliveredUntilConfirmed(t *testing.T) { t.Fatalf("sends = %d, want the correction retried once", len(backend.prompts)) } } + +// The bug that made run 4 stall exactly like run 3. rotationTick returned +// early for the claude harness before reaching the turn boundary, so +// federatedTurn had one call site that this harness never took. Phase requests +// were never read and human decisions were never delivered on the harness both +// burn-in runs actually used. +// +// Claude still skips the occupancy state machine below that branch, because it +// owns its own context rollover. A turn boundary is not a rotation. +func TestClaudeHarnessReachesTheTurnBoundary(t *testing.T) { + reached := make(chan string, 4) + w, backend, wt, done := phaseWorker(t, func(rw http.ResponseWriter, r *http.Request) { + reached <- r.URL.Path + if r.URL.Path == "/v1/federation/phase" { + _ = json.NewEncoder(rw).Encode(map[string]string{"phase": "research"}) + return + } + rw.Write([]byte(`{"verdict":"continue"}`)) + }) + defer done() + writeRequest(t, wt, domain.WorkPhaseFrame, domain.WorkPhaseResearch) + + // rotationTick, not federatedTurn: the dead path was the route in. + w.rotationTick(context.Background(), "task", w.sessions["task"]) + + var saw bool + for len(reached) > 0 { + if <-reached == "/v1/federation/phase" { + saw = true + } + } + if !saw { + t.Fatal("the claude harness never reached the phase boundary") + } + if s := w.sessions["task"]; !s.HandoffRequested || s.HandoffReason != "phase_changed" { + t.Fatalf("session did not rotate: %+v", s) + } + _ = backend +} diff --git a/internal/agentctx/agentctx.go b/internal/agentctx/agentctx.go index 12261af..72faf29 100644 --- a/internal/agentctx/agentctx.go +++ b/internal/agentctx/agentctx.go @@ -117,13 +117,12 @@ func phaseRequestBrief(phase domain.WorkPhase) string { var b strings.Builder b.WriteString("\nAsk by writing .orchestra/phase-request.json at the end of a turn:\n\n") fmt.Fprintf(&b, " {\"from\": %q, \"to\": %q}\n", string(phase), string(next[0])) - if len(next) > 1 { - var names []string - for _, p := range next { - names = append(names, string(p)) - } - fmt.Fprintf(&b, "\nLegal values for \"to\" from here: %s. This project may allow fewer, and a request outside its path is refused with the phase you may ask for.\n", strings.Join(names, ", ")) - } + // Only one target is named. Listing every domain-legal move invited the + // agent to skip ahead: run 4's frame session read "research, implement" + // and asked for implement, which the project's path refuses. The path is + // Orchestra's to know, so the brief states one step and says a wrong + // target comes back with the right one. + b.WriteString("\nAsk for one step. A request the project's path does not allow is refused, and the refusal names the phase you may ask for.\n") if artifact := phaseSealFile[phase]; artifact != "" { fmt.Fprintf(&b, "\nSeal .orchestra/%s before you ask. The request is refused without it.\n", artifact) } diff --git a/internal/federation/client.go b/internal/federation/client.go index ddc17ff..4d89572 100644 --- a/internal/federation/client.go +++ b/internal/federation/client.go @@ -81,11 +81,23 @@ func (c Client) request(ctx context.Context, method, path string, body any) (*ht if resp.StatusCode/100 != 2 { defer resp.Body.Close() b, _ := io.ReadAll(resp.Body) - return nil, fmt.Errorf("federation: %s: %s", resp.Status, strings.TrimSpace(string(b))) + return nil, &StatusError{Code: resp.StatusCode, Status: resp.Status, Body: strings.TrimSpace(string(b))} } return resp, nil } +// StatusError is a coordinator answer the caller can classify. A refusal is +// the agent's mistake and has to reach the agent; a transport failure is not, +// and must not be reported to it as one. The message keeps the previous +// wording so callers that match on it still work. +type StatusError struct { + Code int + Status string + Body string +} + +func (e *StatusError) Error() string { return fmt.Sprintf("federation: %s: %s", e.Status, e.Body) } + func (c Client) Events(ctx context.Context, since uint64) ([]domain.Event, uint64, error) { resp, err := c.request(ctx, http.MethodGet, "/v1/federation/events?since="+fmt.Sprint(since), nil) if err != nil {