14 Commits

Author SHA1 Message Date
kami f25964c18e Record slice B as proven with two unexercised branches
Neither will be manufactured: a second task hitting the same failure
exercises the eligibility transition, and a genuine repair exercises manual
intervention provenance.

Also records why the reasons check earned its place. An inference drawn
from aggregate numbers was wrong, and the pure explanation contradicted it
with counted facts.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 14:57:43 +04:00
kami 0aefe021b0 Explain a debt refusal with facts about the item
Reasons are the auditable explanation of a pure decision, so one that
describes the architecture rots the moment the architecture moves. The
operational refusal asserted that manual interventions were recorded by no
event type: true when written, false the day OperatorInterventionRecorded
landed, and still printed under every refusal after that.

It now reports the counts and the thresholds they missed. Why a count is
zero is not this function's business, since no intervention happening, none
being recorded, and none being migrated all read the same from here.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 14:57:25 +04:00
kami 982741fe97 Say which operator actions are debt and which are just operations
An intervention is an action required to recover, repair, unblock or correct
behaviour that should have proceeded on its own. A deploy restart, a planned
upgrade and burn-in setup are none of those, and recording them would inflate
operator cost with work Orchestra is expected to need.

Policy rather than schema. worker_restart is the one kind that spans both
sides, and it stays one kind until someone actually misuses it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 14:29:17 +04:00
kami 42c5f07844 Write down the rule both slice B defects broke
A projection must never manufacture provenance to make evidence easier to
classify. task=None is better than a confident lie.

Also records that signatures are frozen at write time, so an old event never
changes meaning because normalization code changed. Repairing historical
signatures is an explicit migration, not a different projection result from
the same log.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 14:23:41 +04:00
kami 79d20534b5 Stop the ring's history from manufacturing recurrence
Both defects came from the first real run of slice B against live data, and
neither was visible in a unit test written from the design.

The ring is a bounded history, not a set of live conditions. A quiet timeout
closed an incident, its entry stayed in the ring because nothing evicts it,
and every later heartbeat opened the same incident again: three signatures,
four incidents each, from failures that never happened twice. An incident
now opens only when the entry actually advances past what was already
accounted, and the high-water mark survives the close.

The ring also outlives the work it describes, so attributing its entries to
whatever the worker is running now invented an association. The task is read
out of the message, and only a failure that names no task belongs to the
current lease. An incident that names an older task has no live lease to
bound it, so it closes on quiet timeout rather than on the next epoch change.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 14:20:47 +04:00
kami 74cad5d374 Collapse a pane name's task id in an observation signature
The ledger's first live run showed it: a pane name carries the task id in
lower case, so "phase rotation ...: pane orchestra-<task>-<sha>:1.0 still
holds input" signed differently on every task and could never accumulate
recurrence across them. The id pattern is case-insensitive now.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 06:55:51 +04:00
kami e0601296e0 Record what an operator repaired, and let debt count incidents
Slice B, second half. OperatorInterventionRecorded is the one command for
saying "I fixed this by hand": a manual repair happens outside Orchestra by
definition, so the only honest way to have the evidence is for the person
who made it to state it. Inferring "an operator probably intervened" from a
gap would put guesses into the record the ledger is built from.

The debt projection now consumes both new kinds. A closed incident is one
observation carrying its repeat count as intensity, so recurrence stays a
count of independent incidents: 301 repeats on one lease and 2 on another
is a recurrence of two with an intensity of 303, not a recurrence of 303.

Both kinds were previously reported as holes in the system. They are
ordinary evidence now, so their absence from a history is a fact about that
history, and the gap list says so.

The worker also stamps a per-process incarnation on registration and every
heartbeat. Nothing else on the wire distinguishes a restarted worker from a
running one, and an incident cannot outlive the process that reported it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 06:53:26 +04:00
kami 438c1d6df3 Make worker observations durable as incidents, not as symptoms
Slice B, first half. The F18 ring is bounded, lossy and local, so the debt
ledger reported it as a gap about itself. Two events make it durable:
ObservationIncidentOpened at first sight, appended immediately so a
coordinator that dies mid-incident still leaves the fact that it existed,
and ObservationIncidentClosed carrying the aggregate.

The rules are what matter. Repeats update the aggregate and append nothing,
because run 11's 409 loop was one incident with an intensity of 301 rather
than 301 pieces of evidence. Absence from the ring closes nothing, since a
bounded history evicts as easily as it recovers. An incident is scoped to
its lease and closes on lease end, epoch change, worker restart, or, for
observations with no lease to bound them, on last_seen going stale. A ring
entry that is evicted and recreated accumulates: 34 then 3 is 37.

Also collapses three drifted copies of the list of events that carry no
task into one predicate. Adding a type to two of them left it rejected by
the third, which is how the first version of this failed.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 06:35:17 +04:00
kami 76da8c40b7 End the implementer's trajectory when Orchestra reopens the phase
Run 20 showed the leak precisely: the reopen rotated the session, and 31
seconds later the planning session that replaced it recorded phase-2 of the
plan being replaced. The implementer's .orchestra/plan-progress.json had
outlived it in the worktree, and the successor executed it.

Two changes. Phase verification now belongs to the implement phase and is
refused anywhere else, which covers every worker and every path rather than
the one that produced it. The rotation also drops the ended session's
request files, so a successor never inherits work from a trajectory
Orchestra has already invalidated.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-30 05:46:11 +04:00
kami 575e3ef87e Record run 21: F66 proven, and why round one did not count
The first fix wrote the projection and lost it at the rotation the reopen
causes, so the planner still got nothing. Both rounds passed their unit
tests; what separated them was where the assertion sat in the sequence.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-29 22:03:51 +04:00
kami 75396963ef Keep the contradiction alive across the rotation the reopen causes
The clearing rule sat below the reducer switch, so it ran for every event
rather than for the correction it was written for. TaskReleased found the
task unblocked and erased the contradiction, which is the rotation the
reopen itself causes: the planning session launched one lease later and was
told nothing again.

Scoped to TaskCorrected, and the store test walks the real sequence
(mismatch, reopen, release, lease) rather than reading the projection at
the moment it is written.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-29 21:05:01 +04:00
kami edf00761fd Tell the planner what it was convened to fix
F66, found live on run 20. A replan reopens the plan phase and the session
it convenes was given the ordinary plan brief and an empty template: no
mention that a plan already exists, what contradicted it, which phase, what
evidence, or that its output supersedes an accepted plan. All of it was
already durable on PlanMismatchRecorded and none of it reached the agent,
so nothing stopped the replacement from sealing with the same
contradiction in it.

The contradiction is now projected onto the task and rendered above the
sealed artifacts, because it changes how they should be read. Its lifetime
is bounded at both ends: a sealed replacement answers it, and so does a
human reply to the stop it caused. Only the phases a mismatch can reopen
render it, since an implementer looks at the code rather than at an account
of the last contradiction.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-29 20:47:44 +04:00
kami 1330ad9943 Stop reporting a blocker the task is no longer blocked on
F67. TaskCorrected cleared the standing question when a task resumed and
left Blocker and BlockReason in place, so task 29 ran through implement,
review and submission still reporting block_reason plan_mismatch. Every
surface that reads the projection rather than the event log showed a stop
that had already been answered.

The blocker has the same lifetime as the question beside it, and is now
cleared with it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-29 20:41:36 +04:00
kami cb80dd1952 Record run 20: the mismatch and replan ladder holds, and F66
Both halves proven live. A human_decision mismatch stops the task, the
blocker packet states the contradiction, and a Gitea reply resumes the same
plan in 55 seconds with no reseal. A replan reopens into plan while the old
plan stays accepted with its progress, and sealing the replacement moves
plan_ref, retains the old one in history, stops the old progress counting,
and hands the successor the replacement whole.

F66 recorded: the planning session a replan convenes is told nothing about
the contradiction it exists to fix, though all of it is durable.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01CVbaKucEYBjMqVeUgJUsc1
2026-08-29 20:39:04 +04:00
24 changed files with 1744 additions and 37 deletions
+168
View File
@@ -2848,3 +2848,171 @@ unchanged.
"ready_for_verification"}`. It is the whole lever for this rung.
- Ingest turns every issue label into a required capability, so a rig issue
must carry no labels or it will not schedule.
## Run 20, 2026-08-29: the mismatch and replan ladder, and three defects
Task `06G4WJ9T4F35NZC4Z8QQXM9Z6G` (issue 29) on `de18f37`, plus a first attempt
on `06G4WDJ06G7FK00QF73Z9DDBT4` (issue 27) on `c587f2c` that found F65.
The lever throughout is the agent's own file, written by the operator with the
worker stopped: `.orchestra/plan-mismatch.json`, carrying `phase_id`,
`observed`, `contradicts`, `evidence` and `requested_action`. The worker fills
`plan_ref` and `at_sha` from what it can verify, never from the file.
### F65: a task that stops for a human never stopped
Found on the first attempt, live:
```text
16:04:25 PlanMismatchRecorded phase-2 human_decision
16:04:25 worker: plan mismatch refused: task version conflict
16:04:48 PlanPhaseVerified phase-1 work continues as if nothing happened
```
`Store.Append` fences every lifecycle event on a leased task against the
current owner and epoch. `blockForPlanMismatch` carried neither `harness_id`
nor `lease_epoch`, so the block was refused on every task that was actually
running, which is every task that can produce a mismatch. The observation was
durable and the transition silently did not happen: the repo's own documented
failure shape. `raiseTrajectoryGate` had the identical omission, so the
trajectory gate could never have stopped a live task either.
`RecordPlanMismatch` also returns that error after the record is already
appended, so the worker told the agent its report was refused for a report
Orchestra had accepted.
Fixed in `de18f37` with one `fenceToLease` helper, called by all three stops.
The human-decision path already did it correctly and explained why in a
comment; that comment is now the helper.
**Why no test caught it.** `planWith` never leased its task, so every
plan-progress and plan-mismatch test ran in a state no agent can be in. The
`lease` helper in the same package carries a comment warning about exactly
that. It leases now, and the mismatch block test fails without the fence with
the same `task version conflict`.
### Proven: human_decision stops, and the reply resumes the same plan
```text
16:24:21 PlanMismatchRecorded phase-2 human_decision
16:24:21 TaskBlocked plan_mismatch, lifecycle awaiting_human
18:24:46 HumanDecisionRecorded operator_instruction (Gitea's timestamp)
16:25:16 TaskCorrected resumed
16:25:16 TaskLeased plan_ref unchanged at 0bc8ef84
16:25:21 TaskPickupValidated
```
55 seconds from block to resumed, on the same plan, with no reseal. The
blocker packet states the observation, the plan's claim and the evidence.
This is also the live proof of F64: before `6cb2f93` nothing read a blocked
task's comments, because the reconciler ran only before a lease and at a turn
boundary, and a blocked task is never leased.
### Proven: replan keeps the old plan until a replacement seals
```text
16:26:07 PlanMismatchRecorded phase-3 replan
16:26:07 WorkPhaseChanged plan reopen=PlanMismatchRecorded
during planning: plan_ref 0bc8ef84 accepted, phase-1 and phase-2 counted
after the seal:
plan_ref 922f293b
plan_history [0bc8ef84]
progress empty
successor in implement: four phases, all "not started"
```
The successor's launch context carries the replacement whole, with files,
changes and verification per phase. The old progress stops counting because
`PlanPhases()` drops records whose plan ref is not the accepted one. An
abandoned replan would have cost nothing.
### F66: the planner replans blind
The planning session convened by a replan is given the ordinary plan brief and
an empty template. Its launch context says nothing about the plan that already
exists, the contradiction that reopened the phase, the phase id, the evidence,
or the fact that its output supersedes an accepted plan. The only human input
it carried was an unrelated earlier correction.
Everything it needs is already durable. `PlanMismatchRecorded` holds the phase,
the observation, the contradiction and the evidence, and `reopenPhase` writes
`reopen_phase_id` onto the `WorkPhaseChanged` payload. None of it reaches the
agent, so nothing stops the replacement from sealing with the same
contradiction in it.
### Smaller observation
The implement session kept working after the reopen. It verified phase-2
against the old plan 40 seconds after the task had moved to `plan`. Harmless,
because supersession discards it, but the reopen does not end the session that
reported the contradiction. That session rotates at its own next boundary.
## Run 21, 2026-08-29: F66 proven, in two rounds
Tasks `06G4WW6TND26M16CZA6WE5T458` (issue 32, on `edf0076`) and
`06G4XAFH1MBPC35VSJN7V3NS14` (issue 34, on `7539696`).
### Round one failed, and the failure was in the fix
`edf0076` projected the contradiction onto the task and rendered it into the
plan-phase context. The projection appeared at the reopen and was gone before
the planning session launched:
```text
16:58:01 PlanMismatchRecorded phase-2 replan, plan reopened
projection carries the contradiction
16:58:20 TaskReleased the rotation the reopen causes
projection empty
16:59:29 replacement sealed, planner never told anything
```
The clearing rule added with F67 sits **below** the reducer switch, so it runs
for every event rather than for the correction it was written for. A release
found the task unblocked and erased the contradiction. Two mistakes made it:
the rule was written as if it were inside `case "TaskCorrected"`, which is
merely the nearest case above it, and the unit test read the projection at the
moment it was written rather than at the moment the planner reads it.
`7539696` scopes the clear to `TaskCorrected`, and the store test now walks the
real sequence: mismatch, reopen, release, lease, then assert.
### Round two: the planner is told what it was convened to fix
```text
18:00:17 PlanMismatchRecorded phase-2 replan, plan reopened
projection survives the rotation
18:01:02 planning session launches
```
From that session's `.orchestra/launch.md`:
```text
## Why this phase reopened
A plan was already accepted and the code contradicted it. Orchestra reopened
this phase to settle that, and the session that found it is gone.
- phase: phase-2
- observed: The summary lines are printed from the recorded results after
every check has run, ...
- the plan says: The plan states that phase 2 prints the header from a helper
that returns the number of checks about to run.
- evidence: scripts/orchestra_e2e_healthcheck.sh:1
The accepted plan stays accepted until you seal a replacement, and sealing one
supersedes it along with every phase it had verified. Address the
contradiction above: a replacement that repeats it will be contradicted again.
```
It renders above the sealed research and plan, because it changes how they
should be read. The first planning session of a task carries no such section,
and neither does implement. Sealing the replacement (`2edcbe9e`) cleared the
projection, which is the other end of its lifetime.
### The lesson worth keeping
Both rounds of this fix passed their unit tests. What separated them was where
the assertion sat in the sequence. A projection written correctly and read one
rotation later is not the same claim, and only the live run put the read where
the agent does.
+110
View File
@@ -408,3 +408,113 @@ which is the priority function slice one deliberately omitted.
None of these required a schema commitment to discover. That was the point of
making the first slice read-only.
## The invariant slice B was written against
**A projection must never manufacture provenance to make evidence easier to
classify.** `task=None` is better than a confident lie.
Both defects the first live run of durable observations exposed were failures
of exactly this rule, and both looked perfectly reasonable in code:
- **False attribution.** The worker's ring outlives the work it describes, so
binding its entries to whatever task the worker is running now produced a
clean, well-formed, wrong association between an old failure and an unrelated
task. The task is read from the observation itself, and only an observation
that names no task belongs to the current lease.
- **Manufactured recurrence.** Treating "still present in the ring" as "it
happened again" turned one failure into four incidents. Presence is not
occurrence: an incident opens only when the entry advances past what has
already been accounted for, and that high-water mark survives the close.
Either one would have corrupted the ledger while every number in it stayed
plausible, which is the specific way this repo's bugs have always presented.
## Signatures are frozen at write time
The signature is computed when an incident is recorded and stored in the event.
Re-projecting an old log with a newer normalizer therefore changes nothing:
running one history through the build before and after the pane-name fix
produced identical output.
That is the intended behavior. An event must not silently change meaning
because normalization code changed. Repairing historical signatures is an
explicit migration or reclassification event, never a different projection
result from the same log.
## What counts as a manual intervention
An intervention is an operator action required to recover, repair, unblock or
correct behaviour that should otherwise have proceeded autonomously. The
ledger measures what the system costs to keep running, so routine operation
does not belong in it.
Counts:
```text
transaction_cleanup
forced_release
state_repair
manual_requeue when recovery failed and a human had to requeue
manual_phase_recovery
worker_restart only when restarting is itself the repair
```
Does not count:
```text
deploy restart
planned upgrade
configuration rollout
normal shutdown and start
deliberate burn-in setup
```
The distinction is policy rather than schema. `worker_restart` is the one kind
that spans both sides, and it stays a single kind until someone actually
misuses it; a field added before the confusion exists is a guess about how it
will be misread.
The first live consequence: the deploy restart of `79d2053` was not recorded,
and `manual_intervention` stayed in the gap list afterwards. That is the
correct result. Orchestra can record the evidence and this history contains
none, which is an honest gap rather than synthetic evidence.
## Slice B status, 2026-08-30
```text
worker observation durability proven live
incident open/close semantics proven live
high-water, no phantom recurrence proven live
task attribution proven live
frozen historical provenance proven live
eligibility calculation proven against real data
eligibility transition unexercised
manual intervention recording implemented
manual intervention provenance unexercised
```
Neither unexercised branch will be manufactured. A second task hitting the
same failure exercises the first, and a genuine repair exercises the second.
The proof that matters from the live run:
```text
recurrence 5, intensity 10, distinct tasks 1, interventions 0 -> eligible=false
```
A noisy failure inside one task does not become system-level maintenance debt.
The three counts stay separate on purpose: recurrence is how often the incident
happened, intensity is how repetitive each incident became, and breadth is how
many independent tasks paid for it. Operational debt requires breadth unless an
operator had to intervene.
### The reasons check is part of the design, not a formality
The aggregate numbers moved in a way that looked like a promotion, and reading
them that way was wrong: the eligible count rose because of an unrelated item.
The pure eligibility explanation contradicted that inference with counted
facts. That is the argument for the ledger resting on mechanically derived
evidence rather than on anyone's reading of what looks recurring, including an
agent's.
+56
View File
@@ -0,0 +1,56 @@
// Runs the debt projection over a captured event log and prints one row per
// item, so two builds can be compared on identical input. The point of the
// comparison is the signature fix: cross-task incidents must collapse into one
// item while genuinely different failures stay separate.
package main
import (
"encoding/json"
"fmt"
"os"
"sort"
"orchestra/internal/domain"
"orchestra/internal/operations"
"orchestra/internal/store"
)
func main() {
b, err := os.ReadFile(os.Args[1])
if err != nil {
panic(err)
}
var events []domain.Event
if err := json.Unmarshal(b, &events); err != nil {
panic(err)
}
ledger := store.ProjectDebt(events)
eligible := map[string]operations.DebtCandidate{}
for _, c := range operations.EligibleDebt(ledger) {
eligible[c.Item.ID] = c
}
rows := make([]map[string]any, 0, len(ledger.Items))
for _, item := range ledger.Items {
tasks := map[string]bool{}
intensity := 0
for _, o := range item.Observations {
if o.TaskID != "" {
tasks[o.TaskID] = true
}
intensity += o.Repeats
}
row := map[string]any{
"signature": item.ID, "class": string(item.Class),
"recurrence": len(item.Observations), "intensity": intensity,
"tasks": len(tasks), "eligible": false, "reasons": []string{},
}
check := operations.CheckDebtEligibility(item)
row["eligible"] = check.Eligible
row["reasons"] = check.Reasons
_ = eligible
rows = append(rows, row)
}
sort.Slice(rows, func(i, j int) bool { return rows[i]["signature"].(string) < rows[j]["signature"].(string) })
out, _ := json.MarshalIndent(map[string]any{"items": rows, "gaps": ledger.Gaps}, "", " ")
fmt.Println(string(out))
}
+16 -2
View File
@@ -103,8 +103,13 @@ func (w *worker) recordError(err error) {
w.observations = append(w.observations, federation.Observation{Message: msg, Count: 1, First: now, Last: now})
}
// workerIncarnation identifies this process. A restarted worker cannot
// continue the previous process's failures, and nothing else on the wire says
// a restart happened: build revision and worker id both survive it.
var workerIncarnation = domain.NewID()
func (w *worker) health(ctx context.Context) federation.WorkerHealth {
h := federation.WorkerHealth{HerdrStatus: "unknown"}
h := federation.WorkerHealth{HerdrStatus: "unknown", Incarnation: workerIncarnation}
if backend := w.executionBackend(); backend != nil {
h.Backend = backend.Kind()
}
@@ -1884,7 +1889,7 @@ func main() {
window: window,
// Capacity stays one per identity because a herdr's declared
// concurrency is one. Serving N harnesses gives the process N slots.
registration: federation.Worker{ID: spec.ID, Address: spec.Address, Capacity: 1, SupportedProjects: supported, Build: buildinfo.Current()},
registration: federation.Worker{ID: spec.ID, Address: spec.Address, Capacity: 1, SupportedProjects: supported, Build: buildinfo.Current(), Incarnation: workerIncarnation},
}
if w.registration.Address == "" {
w.registration.Address = os.Getenv("ORCHESTRA_WORKER_ADDRESS")
@@ -2089,6 +2094,15 @@ func (w *worker) rotateForPhase(ctx context.Context, id string, a herdr.Adapter,
s.HandoffRequested, s.HandoffReason, s.HandoffRequestedAt = true, "phase_changed", time.Now().UTC()
w.sessions[id] = s
_ = w.save()
// A request belongs to the session that wrote it. Both files sit in the
// worktree, which outlives the session, so a successor in a different
// phase would find and execute them: that is how a reopened planning
// session verified a phase of the plan it was replacing.
for _, name := range []string{planProgressFile, phaseRequestFile} {
if err := os.Remove(filepath.Join(s.Worktree, ".orchestra", name)); err != nil && !os.IsNotExist(err) {
w.recordError(fmt.Errorf("phase rotation %s: drop %s: %w", id, name, err))
}
}
log.Printf("phase changed for %s: session rotating", id)
}
+29
View File
@@ -457,3 +457,32 @@ func TestPlanVerificationRunsThePlansCommandsAndReportsExitCodes(t *testing.T) {
t.Fatalf("the outcome was not delivered: %v", backend.prompts)
}
}
// A request belongs to the session that wrote it. The worktree outlives the
// session, so a rotation that leaves these files behind hands them to a
// successor running in a different phase (run 20).
func TestRotationDropsTheEndedSessionsRequests(t *testing.T) {
w, backend, wt, done := phaseWorker(t, func(rw http.ResponseWriter, r *http.Request) {
rw.Write([]byte(`{}`))
})
defer done()
progress := filepath.Join(wt, ".orchestra", planProgressFile)
request := filepath.Join(wt, ".orchestra", phaseRequestFile)
for _, p := range []string{progress, request} {
if err := os.WriteFile(p, []byte(`{"phase":"phase-1","status":"ready_for_verification"}`), 0o644); err != nil {
t.Fatal(err)
}
}
a := herdr.CLIAdapter{Backend: backend, Harness: "claude"}
w.rotateForPhase(context.Background(), "task", a, w.sessions["task"])
for _, p := range []string{progress, request} {
if _, err := os.Stat(p); !os.IsNotExist(err) {
t.Fatalf("%s survived the rotation that ended the session that wrote it", filepath.Base(p))
}
}
if s := w.sessions["task"]; !s.HandoffRequested || s.HandoffReason != "phase_changed" {
t.Fatalf("the session was not rotated: %+v", s)
}
}
+69
View File
@@ -228,6 +228,9 @@ func main() {
// Pull-request readers by source name, for reflecting submitted work.
pullRequests := map[string]human.PullRequestSource{}
localMachine := os.Getenv("ORCHESTRA_MACHINE_ID")
// One tracker for the process: it holds the per-incident accumulation that
// makes an evicted and recreated ring entry add up instead of restarting.
observations := &operations.ObservationTracker{Store: s}
workers := &federation.Registry{AdmitToken: os.Getenv("ORCHESTRA_FEDERATION_ADMIT_TOKEN"), StatePath: filepath.Join(dir, "federation-state.json")}
if err := workers.Load(); err != nil {
log.Fatalf("load federation state: %v", err)
@@ -445,6 +448,49 @@ func main() {
}
json.NewEncoder(w).Encode(s.Events(n))
})
mux.HandleFunc("/v1/interventions", func(w http.ResponseWriter, r *http.Request) {
// The one command an operator has for saying "I fixed this by hand".
// Everything Orchestra does to itself is already an event; a manual
// repair is the only kind of recovery that leaves no trace unless the
// person who made it says so.
if r.Method == http.MethodGet {
out := make([]domain.Event, 0)
for _, e := range s.Events(0) {
if e.Type == domain.EventOperatorInterventionRecorded {
out = append(out, e)
}
}
json.NewEncoder(w).Encode(out)
return
}
if r.Method != http.MethodPost {
http.Error(w, "method not allowed", http.StatusMethodNotAllowed)
return
}
if err := authz.AuthorizeEvent(surface(r), domain.EventOperatorInterventionRecorded); err != nil {
http.Error(w, err.Error(), http.StatusForbidden)
return
}
var in domain.OperatorIntervention
if json.NewDecoder(http.MaxBytesReader(w, r.Body, 1<<16)).Decode(&in) != nil {
http.Error(w, "invalid json", http.StatusBadRequest)
return
}
e, err := operations.RecordIntervention(s, surface(r), in)
switch {
case errors.Is(err, domain.ErrNotFound):
http.Error(w, err.Error(), http.StatusNotFound)
return
case errors.Is(err, domain.ErrInvalid):
http.Error(w, err.Error(), http.StatusBadRequest)
return
case err != nil:
http.Error(w, err.Error(), http.StatusConflict)
return
}
w.WriteHeader(http.StatusCreated)
json.NewEncoder(w).Encode(e)
})
mux.HandleFunc("/v1/debt", func(w http.ResponseWriter, r *http.Request) {
// Read-only, and deliberately so. This projection is evidence about
// history, not a new kind of truth: nothing here writes an event,
@@ -1391,6 +1437,29 @@ func main() {
http.Error(w, err.Error(), 404)
return
}
// The ring carries messages and nothing else, so the coordinator
// attributes them: the worker's active task, and that task's
// current lease epoch, are what bind an incident to the work it
// happened during. A failed fold is logged rather than failing the
// heartbeat, because losing evidence about a worker is not a reason
// to also stop believing the worker is alive.
report := operations.WorkerReport{
WorkerID: parts[3], Incarnation: health.Incarnation,
TaskID: health.ActiveTask, At: time.Now().UTC(),
}
if report.TaskID != "" {
if t, ok := s.Task(report.TaskID); ok && t.Lease != nil {
report.LeaseEpoch = t.Lease.Epoch
}
}
for _, o := range health.Observations {
report.Observations = append(report.Observations, domain.WorkerObservation{
Message: o.Message, Count: o.Count, First: o.First, Last: o.Last,
})
}
if _, err := observations.Ingest(report); err != nil {
log.Printf("observation incidents for %s: %v", parts[3], err)
}
w.WriteHeader(http.StatusNoContent)
return
}
+32
View File
@@ -314,6 +314,9 @@ func renderTask(in Input) string {
fmt.Fprintf(&b, "- head: %s\n", fallback(in.Git.HeadSHA))
fmt.Fprintf(&b, "- uncommitted changes: %t\n", in.Git.Dirty)
// Above the sealed artifacts, because it is the reason this session exists
// and it changes how the artifacts below should be read.
b.WriteString(renderReopen(in))
b.WriteString(renderSealed(in))
// Below the plan, above continuity. Progress is a fact about the plan, so
// it follows the plan; continuity is one predecessor's account, so it
@@ -499,6 +502,35 @@ func renderPlanProgress(in Input) string {
return b.String()
}
// renderReopen states the contradiction that reopened this phase. Without it
// the planning session a replan convenes gets the ordinary plan brief and an
// empty template, with nothing saying a plan already exists, what contradicted
// it, or that its output supersedes an accepted plan (F66). Everything here is
// durable on PlanMismatchRecorded; it simply never reached the agent.
//
// Only the phases a mismatch can reopen render it. An implementer that finds
// the next contradiction is looking at the code, not at this account of the
// last one.
func renderReopen(in Input) string {
m := in.Task.PlanMismatch
if m == nil || (in.Phase != domain.WorkPhasePlan && in.Phase != domain.WorkPhaseResearch) {
return ""
}
var b strings.Builder
b.WriteString("\n## Why this phase reopened\n\n")
fmt.Fprintf(&b, "A plan was already accepted and the code contradicted it. Orchestra reopened this phase to settle that, and the session that found it is gone.\n\n")
fmt.Fprintf(&b, "- phase: %s\n", collapse(m.PhaseID))
fmt.Fprintf(&b, "- observed: %s\n", collapse(m.Observed))
fmt.Fprintf(&b, "- the plan says: %s\n", collapse(m.Contradicts))
for _, e := range m.Evidence {
fmt.Fprintf(&b, "- evidence: %s\n", collapse(e))
}
if in.Phase == domain.WorkPhasePlan {
b.WriteString("\nThe accepted plan stays accepted until you seal a replacement, and sealing one supersedes it along with every phase it had verified. Address the contradiction above: a replacement that repeats it will be contradicted again.\n")
}
return b.String()
}
func renderSealed(in Input) string {
var b strings.Builder
research := in.Research
+58
View File
@@ -734,3 +734,61 @@ func TestPendingManualGateRendersStale(t *testing.T) {
t.Errorf("a pending manual gate at HEAD rendered stale:\n%s", fresh)
}
}
// F66, found live on run 20. A replan convenes a planning session to settle a
// contradiction, and that session was told nothing about it: the ordinary plan
// brief, an empty template, and no mention that a plan already exists.
func TestAReopenedPlanPhaseIsToldWhatContradictedThePlan(t *testing.T) {
in := input()
in.Phase = domain.WorkPhasePlan
in.Task.PlanRef = "plan-a"
in.Task.PlanMismatch = &domain.PlanMismatch{
PlanRef: "plan-a", PhaseID: "phase-3", AtSHA: "18ccaf00000000000000000000000000000000aa",
Observed: "the aggregation runs per figure, not per person",
Contradicts: "the plan states the pipeline already aggregates per person",
Evidence: []string{"internal/figures/aggregate.go:88"},
RequestedAction: domain.PlanMismatchReplan,
}
out, err := Build(in)
if err != nil {
t.Fatal(err)
}
for _, want := range []string{
"## Why this phase reopened",
"phase: phase-3",
"the aggregation runs per figure",
"the plan states the pipeline already aggregates per person",
"internal/figures/aggregate.go:88",
"stays accepted until you seal a replacement",
} {
if !strings.Contains(out.Task, want) {
t.Fatalf("the planner was not told %q:\n%s", want, out.Task)
}
}
// It must come before the artifacts it changes the reading of.
in.Research = &workphase.Research{Findings: []workphase.Finding{{
ID: "r1", Confidence: "fact", Claim: "aggregation is per figure",
Evidence: "internal/figures/aggregate.go:88",
}}}
out, err = Build(in)
if err != nil {
t.Fatal(err)
}
if !strings.Contains(out.Task, "## Accepted research") {
t.Fatal("the research this planner works from is missing")
}
if strings.Index(out.Task, "## Why this phase reopened") > strings.Index(out.Task, "## Accepted research") {
t.Fatal("the reason this session exists is rendered below the material it qualifies")
}
// An implementer is looking at the code, not at an account of the last
// contradiction, so it renders nowhere else.
in.Phase = domain.WorkPhaseImplement
out, err = Build(in)
if err != nil {
t.Fatal(err)
}
if strings.Contains(out.Task, "## Why this phase reopened") {
t.Fatal("a settled contradiction reached the implementation phase")
}
}
+6
View File
@@ -113,6 +113,12 @@ type DebtObservation struct {
Detail string `json:"detail,omitempty"`
Paths []string `json:"paths,omitempty"`
At time.Time `json:"at"`
// Repeats is how many times this one incident recurred. It is intensity,
// never recurrence: one worker stuck in a five-second retry loop produced
// 301 repeats of a single failure, and counting those as 301 pieces of
// evidence would make one broken worker look like chronic, system-wide
// debt. Recurrence is the number of independent observations.
Repeats int `json:"repeats,omitempty"`
}
func (o DebtObservation) Validate() error {
+34 -2
View File
@@ -234,7 +234,14 @@ type Task struct {
// current one, oldest first. A superseded plan stays queryable: the
// verification recorded against it is provenance, not garbage.
PlanHistory []string `json:"plan_history,omitempty"`
LastError string `json:"last_error,omitempty"`
// PlanMismatch is the contradiction that reopened this task's phase. The
// planning session convened by a replan has to be told what it is there to
// fix, and the implementer that found it is gone by then (F66). It is
// cleared when a replacement plan is accepted, or when the stop it caused
// is answered, because after either it is history rather than a live
// instruction.
PlanMismatch *PlanMismatch `json:"plan_mismatch,omitempty"`
LastError string `json:"last_error,omitempty"`
}
// ReviewRef binds a sealed review artifact to one commit.
@@ -286,6 +293,25 @@ func NewID() string {
_, _ = rand.Read(b[6:])
return ulidEncoding.EncodeToString(b)
}
// EventWithoutTask reports whether an event records something about the
// system rather than about one task's lifecycle. These carry the "system"
// aggregate id, so no task projection has to exist for them.
//
// One list, because there were three: the replay guard, the append guard and
// the transition check each kept their own copy, and adding an event type to
// two of them left it rejected by the third.
func EventWithoutTask(typ string) bool {
switch typ {
case "QuotaReported", "StandupAdvisory", "ApprovalGranted", "ApprovalDenied",
EventObservationIncidentOpened, EventObservationIncidentClosed:
// An intervention is deliberately absent: it names a task when it
// repaired one, and that task must exist.
return true
}
return false
}
func ValidateEvent(e Event) error {
if e.SchemaVersion > CurrentEventSchema || e.Type == "" || e.TaskID == "" || len(e.Payload) == 0 || len(e.Payload) > 64*1024 {
return ErrInvalid
@@ -293,7 +319,7 @@ func ValidateEvent(e Event) error {
if e.SchemaVersion >= 2 && strings.TrimSpace(e.Surface) == "" {
return fmt.Errorf("%w: surface required", ErrInvalid)
}
allowed := map[string]bool{"TaskCreated": true, "TaskLeased": true, "TaskLeaseRenewed": true, "TaskReleased": true, "TaskLaunchAcknowledged": true, "TaskPickupValidated": true, "TaskCompleted": true, "TaskFailed": true, "TaskBlocked": true, "TaskNeedsAttention": true, "ApprovalRequested": true, "ApprovalGranted": true, "ApprovalDenied": true, "TaskAmended": true, "TaskCorrected": true, "QuotaReported": true, "StandupAdvisory": true, EventHumanDecisionRecorded: true, EventHumanDecisionSuperseded: true, EventWorkPhaseChanged: true, EventDeferredFindingRecorded: true, EventReviewRecorded: true, EventTaskSubmitted: true, EventTaskChangesRequested: true, EventPlanPhaseVerified: true, EventPlanMismatchRecorded: true}
allowed := map[string]bool{"TaskCreated": true, "TaskLeased": true, "TaskLeaseRenewed": true, "TaskReleased": true, "TaskLaunchAcknowledged": true, "TaskPickupValidated": true, "TaskCompleted": true, "TaskFailed": true, "TaskBlocked": true, "TaskNeedsAttention": true, "ApprovalRequested": true, "ApprovalGranted": true, "ApprovalDenied": true, "TaskAmended": true, "TaskCorrected": true, "QuotaReported": true, "StandupAdvisory": true, EventHumanDecisionRecorded: true, EventHumanDecisionSuperseded: true, EventWorkPhaseChanged: true, EventDeferredFindingRecorded: true, EventReviewRecorded: true, EventTaskSubmitted: true, EventTaskChangesRequested: true, EventPlanPhaseVerified: true, EventPlanMismatchRecorded: true, EventObservationIncidentOpened: true, EventObservationIncidentClosed: true, EventOperatorInterventionRecorded: true}
if !allowed[e.Type] {
return fmt.Errorf("%w: unknown type %q", ErrInvalid, e.Type)
}
@@ -575,6 +601,12 @@ func ValidatePayload(typ string, p map[string]any) error {
return ValidatePlanPhaseVerified(p)
case EventPlanMismatchRecorded:
return ValidatePlanMismatchRecorded(p)
case EventObservationIncidentOpened:
return ValidateObservationIncidentOpened(p)
case EventObservationIncidentClosed:
return ValidateObservationIncidentClosed(p)
case EventOperatorInterventionRecorded:
return ValidateOperatorInterventionRecorded(p)
case EventReviewRecorded:
if err := requiredHash(p, "artifact_ref"); err != nil {
return err
+81
View File
@@ -0,0 +1,81 @@
package domain
import (
"fmt"
"strings"
"time"
)
// EventOperatorInterventionRecorded is a human saying what they repaired by
// hand. Nothing infers it: a manual fix happens outside Orchestra by
// definition, so the only honest way to have the evidence is for the operator
// to state it. Without this the debt ledger reported manual recovery as a
// permanent gap, and every repair that kept the system running was invisible
// to the record of how much the system costs to run.
const EventOperatorInterventionRecorded = "OperatorInterventionRecorded"
// InterventionKind is what the operator did. The list is closed so the ledger
// can group repairs; an unrecognised kind is refused rather than guessed at.
type InterventionKind string
const (
InterventionWorkerRestart InterventionKind = "worker_restart"
InterventionTransactionClean InterventionKind = "transaction_cleanup"
InterventionForcedRelease InterventionKind = "forced_release"
InterventionStateRepair InterventionKind = "state_repair"
InterventionManualRequeue InterventionKind = "manual_requeue"
InterventionPhaseRecovery InterventionKind = "manual_phase_recovery"
)
func (k InterventionKind) Valid() bool {
switch k {
case InterventionWorkerRestart, InterventionTransactionClean, InterventionForcedRelease,
InterventionStateRepair, InterventionManualRequeue, InterventionPhaseRecovery:
return true
}
return false
}
// OperatorIntervention is one recorded manual repair.
type OperatorIntervention struct {
TaskID string `json:"task_id,omitempty"`
WorkerID string `json:"worker_id,omitempty"`
Kind InterventionKind `json:"kind"`
// Reason is the operator's own account of why it was needed. It is the
// part a later reader cannot reconstruct from anything else.
Reason string `json:"reason"`
// RelatedEventID and RelatedTransactionID point at what was repaired, so a
// reader can find the failure this answered rather than infer it.
RelatedEventID string `json:"related_event_id,omitempty"`
RelatedTransactionID string `json:"related_transaction_id,omitempty"`
Components []string `json:"components,omitempty"`
At time.Time `json:"at,omitempty"`
}
const maxInterventionReason = 1000
func (i OperatorIntervention) Validate() error {
if !i.Kind.Valid() {
return fmt.Errorf("%w: %q is not an intervention kind", ErrInvalid, i.Kind)
}
if strings.TrimSpace(i.Reason) == "" {
return fmt.Errorf("%w: an intervention states why it was needed", ErrInvalid)
}
if len(i.Reason) > maxInterventionReason {
return fmt.Errorf("%w: reason exceeds %d characters", ErrInvalid, maxInterventionReason)
}
if i.TaskID == "" && i.WorkerID == "" {
return fmt.Errorf("%w: an intervention names the task or the worker it repaired", ErrInvalid)
}
return nil
}
func ValidateOperatorInterventionRecorded(p map[string]any) error {
kind, _ := p["kind"].(string)
reason, _ := p["reason"].(string)
task, _ := p["task_id"].(string)
worker, _ := p["worker_id"].(string)
return OperatorIntervention{
Kind: InterventionKind(kind), Reason: reason, TaskID: task, WorkerID: worker,
}.Validate()
}
+160
View File
@@ -0,0 +1,160 @@
package domain
import (
"fmt"
"regexp"
"strings"
"time"
)
// A worker's observation ring is bounded, lossy, and local: it holds distinct
// failure messages with repeat counts and nothing else, and it disappears when
// the process does. The debt ledger reported that gap about itself, because no
// event carried any of it.
//
// These two events make it durable as incidents rather than as symptoms. Run
// 11 saw the same 409 refusal 301 times; that is one incident with an
// intensity of 301, not 301 pieces of evidence. Recurrence has to mean "this
// happened on four independent leases", or one stuck loop makes everything
// look chronic.
const (
EventObservationIncidentOpened = "ObservationIncidentOpened"
EventObservationIncidentClosed = "ObservationIncidentClosed"
)
// ObservationCloseReason is why Orchestra finalized an incident. None of them
// is "the message stopped appearing in the ring": the ring is a bounded
// history, so absence proves eviction as easily as recovery.
type ObservationCloseReason string
const (
// ObservationCloseLeaseEnd and ObservationCloseEpochChange are the natural
// boundaries of a lease-scoped incident. The work it was about is over.
ObservationCloseLeaseEnd ObservationCloseReason = "lease_end"
ObservationCloseEpochChange ObservationCloseReason = "epoch_change"
// ObservationCloseWorkerRestart ends every incident of an incarnation. A
// new process cannot continue the old one's symptom.
ObservationCloseWorkerRestart ObservationCloseReason = "worker_restart"
// ObservationCloseQuietTimeout is the only closer for an observation with
// no lease to bound it, and it fires on last_seen going stale rather than
// on the entry vanishing.
ObservationCloseQuietTimeout ObservationCloseReason = "quiet_timeout"
)
func (r ObservationCloseReason) Valid() bool {
switch r {
case ObservationCloseLeaseEnd, ObservationCloseEpochChange, ObservationCloseWorkerRestart, ObservationCloseQuietTimeout:
return true
}
return false
}
// WorkerObservation is one entry of a worker's ring as reported on a
// heartbeat. It is the input to the incident projection, never a stored event.
type WorkerObservation struct {
Message string `json:"message"`
Count int `json:"count"`
First time.Time `json:"first"`
Last time.Time `json:"last"`
}
// ObservationIncident is one durable incident: a signature seen by one worker,
// on one lease when there is one, from its first occurrence to the boundary
// that ended it.
type ObservationIncident struct {
ID string `json:"observation_id"`
WorkerID string `json:"worker_id"`
Incarnation string `json:"incarnation,omitempty"`
TaskID string `json:"task_id,omitempty"`
LeaseEpoch string `json:"lease_epoch,omitempty"`
// Signature is the message with its task ids, commit shas, paths and
// durations replaced, so the same failure on two tasks shares it. Grouping
// on the raw message would make every task its own kind of problem.
Signature string `json:"signature"`
Detail string `json:"detail,omitempty"`
FirstSeen time.Time `json:"first_seen"`
// LastSeen is the last actual occurrence. ClosedAt is when Orchestra
// finalized the incident, which is later and often much later: an incident
// stays open until its lease ends, and open means "not yet final evidence"
// rather than "happening right now".
LastSeen time.Time `json:"last_seen,omitempty"`
ClosedAt time.Time `json:"closed_at,omitempty"`
RepeatCount int `json:"repeat_count,omitempty"`
CloseReason ObservationCloseReason `json:"close_reason,omitempty"`
}
// Key identifies an incident. Two workers reporting the same failure are two
// incidents, and so are two leases of one task.
func (i ObservationIncident) Key() string {
return strings.Join([]string{i.WorkerID, i.TaskID, i.LeaseEpoch, i.Signature}, "\x00")
}
var (
// Case-insensitive: a task id appears upper-case in a message and
// lower-case inside a pane name, and the live ledger's first run showed
// pane names keeping their task, which would give the same failure a
// different signature on every task.
observationID = regexp.MustCompile(`(?i)\b[0-9A-HJKMNP-TV-Z]{26}\b`)
observationSHA = regexp.MustCompile(`\b[0-9a-f]{7,64}\b`)
observationDuration = regexp.MustCompile(`\b\d+(\.\d+)?(ns|us|µs|ms|s|m|h)(\d+(\.\d+)?(ns|us|µs|ms|s|m|h))*\b`)
observationNumber = regexp.MustCompile(`\b\d+\b`)
observationPath = regexp.MustCompile(`(/[\w.-]+){2,}`)
)
// ObservationSignature collapses one message to the kind of failure it is.
// "lease A not renewed" and "lease B not renewed" are the same problem seen
// twice, which is the whole basis of counting recurrence across tasks.
func ObservationSignature(message string) string {
s := strings.TrimSpace(message)
s = observationID.ReplaceAllString(s, "<id>")
s = observationPath.ReplaceAllString(s, "<path>")
s = observationDuration.ReplaceAllString(s, "<dur>")
s = observationSHA.ReplaceAllString(s, "<sha>")
s = observationNumber.ReplaceAllString(s, "<n>")
s = strings.Join(strings.Fields(s), " ")
if len(s) > 200 {
s = s[:200]
}
return s
}
// ObservationTaskID reads the task a failure was about out of the message
// itself. The ring is a history: it holds entries from tasks that ended long
// ago, so the worker's currently active task is the wrong answer for most of
// them, and attributing an old failure to whatever is running now would be a
// fabricated association.
func ObservationTaskID(message string) string {
if m := observationTaskID.FindString(message); m != "" {
return strings.ToUpper(m)
}
return ""
}
var observationTaskID = regexp.MustCompile(`(?i)\b[0-9A-HJKMNP-TV-Z]{26}\b`)
func ValidateObservationIncidentOpened(p map[string]any) error {
if id, _ := p["observation_id"].(string); strings.TrimSpace(id) == "" {
return fmt.Errorf("%w: observation_id required", ErrInvalid)
}
if w, _ := p["worker_id"].(string); strings.TrimSpace(w) == "" {
return fmt.Errorf("%w: worker_id required", ErrInvalid)
}
if sig, _ := p["signature"].(string); strings.TrimSpace(sig) == "" {
return fmt.Errorf("%w: signature required", ErrInvalid)
}
return nil
}
func ValidateObservationIncidentClosed(p map[string]any) error {
if id, _ := p["observation_id"].(string); strings.TrimSpace(id) == "" {
return fmt.Errorf("%w: observation_id required", ErrInvalid)
}
reason, _ := p["close_reason"].(string)
if !ObservationCloseReason(reason).Valid() {
return fmt.Errorf("%w: close_reason %q is not a close reason", ErrInvalid, reason)
}
if c, ok := p["repeat_count"].(float64); ok && c < 0 {
return fmt.Errorf("%w: repeat_count cannot be negative", ErrInvalid)
}
return nil
}
+11 -4
View File
@@ -21,10 +21,14 @@ type Worker struct {
Capacity int `json:"capacity"`
SupportedProjects []string `json:"supported_projects"`
Build buildinfo.Info `json:"build"`
LastSeen time.Time `json:"last_seen"`
Online bool `json:"online"`
Health WorkerHealth `json:"health"`
Token string `json:"-"`
// Incarnation identifies one worker process. Nothing else on the wire
// distinguishes a restarted worker from a running one, and an observation
// incident cannot outlive the process that reported it.
Incarnation string `json:"incarnation,omitempty"`
LastSeen time.Time `json:"last_seen"`
Online bool `json:"online"`
Health WorkerHealth `json:"health"`
Token string `json:"-"`
}
// WorkerHealth is reported by the worker that owns the local execution backend.
@@ -42,6 +46,9 @@ type WorkerHealth struct {
// Observations is the bounded set of distinct failures behind LastError,
// which keeps its wire name and still reports only the newest.
Observations []Observation `json:"observations,omitempty"`
// Incarnation repeats the worker's process identity on every heartbeat, so
// the coordinator sees a restart even if it missed the registration.
Incarnation string `json:"incarnation,omitempty"`
}
// Observation is one distinct worker failure with its repeat count. A single
+10 -2
View File
@@ -43,9 +43,17 @@ func CheckDebtEligibility(item domain.DebtItem) DebtCheck {
if len(why) > 0 {
return DebtCheck{true, why}
}
// Reasons state facts about this item and nothing about the
// architecture around it. The second line here used to say manual
// interventions were recorded by no event type, which was true when it
// was written and false the moment OperatorInterventionRecorded
// landed. A decision that is right for a reason that has become a lie
// cannot be audited, and why a count is zero is not this function's
// business: no intervention happened, none was recorded, or none was
// migrated all read the same from here.
return DebtCheck{false, []string{
fmt.Sprintf("needs 3 occurrences across 2 tasks, or 1 manual intervention; has %d across %d tasks with %d interventions", recurrence, tasks, manual),
"manual interventions are not recorded by any event type, so that count reads 0 on every current log",
fmt.Sprintf("breadth threshold not met: %d occurrences across %d tasks, needs 3 across 2", recurrence, tasks),
fmt.Sprintf("manual intervention threshold not met: %d recorded, needs 1", manual),
}}
case domain.DebtStructural:
if recurrence >= 3 {
+12 -2
View File
@@ -62,7 +62,17 @@ func TestDebtRefusalNamesTheMissingEvidence(t *testing.T) {
t.Fatalf("want a refusal with reasons, got %+v", check)
}
joined := strings.Join(check.Reasons, " ")
if !strings.Contains(joined, "manual interventions are not recorded") {
t.Fatalf("the refusal must say the intervention count is structurally zero: %v", check.Reasons)
// Every reason is a fact about this item. The old text asserted that no
// event type recorded manual interventions, which stopped being true the
// day one did, leaving a correct decision explained by a lie.
for _, want := range []string{"1 occurrences across 1 tasks", "0 recorded, needs 1"} {
if !strings.Contains(joined, want) {
t.Fatalf("the refusal does not state %q: %v", want, check.Reasons)
}
}
for _, forbidden := range []string{"event type", "every current log"} {
if strings.Contains(joined, forbidden) {
t.Fatalf("a reason describes the architecture instead of the item: %v", check.Reasons)
}
}
}
+275
View File
@@ -0,0 +1,275 @@
package operations
import (
"encoding/json"
"fmt"
"time"
"orchestra/internal/authz"
"orchestra/internal/domain"
"orchestra/internal/store"
)
// QuietTimeout bounds an incident that has no lease to bound it. A worker-level
// observation has no terminal boundary of its own, so staleness of its last
// actual occurrence is the only honest closer.
const QuietTimeout = 10 * time.Minute
// ObservationTracker turns a worker's bounded, lossy ring into durable
// incidents. It is deliberately not a copy of the ring.
//
// The rules that matter, and why:
//
// - An incident is opened at first sight and appended immediately, so a
// coordinator that dies mid-incident still leaves the fact that it existed.
// - A repeat updates the aggregate and appends nothing. Run 11's 409 loop
// repeated 301 times; appending each would have been 301 pieces of evidence
// for one problem, and would have made every debt item eligible at once.
// - Absence from the ring closes nothing. The ring is a bounded history, so a
// message can vanish because it was evicted rather than because it stopped.
// - The lease is the scope. The same signature going quiet and returning
// inside one epoch is one incident, not two recurrences.
type ObservationTracker struct {
Store *store.Store
// counts is the last count this tracker saw for an open incident, so a
// ring entry that is evicted and recreated accumulates rather than
// restarting. Reported 34, evicted, reported 3 again means 37 occurrences,
// not 3. In-memory: a restart loses the accumulation, never the incident.
counts map[string]int
// seen is the high-water mark per worker and signature, kept after an
// incident closes. The ring is a history, so a closed incident's entry
// keeps being reported for as long as it survives eviction; without this,
// every heartbeat after a quiet timeout opened the same incident again and
// manufactured recurrence out of one old failure. Live on the first real
// run: three signatures, four incidents each, none of them a new event.
seen map[string]watermark
// incarnations is the last incarnation seen per worker, which is what makes
// a restart detectable at all.
incarnations map[string]string
}
// watermark is the last occurrence this tracker accounted for one worker's
// signature, whether or not its incident is still open.
type watermark struct {
last time.Time
count int
}
// WorkerReport is one heartbeat's worth of attributed observations. The
// coordinator attributes them, because the ring carries only messages: the
// worker's active task and that task's current lease epoch are what bind an
// incident to the work it happened during.
type WorkerReport struct {
WorkerID string
Incarnation string
TaskID string
LeaseEpoch string
Observations []domain.WorkerObservation
At time.Time
}
// Ingest folds one heartbeat into the durable incidents and returns the events
// it appended. Every close it decides is one of the four boundaries; none of
// them is "the message is no longer in the ring".
func (t *ObservationTracker) Ingest(r WorkerReport) ([]domain.Event, error) {
if t == nil || t.Store == nil || r.WorkerID == "" {
return nil, nil
}
if t.counts == nil {
t.counts, t.incarnations = map[string]int{}, map[string]string{}
t.seen = map[string]watermark{}
}
at := r.At
if at.IsZero() {
at = time.Now().UTC()
}
var appended []domain.Event
// A new process cannot continue the previous one's symptom, so its
// incidents are finalized before anything this heartbeat says is folded in.
if previous, seen := t.incarnations[r.WorkerID]; r.Incarnation != "" && seen && previous != r.Incarnation {
closed, err := t.closeWhere(at, domain.ObservationCloseWorkerRestart, func(inc domain.ObservationIncident) bool {
return inc.WorkerID == r.WorkerID
})
appended = append(appended, closed...)
if err != nil {
return appended, err
}
}
if r.Incarnation != "" {
t.incarnations[r.WorkerID] = r.Incarnation
}
open := map[string]domain.ObservationIncident{}
for _, inc := range t.Store.OpenObservations() {
if inc.WorkerID == r.WorkerID {
open[inc.Key()] = inc
}
}
for _, o := range r.Observations {
signature := domain.ObservationSignature(o.Message)
if signature == "" {
continue
}
// The task comes from the message, because the ring outlives the work
// it describes. Only a failure that names no task is attributed to the
// lease running now.
taskID, epoch := domain.ObservationTaskID(o.Message), ""
if taskID == "" {
taskID, epoch = r.TaskID, r.LeaseEpoch
} else if taskID == r.TaskID {
epoch = r.LeaseEpoch
}
candidate := domain.ObservationIncident{
WorkerID: r.WorkerID, Incarnation: r.Incarnation, Signature: signature,
TaskID: taskID, LeaseEpoch: epoch,
}
mark := t.seen[r.WorkerID+"\x00"+signature]
existing, isOpen := open[candidate.Key()]
if !isOpen {
// Nothing new: this is a closed incident's entry still sitting in
// the ring. Presence is not occurrence.
if !firstOr(o.Last, at).After(mark.last) && o.Count <= mark.count {
continue
}
candidate.ID = domain.NewID()
candidate.Detail = o.Message
candidate.FirstSeen = firstOr(o.First, at)
candidate.LastSeen = firstOr(o.Last, at)
e, err := t.append(domain.EventObservationIncidentOpened, candidate)
if err != nil {
return appended, err
}
appended = append(appended, e)
t.counts[candidate.ID] = o.Count
t.seen[r.WorkerID+"\x00"+signature] = watermark{last: candidate.LastSeen, count: o.Count}
continue
}
// Open already: accumulate, append nothing. A count lower than the last
// one means the ring evicted the entry and started it again.
delta := o.Count - t.counts[existing.ID]
if delta < 0 {
delta = o.Count
}
t.counts[existing.ID] += delta
if last := firstOr(o.Last, at); last.After(existing.LastSeen) {
existing.LastSeen = last
t.Store.NoteObservation(existing) // last_seen is durable at close
}
t.seen[r.WorkerID+"\x00"+signature] = watermark{last: existing.LastSeen, count: o.Count}
}
// The boundaries. A lease that ended, an epoch that changed, and a
// worker-level incident whose last occurrence has gone stale.
closed, err := t.closeWhere(at, "", func(inc domain.ObservationIncident) bool {
if inc.WorkerID != r.WorkerID {
return false
}
// Only an incident bound to a live lease has a lease boundary to close
// it. One read out of the ring about a task that already finished has
// no such boundary, so it ends the way a worker-level incident does.
if inc.LeaseEpoch == "" {
return at.Sub(inc.LastSeen) > QuietTimeout
}
return inc.TaskID != r.TaskID || inc.LeaseEpoch != r.LeaseEpoch
})
appended = append(appended, closed...)
return appended, err
}
// closeWhere finalizes every open incident the predicate selects. A reason of
// "" is resolved per incident, which is what lets one sweep close a lease that
// ended and a worker-level incident that went quiet.
func (t *ObservationTracker) closeWhere(at time.Time, reason domain.ObservationCloseReason, match func(domain.ObservationIncident) bool) ([]domain.Event, error) {
var out []domain.Event
for _, inc := range t.Store.OpenObservations() {
if !match(inc) {
continue
}
inc.ClosedAt = at
inc.RepeatCount = t.counts[inc.ID]
inc.CloseReason = reason
if inc.CloseReason == "" {
switch {
case inc.LeaseEpoch == "":
inc.CloseReason = domain.ObservationCloseQuietTimeout
case inc.TaskID != "":
inc.CloseReason = domain.ObservationCloseEpochChange
default:
inc.CloseReason = domain.ObservationCloseLeaseEnd
}
}
e, err := t.append(domain.EventObservationIncidentClosed, inc)
if err != nil {
return out, err
}
delete(t.counts, inc.ID)
out = append(out, e)
}
return out, nil
}
// append writes the incident as a worker-scoped event. The task it happened
// during is carried in the payload rather than in Event.TaskID on purpose: an
// incident is evidence about a worker, and binding it to the task aggregate
// would bump that task's version from a path the lease knows nothing about.
func (t *ObservationTracker) append(typ string, inc domain.ObservationIncident) (domain.Event, error) {
b, err := json.Marshal(inc)
if err != nil {
return domain.Event{}, err
}
// "system" is the same aggregate QuotaReported uses for worker-scoped
// facts: every event needs a task id, and this evidence belongs to a
// worker rather than to any one task.
e := domain.Event{ID: domain.NewID(), Type: typ, TaskID: "system", Payload: b, Surface: string(authz.System)}
if err := t.Store.Append(e); err != nil {
return domain.Event{}, fmt.Errorf("record observation incident: %w", err)
}
return e, nil
}
func firstOr(t, fallback time.Time) time.Time {
if t.IsZero() {
return fallback
}
return t
}
// RecordIntervention writes down a repair the operator made by hand. It is
// deliberately an explicit act: Orchestra cannot see a worker someone
// restarted or a transaction someone deleted, and inferring "an operator
// probably intervened" from a gap in the log would put guesses into the
// evidence the ledger is built from.
func RecordIntervention(s *store.Store, surface authz.Surface, in domain.OperatorIntervention) (domain.Event, error) {
if err := in.Validate(); err != nil {
return domain.Event{}, err
}
if in.At.IsZero() {
in.At = time.Now().UTC()
}
taskID := in.TaskID
version := 0
if taskID != "" {
t, ok := s.Task(taskID)
if !ok {
return domain.Event{}, domain.ErrNotFound
}
version = t.Version + 1
} else {
// A repair with no task is still about this deployment, so it lands on
// the same aggregate the other worker-scoped facts use.
taskID = "system"
}
b, err := json.Marshal(in)
if err != nil {
return domain.Event{}, err
}
e := domain.Event{
ID: domain.NewID(), Type: domain.EventOperatorInterventionRecorded,
TaskID: taskID, Version: version, At: in.At, Payload: b, Surface: string(surface),
}
if err := s.Append(e); err != nil {
return domain.Event{}, err
}
return e, nil
}
+295
View File
@@ -0,0 +1,295 @@
package operations
import (
"encoding/json"
"testing"
"time"
"orchestra/internal/domain"
"orchestra/internal/store"
)
func tracker(t *testing.T) (*ObservationTracker, *store.Store) {
t.Helper()
s, err := store.Open(t.TempDir())
if err != nil {
t.Fatal(err)
}
return &ObservationTracker{Store: s}, s
}
func ring(message string, count int, last time.Time) []domain.WorkerObservation {
return []domain.WorkerObservation{{Message: message, Count: count, First: last.Add(-time.Minute), Last: last}}
}
func closedIncident(t *testing.T, s *store.Store) domain.ObservationIncident {
t.Helper()
var out domain.ObservationIncident
found := 0
for _, e := range s.Events(0) {
if e.Type != domain.EventObservationIncidentClosed {
continue
}
found++
if err := json.Unmarshal(e.Payload, &out); err != nil {
t.Fatal(err)
}
}
if found != 1 {
t.Fatalf("closed incidents = %d, want 1", found)
}
return out
}
// 301 repeats of one refusal are one incident with an intensity of 301, not
// 301 pieces of evidence. Appending each would spam the log and make one stuck
// loop look like chronic, recurring debt.
func TestRepeatsAreOneIncident(t *testing.T) {
tr, s := tracker(t)
at := time.Unix(1700000000, 0).UTC()
report := func(count int, when time.Time) {
if _, err := tr.Ingest(WorkerReport{
WorkerID: "workpc-claude", Incarnation: "boot-1", TaskID: "task-a", LeaseEpoch: "epoch-1",
Observations: ring("release task-a commit: 409 superseded", count, when), At: when,
}); err != nil {
t.Fatal(err)
}
}
report(1, at)
report(40, at.Add(time.Minute))
report(301, at.Add(2*time.Minute))
opened := 0
for _, e := range s.Events(0) {
if e.Type == domain.EventObservationIncidentOpened {
opened++
}
if e.Type == domain.EventObservationIncidentClosed {
t.Fatal("an incident was closed while its lease was still running")
}
}
if opened != 1 {
t.Fatalf("opened %d incidents for one repeating failure", opened)
}
if open := s.OpenObservations(); len(open) != 1 || open[0].TaskID != "task-a" {
t.Fatalf("open incidents = %+v", open)
}
}
// The ring is a bounded history, so an entry that disappears may have been
// evicted rather than resolved. Absence must not close anything, and a
// recreated entry must accumulate rather than restart its count.
func TestEvictionNeitherClosesNorRestartsTheCount(t *testing.T) {
tr, s := tracker(t)
at := time.Unix(1700000000, 0).UTC()
send := func(obs []domain.WorkerObservation, when time.Time) {
if _, err := tr.Ingest(WorkerReport{
WorkerID: "w", Incarnation: "boot-1", TaskID: "task-a", LeaseEpoch: "epoch-1",
Observations: obs, At: when,
}); err != nil {
t.Fatal(err)
}
}
send(ring("lease task-a not renewed: agent idle", 34, at), at)
// Evicted: the message is simply gone from this heartbeat.
send(nil, at.Add(time.Minute))
if len(s.OpenObservations()) != 1 {
t.Fatal("an incident was closed because its message left a bounded ring")
}
// Recreated, counting from scratch on the worker side.
send(ring("lease task-a not renewed: agent idle", 3, at.Add(2*time.Minute)), at.Add(2*time.Minute))
// The lease ends, which is a real boundary.
if _, err := tr.Ingest(WorkerReport{WorkerID: "w", Incarnation: "boot-1", At: at.Add(3 * time.Minute)}); err != nil {
t.Fatal(err)
}
inc := closedIncident(t, s)
if inc.RepeatCount != 37 {
t.Fatalf("repeat_count = %d, want 37 (34 before eviction plus 3 after)", inc.RepeatCount)
}
if inc.CloseReason != domain.ObservationCloseEpochChange {
t.Fatalf("close_reason = %q", inc.CloseReason)
}
if !inc.LastSeen.Equal(at.Add(2 * time.Minute)) {
t.Fatalf("last_seen = %s, want the last actual occurrence", inc.LastSeen)
}
if !inc.ClosedAt.After(inc.LastSeen) {
t.Fatal("closed_at must be when Orchestra finalized it, not when the failure last happened")
}
}
// Recurrence is independent incidents. The same signature on two tasks is two,
// which is the evidence that means something; repeats inside one are intensity.
func TestTheSameSignatureOnAnotherTaskIsASecondIncident(t *testing.T) {
tr, s := tracker(t)
at := time.Unix(1700000000, 0).UTC()
if _, err := tr.Ingest(WorkerReport{
WorkerID: "w", Incarnation: "boot-1", TaskID: "task-a", LeaseEpoch: "e1",
Observations: ring("lease task-a not renewed: agent idle", 5, at), At: at,
}); err != nil {
t.Fatal(err)
}
if _, err := tr.Ingest(WorkerReport{
WorkerID: "w", Incarnation: "boot-1", TaskID: "task-b", LeaseEpoch: "e2",
Observations: ring("lease task-b not renewed: agent idle", 2, at.Add(time.Minute)), At: at.Add(time.Minute),
}); err != nil {
t.Fatal(err)
}
opened, closed := 0, 0
for _, e := range s.Events(0) {
switch e.Type {
case domain.EventObservationIncidentOpened:
opened++
case domain.EventObservationIncidentClosed:
closed++
}
}
if opened != 2 {
t.Fatalf("opened = %d, want one incident per lease", opened)
}
if closed != 1 {
t.Fatalf("closed = %d, want the first lease finalized when the second began", closed)
}
}
// A restart cannot continue the previous process's symptom.
func TestAWorkerRestartClosesItsIncidents(t *testing.T) {
tr, s := tracker(t)
at := time.Unix(1700000000, 0).UTC()
if _, err := tr.Ingest(WorkerReport{
WorkerID: "w", Incarnation: "boot-1", TaskID: "task-a", LeaseEpoch: "e1",
Observations: ring("herdr unreachable", 9, at), At: at,
}); err != nil {
t.Fatal(err)
}
if _, err := tr.Ingest(WorkerReport{WorkerID: "w", Incarnation: "boot-2", At: at.Add(time.Minute)}); err != nil {
t.Fatal(err)
}
inc := closedIncident(t, s)
if inc.CloseReason != domain.ObservationCloseWorkerRestart || inc.RepeatCount != 9 {
t.Fatalf("incident = %+v", inc)
}
}
// An observation with no lease has no terminal boundary, so staleness of its
// last actual occurrence is what ends it.
func TestAWorkerLevelIncidentClosesOnQuietTimeout(t *testing.T) {
tr, s := tracker(t)
at := time.Unix(1700000000, 0).UTC()
if _, err := tr.Ingest(WorkerReport{
WorkerID: "w", Incarnation: "boot-1",
Observations: ring("heartbeat: connection refused", 4, at), At: at,
}); err != nil {
t.Fatal(err)
}
if _, err := tr.Ingest(WorkerReport{WorkerID: "w", Incarnation: "boot-1", At: at.Add(time.Minute)}); err != nil {
t.Fatal(err)
}
if len(s.OpenObservations()) != 1 {
t.Fatal("a worker-level incident closed before its quiet timeout")
}
if _, err := tr.Ingest(WorkerReport{WorkerID: "w", Incarnation: "boot-1", At: at.Add(QuietTimeout + time.Minute)}); err != nil {
t.Fatal(err)
}
if inc := closedIncident(t, s); inc.CloseReason != domain.ObservationCloseQuietTimeout {
t.Fatalf("close_reason = %q", inc.CloseReason)
}
}
// The signature is what makes recurrence countable across tasks.
func TestSignatureCollapsesIdsAndCounts(t *testing.T) {
a := domain.ObservationSignature("lease 06G4WJ9T4F35NZC4Z8QQXM9Z6G not renewed: agent status idle and pane unchanged")
b := domain.ObservationSignature("lease 06G4VF5HZW7Q4JBM3TTY7W1Y64 not renewed: agent status idle and pane unchanged")
if a != b {
t.Fatalf("the same failure on two tasks has two signatures:\n%s\n%s", a, b)
}
if c := domain.ObservationSignature("release 06G4WJ9T4F35NZC4Z8QQXM9Z6G commit: 409 superseded"); c == a {
t.Fatal("two different failures collapsed to one signature")
}
}
// The first live run of the ledger caught this: a pane name carries the task
// id in lower case, so the same failure signed differently on every task and
// could never accumulate recurrence.
func TestSignatureCollapsesAPaneName(t *testing.T) {
a := domain.ObservationSignature(`phase rotation 06G4XAFH1MBPC35VSJN7V3NS14: pane orchestra-06g4xafh1mbpc35vsjn7v3ns14-be13b045:1.0 still holds input`)
b := domain.ObservationSignature(`phase rotation 06G4WW6TND26M16CZA6WE5T458: pane orchestra-06g4ww6tnd26m16cza6we5t458-4d839c05:1.0 still holds input`)
if a != b {
t.Fatalf("one failure has two signatures:\n%s\n%s", a, b)
}
}
// The first live run manufactured recurrence out of one old failure: a quiet
// timeout closed the incident, the entry stayed in the ring because the ring
// is a bounded history rather than a set of live conditions, and every later
// heartbeat opened it again. Four incidents, one failure, no new occurrence.
func TestAClosedIncidentDoesNotReopenFromAStaleRingEntry(t *testing.T) {
tr, s := tracker(t)
at := time.Unix(1700000000, 0).UTC()
entry := ring("heartbeat: connection refused", 4, at)
if _, err := tr.Ingest(WorkerReport{WorkerID: "w", Incarnation: "b1", Observations: entry, At: at}); err != nil {
t.Fatal(err)
}
// Long enough to close on quiet timeout, with the entry still reported.
quiet := at.Add(QuietTimeout + time.Minute)
for i := 0; i < 4; i++ {
if _, err := tr.Ingest(WorkerReport{
WorkerID: "w", Incarnation: "b1", Observations: entry,
At: quiet.Add(time.Duration(i) * time.Minute),
}); err != nil {
t.Fatal(err)
}
}
opened, closed := 0, 0
for _, e := range s.Events(0) {
switch e.Type {
case domain.EventObservationIncidentOpened:
opened++
case domain.EventObservationIncidentClosed:
closed++
}
}
if opened != 1 || closed != 1 {
t.Fatalf("opened=%d closed=%d for one failure that never happened again", opened, closed)
}
// A real new occurrence, which the ring shows by advancing the entry.
later := quiet.Add(time.Hour)
if _, err := tr.Ingest(WorkerReport{
WorkerID: "w", Incarnation: "b1", Observations: ring("heartbeat: connection refused", 5, later), At: later,
}); err != nil {
t.Fatal(err)
}
reopened := 0
for _, e := range s.Events(0) {
if e.Type == domain.EventObservationIncidentOpened {
reopened++
}
}
if reopened != 2 {
t.Fatalf("a genuine new occurrence did not open an incident: opened=%d", reopened)
}
}
// The ring outlives the work it describes, so the task comes from the message
// rather than from whatever the worker happens to be running now.
func TestTheTaskComesFromTheMessageNotTheCurrentLease(t *testing.T) {
tr, s := tracker(t)
at := time.Unix(1700000000, 0).UTC()
if _, err := tr.Ingest(WorkerReport{
WorkerID: "w", Incarnation: "b1", TaskID: "06G4XAFH1MBPC35VSJN7V3NS14", LeaseEpoch: "now",
Observations: ring("renew lease 06G4WW6TND26M16CZA6WE5T458: 409 conflict", 3, at), At: at,
}); err != nil {
t.Fatal(err)
}
open := s.OpenObservations()
if len(open) != 1 {
t.Fatalf("open = %+v", open)
}
if open[0].TaskID != "06G4WW6TND26M16CZA6WE5T458" {
t.Fatalf("the failure was attributed to the wrong task: %q", open[0].TaskID)
}
if open[0].LeaseEpoch != "" {
t.Fatalf("an old failure inherited the current lease's epoch: %q", open[0].LeaseEpoch)
}
}
+19
View File
@@ -108,6 +108,11 @@ func TestReplanKeepsTheOldPlanUntilAReplacementIsSealed(t *testing.T) {
if len(during.PlanHistory) != 0 {
t.Fatalf("the plan was moved to history early: %v", during.PlanHistory)
}
// F66: the planning session this reopen convenes has to be told what it is
// there to fix, and the implementer that found it is gone by then.
if during.PlanMismatch == nil || during.PlanMismatch.PhaseID != "phase-1" {
t.Fatalf("the contradiction did not survive to the phase it reopened: %+v", during.PlanMismatch)
}
}
// Sealing the replacement is the moment the old plan is superseded. Progress
@@ -151,6 +156,11 @@ func TestSealingTheReplacementSupersedesThePlanAndItsProgress(t *testing.T) {
if _, err := s.Artifact(oldRef); err != nil {
t.Fatalf("the superseded plan is unreadable: %v", err)
}
// The replacement answers the contradiction, so it stops being a live
// instruction and stays in the log as history.
if after, _ := s.Task(id); after.PlanMismatch != nil {
t.Fatalf("a settled contradiction is still live: %+v", after.PlanMismatch)
}
assertPhase(t, s, id, domain.WorkPhaseImplement)
}
@@ -225,6 +235,15 @@ func TestHumanAnswerResumesTheSamePlanWithoutResealing(t *testing.T) {
if after.State != domain.StateQueued {
t.Fatalf("state = %s after the human answered, want queued", after.State)
}
// F67: the stop is over, so the projection must not keep reporting it.
if after.BlockReason != "" || after.Blocker != "" {
t.Fatalf("a resumed task still reports its blocker: %q %q", after.BlockReason, after.Blocker)
}
// The answer outranks the plan and stands as an ordinary decision, so the
// contradiction it settled is not carried into later sessions either.
if after.PlanMismatch != nil {
t.Fatalf("an answered contradiction is still live: %+v", after.PlanMismatch)
}
if after.PlanRef != planRef {
t.Fatal("answering the question replaced the plan")
}
+7
View File
@@ -43,6 +43,13 @@ func PlanPhaseCommands(s *store.Store, project registry.Project, taskID, phaseID
if t.PlanRef == "" {
return workphase.PlanPhase{}, fmt.Errorf("%w: this task has no accepted plan", ErrPlanPhase)
}
// Verification is implementation work. A request that arrives in another
// phase belongs to a trajectory Orchestra has already ended: run 20's
// reopened planning session executed the implementer's leftover request
// and recorded a phase of a plan that was being replaced.
if current(t) != domain.WorkPhaseImplement {
return workphase.PlanPhase{}, fmt.Errorf("%w: phase verification belongs to the implement phase, and this task is in %s", ErrPlanPhase, current(t))
}
raw, err := s.Artifact(t.PlanRef)
if err != nil {
return workphase.PlanPhase{}, fmt.Errorf("read accepted plan: %w", err)
+27
View File
@@ -330,3 +330,30 @@ func TestASignOffDoesNotSurviveTheTreeItWasGivenAgainst(t *testing.T) {
t.Fatalf("a fresh sign-off did not verify the current tree: %+v", rec)
}
}
// Run 20: a replan reopened the plan phase, the implementer's leftover
// verification request outlived its session, and the planning session that
// replaced it executed the request. Orchestra recorded a verified phase of the
// plan it was in the middle of replacing.
func TestVerificationIsRefusedOutsideImplement(t *testing.T) {
s, project, id := planWith(t, twoPhasePlan)
task, _ := s.Task(id)
m := mismatch(task.PlanRef)
m.RequestedAction = domain.PlanMismatchReplan
if _, err := RecordPlanMismatch(s, project, id, m, shaOne); err != nil {
t.Fatal(err)
}
assertPhase(t, s, id, domain.WorkPhasePlan)
_, err := RecordPlanPhaseVerification(s, project, id, "phase-1", shaOne,
[]VerificationRun{{Command: []string{"go", "build", "./..."}, ExitCode: 0}})
if !errors.Is(err, ErrPlanPhase) {
t.Fatalf("a reopened task verified a phase of the plan being replaced: %v", err)
}
if !strings.Contains(err.Error(), "implement") {
t.Fatalf("the refusal does not say which phase owns verification: %v", err)
}
if after, _ := s.Task(id); len(after.PlanPhases()) != 0 {
t.Fatalf("progress was recorded anyway: %+v", after.PlanPhases())
}
}
+36 -7
View File
@@ -102,6 +102,36 @@ func projectDebt(events []domain.Event, readArtifact func(string) ([]byte, error
o.Detail = str(p["last_error"])
add(class, domain.DebtSignature(class, failure, harness, "lease"), o,
"tasks end in "+failure, review.Important)
case domain.EventObservationIncidentClosed:
// One incident, whatever it repeated. The debt class comes from
// the signature's shape rather than a failure class, because a
// worker observation is a symptom the worker described, not a
// lifecycle outcome Orchestra decided.
var inc domain.ObservationIncident
if json.Unmarshal(e.Payload, &inc) != nil || inc.Signature == "" {
continue
}
o := base
o.Kind = domain.ObservationWorkerFailure
o.TaskID = inc.TaskID
o.Detail = inc.Detail
o.Repeats = inc.RepeatCount
add(domain.DebtOperational,
domain.DebtSignature(domain.DebtOperational, inc.Signature, inc.WorkerID, "worker"),
o, "workers report "+inc.Signature, review.Important)
case domain.EventOperatorInterventionRecorded:
var in domain.OperatorIntervention
if json.Unmarshal(e.Payload, &in) != nil || !in.Kind.Valid() {
continue
}
o := base
o.Kind = domain.ObservationManualIntervention
o.TaskID = in.TaskID
o.Detail = in.Reason
o.Paths = in.Components
add(domain.DebtOperational,
domain.DebtSignature(domain.DebtOperational, string(in.Kind), in.WorkerID, "manual"),
o, "an operator repairs this by hand ("+string(in.Kind)+")", review.Important)
case domain.EventPlanMismatchRecorded:
o := base
o.Kind = domain.ObservationPlanMismatch
@@ -167,16 +197,15 @@ func projectDebt(events []domain.Event, readArtifact func(string) ([]byte, error
// hole in the system. A kind the log could carry and does not is a fact about
// this history.
func debtGaps(seen map[domain.ObservationKind]bool) []domain.EvidenceGap {
gaps := []domain.EvidenceGap{
{Kind: domain.ObservationManualIntervention, Durable: false,
Reason: "no event type records an operator repair, so every manual recovery is invisible to this ledger"},
{Kind: domain.ObservationWorkerFailure, Durable: false,
Reason: "worker observations live in worker memory and reach the coordinator only inside WorkerHealth, which is not persisted"},
}
// Both of these were once permanent holes in the system. They are ordinary
// evidence now, so their absence is a fact about this history rather than
// about Orchestra.
var gaps []domain.EvidenceGap
for _, k := range []domain.ObservationKind{
domain.ObservationBlockReason, domain.ObservationFailureClass,
domain.ObservationReviewFinding, domain.ObservationPlanMismatch,
domain.ObservationDeferredFinding,
domain.ObservationDeferredFinding, domain.ObservationWorkerFailure,
domain.ObservationManualIntervention,
} {
if !seen[k] {
gaps = append(gaps, domain.EvidenceGap{Kind: k, Durable: true,
+83 -15
View File
@@ -64,24 +64,92 @@ func TestProjectDebtIgnoresOrdinaryLifecycleStops(t *testing.T) {
// not recorded anywhere".
func TestProjectDebtReportsWhatItCannotSee(t *testing.T) {
ledger := ProjectDebt(nil)
var manual, worker bool
for _, g := range ledger.Gaps {
if g.Durable {
continue
}
switch g.Kind {
case domain.ObservationManualIntervention:
manual = true
case domain.ObservationWorkerFailure:
worker = true
}
}
if !manual || !worker {
t.Fatalf("the two known holes must always be reported: %+v", ledger.Gaps)
}
for _, g := range ledger.Gaps {
if g.Reason == "" {
t.Fatalf("gap %q has no reason", g.Kind)
}
// Slice B closed the two holes this ledger used to report about
// itself. Every silence is now a fact about one history, never a kind
// of evidence the system cannot record at all.
if !g.Durable {
t.Fatalf("gap %q is reported as unrecordable: %+v", g.Kind, g)
}
}
var worker, manual bool
for _, g := range ledger.Gaps {
switch g.Kind {
case domain.ObservationWorkerFailure:
worker = true
case domain.ObservationManualIntervention:
manual = true
}
}
if !worker || !manual {
t.Fatalf("an empty history should still name both kinds as absent: %+v", ledger.Gaps)
}
}
// The whole point of incidents. One worker stuck in a retry loop must not
// manufacture recurrence, while its intensity is still on the record.
func TestRecurrenceCountsIncidentsAndKeepsIntensitySeparate(t *testing.T) {
closed := func(id, worker, task, epoch string, repeats int) domain.Event {
b, _ := json.Marshal(domain.ObservationIncident{
ID: id, WorkerID: worker, TaskID: task, LeaseEpoch: epoch,
Signature: "lease <id> not renewed: agent status idle and pane unchanged",
Detail: "lease " + task + " not renewed: agent status idle and pane unchanged",
RepeatCount: repeats, CloseReason: domain.ObservationCloseEpochChange,
})
return domain.Event{ID: id, Type: domain.EventObservationIncidentClosed, TaskID: "system", Payload: b}
}
ledger := ProjectDebt([]domain.Event{
closed("i1", "workpc-claude", "task-a", "e1", 301),
closed("i2", "workpc-claude", "task-b", "e2", 2),
})
if len(ledger.Items) != 1 {
t.Fatalf("one kind of failure produced %d items", len(ledger.Items))
}
item := ledger.Items[0]
if len(item.Observations) != 2 {
t.Fatalf("recurrence = %d, want one per incident", len(item.Observations))
}
intensity := 0
for _, o := range item.Observations {
if o.Kind != domain.ObservationWorkerFailure {
t.Fatalf("observation kind = %q", o.Kind)
}
intensity += o.Repeats
}
if intensity != 303 {
t.Fatalf("intensity = %d, want 303 carried alongside a recurrence of 2", intensity)
}
tasks := map[string]bool{}
for _, o := range item.Observations {
tasks[o.TaskID] = true
}
if len(tasks) != 2 {
t.Fatalf("the two incidents are not attributed to their tasks: %+v", item.Observations)
}
}
// A repair the operator made by hand is evidence like any other, once they say
// it happened.
func TestAnOperatorRepairBecomesDebtEvidence(t *testing.T) {
b, _ := json.Marshal(domain.OperatorIntervention{
WorkerID: "workpc-opencode", Kind: domain.InterventionTransactionClean,
Reason: "deleted a release transaction stuck at prepared so the pane could be reused",
})
ledger := ProjectDebt([]domain.Event{{
ID: "i1", Type: domain.EventOperatorInterventionRecorded, TaskID: "system", Payload: b,
}})
if len(ledger.Items) != 1 || len(ledger.Items[0].Observations) != 1 {
t.Fatalf("the repair produced no debt evidence: %+v", ledger.Items)
}
if got := ledger.Items[0].Observations[0].Kind; got != domain.ObservationManualIntervention {
t.Fatalf("kind = %q", got)
}
for _, g := range ledger.Gaps {
if g.Kind == domain.ObservationManualIntervention {
t.Fatal("manual intervention is still reported as missing from a history that contains one")
}
}
}
+81 -3
View File
@@ -49,6 +49,9 @@ type Store struct {
cursors map[string]string
cursorPath string
decisionSource map[string]string
// openObservations are the incidents opened and not yet closed, by id.
// Derived from the log, so a restart finds them again.
openObservations map[string]domain.ObservationIncident
// PreLease runs immediately before a lease is minted, which is the single
// point where ownership of a task begins. Reconciliation of newer human
// input belongs here rather than in any individual launch path, because a
@@ -96,7 +99,7 @@ func Open(dir string) (*Store, error) {
if t, ok := s.tasks[e.TaskID]; ok && e.Version != t.Version+1 {
return nil, domain.ErrConflict
}
global := e.Type == "QuotaReported" || e.Type == "StandupAdvisory" || e.Type == "ApprovalGranted" || e.Type == "ApprovalDenied"
global := domain.EventWithoutTask(e.Type)
if _, ok := s.tasks[e.TaskID]; !ok && e.Type != "TaskCreated" && !global {
return nil, domain.ErrNotFound
}
@@ -312,6 +315,9 @@ func (s *Store) apply(e domain.Event) error {
}
t.PlanRef = p.ArtifactRef
t.PlanProgress = nil
// The replacement answers the contradiction. Carrying it
// further would put a solved problem in every later context.
t.PlanMismatch = nil
}
}
t.WorkPhase = p.Phase
@@ -487,6 +493,39 @@ func (s *Store) apply(e domain.Event) error {
t.Version = e.Version
s.replaceTask(e.TaskID, t)
return nil
case domain.EventObservationIncidentOpened:
// Open incidents are projected so a coordinator restart resumes them
// instead of orphaning them half-recorded. The event is what makes an
// incident durable at first sight; this is how it is found again.
var inc domain.ObservationIncident
if err := json.Unmarshal(e.Payload, &inc); err != nil {
return err
}
if s.openObservations == nil {
s.openObservations = map[string]domain.ObservationIncident{}
}
s.openObservations[inc.ID] = inc
return nil
case domain.EventObservationIncidentClosed:
var inc domain.ObservationIncident
if err := json.Unmarshal(e.Payload, &inc); err != nil {
return err
}
delete(s.openObservations, inc.ID)
return nil
case domain.EventPlanMismatchRecorded:
// Projected so the phase this reopens can be told what reopened it.
// The event is the record; this is the live instruction derived from
// it, and it stops being live as soon as a replacement seals or the
// stop is answered.
var m domain.PlanMismatch
if err := json.Unmarshal(e.Payload, &m); err != nil {
return err
}
t.PlanMismatch = &m
t.Version = e.Version
s.replaceTask(e.TaskID, t)
return nil
case domain.EventPlanPhaseVerified:
var pp domain.PlanPhaseRecord
if err := json.Unmarshal(e.Payload, &pp); err != nil {
@@ -588,8 +627,22 @@ func (s *Store) apply(e domain.Event) error {
// A question only stands while the task is blocked on it. Afterwards the
// answer is an ordinary standing decision and the log still holds the
// question, so keeping it on the task would put it in every later context.
//
// The blocker itself has the same lifetime and was outliving it (F67). A
// task resumed from a plan mismatch kept reporting block_reason
// plan_mismatch while it ran, so every surface reading the projection
// showed a stop that had already been answered.
if t.State != domain.StateBlocked {
t.DecisionRequest = nil
t.Blocker, t.BlockReason = "", ""
// The contradiction is cleared only by the correction that answers the
// stop, never by any other event that happens to find the task
// unblocked. This block runs for every event, and clearing it here
// unconditionally erased the contradiction at the very rotation the
// reopen causes, which is exactly when the planner needs it.
if e.Type == "TaskCorrected" {
t.PlanMismatch = nil
}
}
if phase, ok := p["lifecycle_phase"].(string); ok && phase != "" {
t.LifecyclePhase = phase
@@ -817,7 +870,7 @@ func (s *Store) Append(e domain.Event) error {
return fmt.Errorf("%w: corrects references unknown event %q for this task", domain.ErrInvalid, corrects)
}
}
global := e.Type == "QuotaReported" || e.Type == "StandupAdvisory" || e.Type == "ApprovalGranted" || e.Type == "ApprovalDenied"
global := domain.EventWithoutTask(e.Type)
if !taskExists && e.Type != "TaskCreated" && !global {
return domain.ErrNotFound
}
@@ -879,7 +932,7 @@ func (s *Store) Append(e domain.Event) error {
// for every lifecycle mutation.
func (s *Store) validateTransition(e domain.Event, t domain.Task, exists bool, p map[string]any) error {
if !exists {
if e.Type != "TaskCreated" && e.Type != "QuotaReported" && e.Type != "StandupAdvisory" && e.Type != "ApprovalGranted" && e.Type != "ApprovalDenied" {
if e.Type != "TaskCreated" && !domain.EventWithoutTask(e.Type) {
return domain.ErrNotFound
}
return nil
@@ -1083,6 +1136,31 @@ func (s *Store) Artifact(ref string) ([]byte, error) {
return b, nil
}
// NoteObservation updates an open incident's last actual occurrence. It writes
// no event: the aggregate is durable when the incident is finalized, and
// appending one per heartbeat is exactly the spam this design exists to avoid.
func (s *Store) NoteObservation(inc domain.ObservationIncident) {
s.mu.Lock()
defer s.mu.Unlock()
if _, ok := s.openObservations[inc.ID]; ok {
s.openObservations[inc.ID] = inc
}
}
// OpenObservations returns the incidents that are open, newest first by first
// sight. Open means not yet finalized as durable evidence, never "the failure
// is happening right now".
func (s *Store) OpenObservations() []domain.ObservationIncident {
s.mu.Lock()
defer s.mu.Unlock()
out := make([]domain.ObservationIncident, 0, len(s.openObservations))
for _, inc := range s.openObservations {
out = append(out, inc)
}
sort.Slice(out, func(i, j int) bool { return out[i].FirstSeen.After(out[j].FirstSeen) })
return out
}
func (s *Store) Task(id string) (domain.Task, bool) {
s.mu.Lock()
defer s.mu.Unlock()
+69
View File
@@ -723,3 +723,72 @@ func TestBlockRetainsLeaseEpochForALaterReopen(t *testing.T) {
t.Fatalf("last lease epoch %q, want %q", after.LastLeaseEpoch, epoch)
}
}
// F66's projection has to survive the rotation the reopen causes. The session
// that reported the contradiction hands off, a successor leases, and only then
// is the planning context rendered. Live on run 21, the field was gone by
// then: the reopen recorded it and the rotation lost it.
func TestTheContradictionSurvivesTheRotationItCauses(t *testing.T) {
s, err := Open(t.TempDir())
if err != nil {
t.Fatal(err)
}
b := []byte(`{"source":"s","external_id":"x","project":"p"}`)
if err := s.Append(domain.Event{ID: "create", Type: "TaskCreated", TaskID: "t", Version: 1, Payload: b, Surface: string(authz.System)}); err != nil {
t.Fatal(err)
}
if _, err := s.Lease("t", "h", time.Minute); err != nil {
t.Fatal(err)
}
// Frame to implement, the shortest legal route to the phase a mismatch
// can be reported from.
task, _ := s.Task("t")
toImplement, _ := json.Marshal(map[string]any{"phase": "implement", "from": "frame"})
if err := s.Append(domain.Event{ID: "impl", Type: domain.EventWorkPhaseChanged, TaskID: "t", Version: task.Version + 1, Payload: toImplement, Surface: string(authz.System)}); err != nil {
t.Fatal(err)
}
task, _ = s.Task("t")
m, _ := json.Marshal(map[string]any{
"plan_ref": "plan-a", "phase_id": "phase-2",
"at_sha": "0123456789012345678901234567890123456789",
"observed": "the body is assembled inline",
"contradicts": "the plan says one helper returns it",
"harness_id": task.Lease.HarnessID,
"lease_epoch": task.Lease.Epoch,
"requested_action": "replan",
})
if err := s.Append(domain.Event{ID: "mismatch", Type: domain.EventPlanMismatchRecorded, TaskID: "t", Version: task.Version + 1, Payload: m, Surface: string(authz.System)}); err != nil {
t.Fatal(err)
}
if got, _ := s.Task("t"); got.PlanMismatch == nil {
t.Fatal("the contradiction was not projected at all")
}
// The reopen, then the rotation it causes.
task, _ = s.Task("t")
ph, _ := json.Marshal(map[string]any{"phase": "plan", "from": "implement", "reopen": domain.EventPlanMismatchRecorded, "reopen_phase_id": "phase-2"})
if err := s.Append(domain.Event{ID: "reopen", Type: domain.EventWorkPhaseChanged, TaskID: "t", Version: task.Version + 1, Payload: ph, Surface: string(authz.System)}); err != nil {
t.Fatal(err)
}
ref, err := s.PutArtifact([]byte("handoff"))
if err != nil {
t.Fatal(err)
}
task, _ = s.Task("t")
rel, _ := json.Marshal(map[string]any{"handoff_ref": ref, "anchor_sha": "0123456789012345678901234567890123456789", "harness_id": task.Lease.HarnessID, "lease_epoch": task.Lease.Epoch, "expected_version": task.Version})
if err := s.Append(domain.Event{ID: "release", Type: "TaskReleased", TaskID: "t", Version: task.Version + 1, Payload: rel, Surface: string(authz.System)}); err != nil {
t.Fatal(err)
}
if _, err := s.Lease("t", "h", time.Minute); err != nil {
t.Fatal(err)
}
// This is the moment the planning context is rendered.
got, _ := s.Task("t")
if got.PlanMismatch == nil {
t.Fatal("the planner is convened to settle a contradiction it is no longer told about")
}
if got.PlanMismatch.PhaseID != "phase-2" {
t.Fatalf("the contradiction changed across the rotation: %+v", got.PlanMismatch)
}
}