Compare commits
6 Commits
| Author | SHA1 | Date | |
|---|---|---|---|
| f25964c18e | |||
| 0aefe021b0 | |||
| 982741fe97 | |||
| 42c5f07844 | |||
| 79d20534b5 | |||
| 74cad5d374 |
+110
@@ -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.
|
||||
|
||||
@@ -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))
|
||||
}
|
||||
@@ -90,7 +90,11 @@ func (i ObservationIncident) Key() string {
|
||||
}
|
||||
|
||||
var (
|
||||
observationID = regexp.MustCompile(`\b[0-9A-HJKMNP-TV-Z]{26}\b`)
|
||||
// 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`)
|
||||
@@ -114,6 +118,20 @@ func ObservationSignature(message string) string {
|
||||
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)
|
||||
|
||||
@@ -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 {
|
||||
|
||||
@@ -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)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@@ -36,11 +36,25 @@ type ObservationTracker struct {
|
||||
// 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
|
||||
@@ -63,6 +77,7 @@ func (t *ObservationTracker) Ingest(r WorkerReport) ([]domain.Event, error) {
|
||||
}
|
||||
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() {
|
||||
@@ -96,12 +111,27 @@ func (t *ObservationTracker) Ingest(r WorkerReport) ([]domain.Event, error) {
|
||||
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: r.TaskID, LeaseEpoch: r.LeaseEpoch,
|
||||
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)
|
||||
@@ -112,6 +142,7 @@ func (t *ObservationTracker) Ingest(r WorkerReport) ([]domain.Event, error) {
|
||||
}
|
||||
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
|
||||
@@ -125,6 +156,7 @@ func (t *ObservationTracker) Ingest(r WorkerReport) ([]domain.Event, error) {
|
||||
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
|
||||
@@ -133,7 +165,10 @@ func (t *ObservationTracker) Ingest(r WorkerReport) ([]domain.Event, error) {
|
||||
if inc.WorkerID != r.WorkerID {
|
||||
return false
|
||||
}
|
||||
if inc.TaskID == "" {
|
||||
// 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
|
||||
@@ -156,9 +191,9 @@ func (t *ObservationTracker) closeWhere(at time.Time, reason domain.ObservationC
|
||||
inc.CloseReason = reason
|
||||
if inc.CloseReason == "" {
|
||||
switch {
|
||||
case inc.TaskID == "":
|
||||
case inc.LeaseEpoch == "":
|
||||
inc.CloseReason = domain.ObservationCloseQuietTimeout
|
||||
case inc.LeaseEpoch != "":
|
||||
case inc.TaskID != "":
|
||||
inc.CloseReason = domain.ObservationCloseEpochChange
|
||||
default:
|
||||
inc.CloseReason = domain.ObservationCloseLeaseEnd
|
||||
|
||||
@@ -207,3 +207,89 @@ func TestSignatureCollapsesIdsAndCounts(t *testing.T) {
|
||||
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)
|
||||
}
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user