| index ec1727d29..038f265ea 100644 |
| --- a/internal/rollout/sim_test.go |
| +++ b/internal/rollout/sim_test.go |
| @@ -32,7 +32,10 @@ import ( |
| // runs the real scheduler.execute and scheduler.done on a goroutine of its |
| // own, handed off so that exactly one goroutine runs at any moment: a seed is |
| // one deterministic interleaving, and every invariant check sees a state no |
| -// transition is halfway through. |
| +// transition is halfway through. An ordinary wake's healthy event may reach |
| +// the agent some steps after its generation serves (sim.late), and one seed |
| +// in four keeps its failure book on disk, where windows of failing saves |
| +// open and close (sim.fault). |
| // |
| // The invariants, checked against the model's own ground truth (what it |
| // promoted, what failed, what it retried), never against the book: |
| @@ -74,10 +77,23 @@ import ( |
| // cleared without it is an I5 violation. (The book is read here only to |
| // see what the Pass cleared; the evidence is the model's.) When the |
| // marked build is itself the installed good build, it boots under the |
| -// marked-build rule, and I1 requires its wake to boot. |
| +// marked-build rule, and I1 requires its wake to boot. A good write |
| +// that clears a marker the model's restriction still stands for (one |
| +// set after the write's execution began) is an I5 violation at the |
| +// write (goodWrite). |
| // - I6: every execution's intent (Task 5) ends with its outcome: once the |
| // run has drained, an intent stands only for a first wake still in |
| // flight, and it is that wake's. |
| +// - I7: a retry is never undone by an outcome that began before it |
| +// (ruling 191, plan review finding 3): a host's `carlos instances |
| +// retry` stands in the record until that host fails the build again in |
| +// a later execution, and a record a re-signed pointer cleared is |
| +// neither written again nor its adoption cohort halted again but by a |
| +// failure of an execution that began after the clear. |
| +// - I8: a failure outlives an agent restart even when no save of the book |
| +// lands (Task 5, F5): at every failure, before the code records it, an |
| +// agent opening the book from disk holds the build for the instance, |
| +// and holds it down when the failure does. |
| // |
| // Seeds: ROLLOUT_SIM_SEEDS (default 200; the per-revision sweep is 3000). |
| // ROLLOUT_SIM_SEED=<n> replays one seed. The production code iterates some |
| @@ -100,11 +116,11 @@ func TestSimInvariants(t *testing.T) { |
| } |
| first, last = n, n+1 |
| } |
| - opt := t.TempDir() |
| + opt, books := t.TempDir(), t.TempDir() |
| staged := map[string]bool{} |
| failed := 0 |
| for seed := first; seed < last; seed++ { |
| - v := runSimSeed(seed, opt, staged, simSteps) |
| + v := runSimSeed(seed, opt, books, staged, simSteps) |
| if v == nil { |
| continue |
| } |
| @@ -143,9 +159,15 @@ type simFailure struct { |
| trace []string |
| } |
| |
| -func runSimSeed(seed int64, opt string, staged map[string]bool, steps int) (out *simFailure) { |
| +func runSimSeed(seed int64, opt, books string, staged map[string]bool, steps int) (out *simFailure) { |
| var s *sim |
| defer func() { |
| + if s != nil && s.dir != "" { |
| + // Writable again, so the seed's book can go (and t.TempDir's |
| + // own cleanup never meets a read-only directory). |
| + os.Chmod(s.dir, 0o700) |
| + os.RemoveAll(s.dir) |
| + } |
| r := recover() |
| if r == nil { |
| return |
| @@ -163,7 +185,7 @@ func runSimSeed(seed int64, opt string, staged map[string]bool, steps int) (out |
| out = &simFailure{line: fmt.Sprintf("crash at seed %d step %d: %v\n%s", seed, step, r, debug.Stack()), trace: trace} |
| } |
| }() |
| - s = newSim(seed, opt, staged) |
| + s = newSim(seed, opt, books, staged) |
| s.run(steps) |
| return nil |
| } |
| @@ -232,6 +254,14 @@ type simSwap struct { |
| before string |
| } |
| |
| +// simLate is a healthy event on its way (sim.late): the event, and the |
| +// start of the wake's execution (its plan), which the model's good write |
| +// is ordered by. |
| +type simLate struct { |
| + ev activator.GenEvent |
| + start time.Time |
| +} |
| + |
| type simEvent struct { |
| host string |
| swap *simSwap // the attempt reached Swap and is parked |
| @@ -295,13 +325,34 @@ type sim struct { |
| // retry cleared and holds nothing down. |
| retryAt map[string]map[string]time.Time |
| clearedAt map[string]time.Time |
| + // failedAt is when each build last failed in an execution that began |
| + // after every retry of it (a failure the retry ordering lets stand): I7 |
| + // reads it against clearedAt. |
| + failedAt map[string]time.Time |
| + |
| + // The book on disk (I8): one seed in four keeps the failure book in a |
| + // directory of its own, and fault makes that directory read-only for |
| + // a while, so every save fails as a full or broken disk would. fr draws |
| + // the fault windows, apart from r, so the seeds that keep their book in |
| + // memory run exactly the schedules they ran before I8 existed. |
| + dir string |
| + fault bool |
| + fr *rand.Rand |
| + |
| + // late holds an ordinary wake's healthy event (GenHealthy, not a first |
| + // wake) that the activator has not yet delivered, per host: its |
| + // generation serves, and its good write waits for the event (Astra R3 |
| + // N6). Such a wake has no intent, so an adoption may run on the host |
| + // meanwhile; a hold one that fails leaves a marker the late write must |
| + // not clear (I5). |
| + late map[string]simLate |
| |
| swaps map[string]*simSwap |
| events chan simEvent |
| draining bool |
| } |
| |
| -func newSim(seed int64, opt string, staged map[string]bool) *sim { |
| +func newSim(seed int64, opt, books string, staged map[string]bool) *sim { |
| s := &sim{r: rand.New(rand.NewSource(seed)), seed: seed, now: t0, opt: opt, staged: staged, |
| book: &FailureBook{}, rows: &fakeRoutes{rows: map[string]registry.Route{}}, |
| byName: map[string]*simHost{}, channels: [2]string{"", "beta"}, |
| @@ -309,7 +360,20 @@ func newSim(seed int64, opt string, staged map[string]bool) *sim { |
| lastStamp: map[string]time.Time{}, lastSigned: map[string]time.Time{}, failedEver: map[string]bool{}, |
| exempt: map[string]map[string]bool{}, heldDown: map[string]map[string]bool{}, holdRan: map[string]string{}, |
| holdRanAt: map[string]time.Time{}, holdRanSet: map[string]time.Time{}, retryAt: map[string]map[string]time.Time{}, |
| - clearedAt: map[string]time.Time{}, swaps: map[string]*simSwap{}, events: make(chan simEvent)} |
| + clearedAt: map[string]time.Time{}, failedAt: map[string]time.Time{}, late: map[string]simLate{}, swaps: map[string]*simSwap{}, |
| + events: make(chan simEvent)} |
| + if seed%4 == 3 && os.Geteuid() != 0 { |
| + // Root writes into a read-only directory, so it gets no faults. |
| + dir, err := os.MkdirTemp(books, "book") |
| + if err != nil { |
| + panic(simCrash{msg: "make the book's directory: " + err.Error()}) |
| + } |
| + s.dir = dir |
| + if s.book, err = OpenFailureBook(dir); err != nil { |
| + panic(simCrash{msg: "open the book: " + err.Error()}) |
| + } |
| + s.fr = rand.New(rand.NewSource(seed*7919 + 1)) |
| + } |
| s.book.now = func() time.Time { return s.now } |
| s.hold = s.r.Intn(4) == 0 |
| s.concurrency = 1 + s.r.Intn(3) |
| @@ -450,10 +514,12 @@ func (s *sim) failure(build, host string, stamp time.Time, heldDown bool, start |
| } |
| return |
| } |
| + s.checkI8(build, host, heldDown) |
| if stamp.IsZero() { |
| stamp = s.now |
| } |
| s.failedEver[build] = true |
| + s.failedAt[build] = s.now |
| if stamp.After(s.lastStamp[build]) { |
| s.lastStamp[build] = stamp |
| } |
| @@ -467,6 +533,87 @@ func (s *sim) failure(build, host string, stamp time.Time, heldDown bool, start |
| s.logf("ground truth: %s failed on %s (stamp %s, held down %v)", build, host, stamp.Sub(t0), heldDown) |
| } |
| |
| +// diskFault opens or closes a window in which every save of the book fails |
| +// (I8), for a seed whose book is on disk: its directory is made read-only, |
| +// so WriteFileAtomic cannot create its temp file there. |
| +func (s *sim) diskFault() { |
| + if s.dir == "" { |
| + return |
| + } |
| + switch { |
| + case !s.fault && s.fr.Intn(10) == 0: |
| + s.fault = true |
| + case s.fault && s.fr.Intn(4) == 0: |
| + s.fault = false |
| + default: |
| + return |
| + } |
| + mode := os.FileMode(0o700) |
| + if s.fault { |
| + mode = 0o500 |
| + } |
| + if err := os.Chmod(s.dir, mode); err != nil { |
| + panic(simCrash{msg: "the book's directory: " + err.Error()}) |
| + } |
| + s.logf("disk: saves of the failure book now fail: %v", s.fault) |
| +} |
| + |
| +// checkI8 is I8 at a failure of build on host, called before the code has |
| +// written it: an agent restarting now must still find it. The restart is |
| +// simulated by a second book opened from the disk as the agent opens it at |
| +// startup (OpenFailureBook, which turns intents into records). It must hold |
| +// build for host, and hold host down when the failure does. Only the |
| +// execution's intent, saved before the build ran (Task 5, F5), can carry |
| +// that across a window in which every save fails. |
| +func (s *sim) checkI8(build, host string, heldDown bool) { |
| + if s.dir == "" { |
| + return |
| + } |
| + b, err := OpenFailureBook(s.dir) |
| + if err != nil { |
| + panic(simCrash{msg: "reopen the book: " + err.Error()}) |
| + } |
| + if !b.Blocks("bab", "blog", build, host, false) || (heldDown && !b.HeldDown("bab", "blog", build, host)) { |
| + violate("I8", "%s failed on %s (held down %v), and an agent restarting now would not hold it there (saves failing: %v)", build, host, heldDown, s.fault) |
| + } |
| +} |
| + |
| +// checkI7 is I7 after every step, against the model's retries: a failure of |
| +// an execution that began before a retry never takes the retry back. |
| +// - A `carlos instances retry` of host for build b (exempt) stands until |
| +// host fails b again in an execution that began after it (failure |
| +// deletes exempt) or b's record goes: the record still lists host as |
| +// retried. |
| +// - A record a re-signed pointer cleared (clearedAt) is written again, and |
| +// b's adoption cohort is halted again, only by a failure of an execution |
| +// that began after the clear (failedAt). A stale one's halt is caught |
| +// here before the next Pass's liftClearedHalts could hide it. |
| +func (s *sim) checkI7() { |
| + for _, b := range sortedKeys(s.clearedAt) { |
| + if !s.failedAt[b].Before(s.clearedAt[b]) { |
| + continue |
| + } |
| + if r, ok := s.book.Lookup("bab", "blog", b); ok { |
| + violate("I7", "%s's record, cleared by a re-signed pointer at %s, stands again with no failure begun after the clear: %+v", |
| + b, s.clearedAt[b].Sub(t0), r) |
| + } |
| + s.sched.mu.Lock() |
| + c := s.sched.q.cohorts[cohortKey(b, classAdopt)] |
| + halted := c != nil && c.halted |
| + s.sched.mu.Unlock() |
| + if halted { |
| + violate("I7", "%s's cohort, reopened by a re-signed pointer at %s, is halted again with no failure begun after the clear", b, s.clearedAt[b].Sub(t0)) |
| + } |
| + } |
| + for _, host := range sortedKeys(s.exempt) { |
| + for _, b := range sortedKeys(s.exempt[host]) { |
| + if r, ok := s.book.Lookup("bab", "blog", b); ok && !slices.Contains(r.Retried, host) { |
| + violate("I7", "%s's retry of %s was taken back with no failure there begun after it: %+v", host, b, r) |
| + } |
| + } |
| + } |
| +} |
| + |
| func (s *sim) stands(build string) bool { |
| return s.failedEver[build] && !s.lastSigned[build].After(s.lastStamp[build]) |
| } |
| @@ -638,6 +785,10 @@ func (s *sim) launch(d dispatch) { |
| func (s *sim) run(steps int) { |
| for s.step = 0; s.step < steps; s.step++ { |
| s.now = s.now.Add(time.Duration(1+s.r.Intn(3)) * time.Second) |
| + s.diskFault() |
| + if hosts := sortedKeys(s.late); len(hosts) > 0 && s.r.Intn(12) == 0 { |
| + s.deliverLate(hosts[s.r.Intn(len(hosts))]) |
| + } |
| switch k := s.r.Intn(26); { |
| case k < 2: |
| s.promote() |
| @@ -669,6 +820,7 @@ func (s *sim) run(steps int) { |
| s.restage() |
| } |
| s.checkI2() |
| + s.checkI7() |
| } |
| s.draining = true |
| for _, host := range sortedKeys(s.swaps) { |
| @@ -677,6 +829,9 @@ func (s *sim) run(steps int) { |
| close(sw.release) |
| s.await() |
| } |
| + for _, host := range sortedKeys(s.late) { |
| + s.deliverLate(host) |
| + } |
| s.checkIntents() |
| } |
| |
| @@ -734,7 +889,16 @@ func (s *sim) pass() { |
| still[r.Build] = true |
| } |
| for _, b := range sortedKeys(recorded) { |
| - if !still[b] && installed[b] { |
| + if still[b] { |
| + continue |
| + } |
| + // The record is gone, cleared or pruned, and with it every host |
| + // retry's exemption from it: the build's next failure writes a new |
| + // record, which holds every host (spec §8.4). |
| + for _, host := range sortedKeys(s.exempt) { |
| + delete(s.exempt[host], b) |
| + } |
| + if installed[b] { |
| s.clearedAt[b] = s.now |
| s.logf("ground truth: a pass cleared %s's record on a re-signed pointer", b) |
| } |
| @@ -949,6 +1113,11 @@ func (s *sim) wakeBegin() { |
| if h == nil { |
| return |
| } |
| + // The activator's outcome fence (awaitOutcomes): an earlier wake's |
| + // events reach the agent before the host plans again. |
| + if _, ok := s.late[h.name]; ok { |
| + s.deliverLate(h.name) |
| + } |
| row := s.rows.get(h.name) |
| h.phase = simWaking |
| plan := s.m.Plan(context.Background(), row) |
| @@ -961,12 +1130,18 @@ func (s *sim) wakeBegin() { |
| h.plan, h.planRoute, h.wakeStart, h.planAt, h.stamp = plan, row, s.now, s.now, s.stampFor(h, plan.Boot.Version) |
| h.underMark = s.holdRan[h.name] != "" |
| s.logf("wake %s planned: boot %s first %v fallback %v mode %s", h.name, plan.Boot.Version, plan.FirstWake, plan.Fallback != nil, plan.Mode) |
| + s.checkPlanned(h, plan.Boot.Version) |
| } |
| |
| func (s *sim) checkWakeRefused(h *simHost, installed, why string) { |
| if h.good == "" || s.heldDownOn(h.name, installed) { |
| return |
| } |
| + if s.fault && strings.Contains(why, BookUnreadableRefusal) { |
| + // A first wake whose intent could not be saved boots nothing (Task 5): |
| + // its failure could not outlive a restart (I8). |
| + return |
| + } |
| if mark := s.holdRan[h.name]; mark != "" { |
| if installed == mark && installed == h.good { |
| // The marked build is the installed good build (Task 3 fix round |
| @@ -1004,6 +1179,17 @@ func (s *sim) checkBoot(h *simHost, build string) { |
| } |
| } |
| |
| +// checkPlanned is I1 at a wake's plan, its first gate: the planner never |
| +// names a build whose failure on this box stands for an instance with a |
| +// good build (decideWake, and decideHoldRan for the marked build, Astra R3 |
| +// N7). The plan's Check at the exec is the second gate, for records written |
| +// since the plan, and is not what keeps a held build out of a plan. |
| +func (s *sim) checkPlanned(h *simHost, build string) { |
| + if h.good != "" && build != h.good && !h.served[build] && s.blockedFor(h.name, build) { |
| + violate("I1", "%s (good build %s) plans a wake of %s, whose failure on this box stands", h.name, h.good, build) |
| + } |
| +} |
| + |
| // wakeExec is the activator's checkPlan and exec (spec §7.4, §8.2): the |
| // plan's Check, one replan if it refuses, the verdict floor, and the build's |
| // outcome reported through the real OnGen. |
| @@ -1035,7 +1221,7 @@ func (s *sim) wakeExec() { |
| } |
| s.cancelUnrun(rt, plan) |
| // The replan read the row afresh (Plan replans a moved row). |
| - s.checkWakeRefused(h, s.rows.get(h.name).Version, "the plan went stale and the replan refused") |
| + s.checkWakeRefused(h, s.rows.get(h.name).Version, "the plan went stale and the replan refused: "+next.Refuse) |
| return |
| } |
| // The replan replaces the plan, which checkPlan cancels: it never ran. |
| @@ -1043,6 +1229,7 @@ func (s *sim) wakeExec() { |
| plan, h.plan, h.planAt, h.stamp = next, next, s.now, s.stampFor(h, next.Boot.Version) |
| h.underMark = s.holdRan[h.name] != "" |
| s.logf("wake %s replanned: boot %s first %v", h.name, plan.Boot.Version, plan.FirstWake) |
| + s.checkPlanned(h, plan.Boot.Version) |
| } |
| canFall := plan.FirstWake && plan.Fallback != nil && plan.Mode == activator.ModeOverlap |
| if left := h.wakeStart.Add(simHealthWindow).Sub(s.now); canFall && left < simMinVerdict { |
| @@ -1063,9 +1250,9 @@ func (s *sim) wakeExec() { |
| s.checkI5(h, rt, good.Version) |
| h.phase, h.gen = simAwake, s.newGen(good) |
| h.served[good.Version] = true |
| - s.goodAt(h, good.Version, h.planAt) // served: the good build is written again |
| s.logf("wake %s: %s untried, booted the good build %s", h.name, plan.Boot.Version, good.Version) |
| - s.m.OnGen(activator.GenEvent{Kind: activator.GenHealthy, Route: rt, Gen: h.gen, Mode: plan.Mode, At: s.now, Token: plan.Token, ConfigRev: plan.ConfigRev}) |
| + // served: the good build is written again, when the event lands. |
| + s.healthy(h, activator.GenEvent{Kind: activator.GenHealthy, Route: rt, Gen: h.gen, Mode: plan.Mode, At: s.now, Token: plan.Token, ConfigRev: plan.ConfigRev}) |
| return |
| } |
| boot := plan.Boot |
| @@ -1077,10 +1264,9 @@ func (s *sim) wakeExec() { |
| } |
| if !plan.FirstWake { |
| h.phase, h.gen = simAwake, s.newGen(boot) |
| - s.goodAt(h, boot.Version, h.planAt) |
| h.served[boot.Version] = true |
| s.logf("wake %s: booted %s", h.name, boot.Version) |
| - s.m.OnGen(activator.GenEvent{Kind: activator.GenHealthy, Route: rt, Gen: h.gen, Mode: plan.Mode, At: s.now, Token: plan.Token, ConfigRev: plan.ConfigRev}) |
| + s.healthy(h, activator.GenEvent{Kind: activator.GenHealthy, Route: rt, Gen: h.gen, Mode: plan.Mode, At: s.now, Token: plan.Token, ConfigRev: plan.ConfigRev}) |
| return |
| } |
| if s.r.Intn(12) == 0 { |
| @@ -1150,6 +1336,59 @@ func (s *sim) cancelUnrun(rt registry.Route, plan activator.WakePlan) { |
| Token: plan.Token, ConfigRev: plan.ConfigRev}) |
| } |
| |
| +// healthy reports an ordinary wake's healthy event (not a first wake's), |
| +// which writes the good build (served). Half of them are delivered late |
| +// (sim.late): the activator serves the generation at once, but its event, |
| +// and with it the good write, reaches the agent some steps later (OnGen |
| +// takes a late event as a matter of course). The good write is then |
| +// decided by a wake whose execution began before whatever ran on the host |
| +// meanwhile: an adoption, admitted because the generation serves, whose |
| +// hold build ran and failed leaves a marker the write must not clear (Astra |
| +// R3 N6, ClearHoldRanBefore). |
| +func (s *sim) healthy(h *simHost, ev activator.GenEvent) { |
| + s.late[h.name] = simLate{ev: ev, start: h.planAt} |
| + if s.r.Intn(2) == 0 { |
| + s.logf("wake %s: its healthy event is late", h.name) |
| + return |
| + } |
| + s.deliverLate(h.name) |
| +} |
| + |
| +// deliverLate delivers host's healthy event. The good write follows only |
| +// while the event's generation is the one serving (Manager.acknowledged), |
| +// and it lifts only a restriction set before the wake's execution began |
| +// (goodAt). |
| +func (s *sim) deliverLate(host string) { |
| + l, ok := s.late[host] |
| + if !ok { |
| + return |
| + } |
| + delete(s.late, host) |
| + h := s.byName[host] |
| + s.logf("wake %s: healthy event of %s delivered", host, l.ev.Gen.Build) |
| + s.goodWrite(h, l.ev.Gen.Build, l.start, h.phase == simAwake && h.gen.N == l.ev.Gen.N, func() { s.m.OnGen(l.ev) }) |
| +} |
| + |
| +// goodWrite is a good-build write of build on h by an execution that began |
| +// at start (when acked: the code writes only while the generation serves), |
| +// made by deliver, the real event. It is I5 at the write: a write may lift |
| +// only a restriction set before its execution began (goodAt), so a marker |
| +// that stood in the book before the event and is gone after it, while the |
| +// model's restriction stands, was cleared by a write decided before its |
| +// hold build ran (Astra R3 N6). The book is read only to see what the write |
| +// cleared, as pass reads it for a Pass. |
| +func (s *sim) goodWrite(h *simHost, build string, start time.Time, acked bool, deliver func()) { |
| + _, had := s.book.HoldRanOn(h.name) |
| + if acked { |
| + s.goodAt(h, build, start) |
| + } |
| + deliver() |
| + if _, still := s.book.HoldRanOn(h.name); had && !still && s.holdRan[h.name] != "" { |
| + violate("I5", "%s's good write of %s, by an execution begun at %s, cleared the hold-ran restriction of %s, set at %s after it began", |
| + h.name, build, start.Sub(t0), s.holdRan[h.name], s.holdRanSet[h.name].Sub(t0)) |
| + } |
| +} |
| + |
| // checkIntents is I6 once the run has drained (Task 5): every execution's |
| // intent ends with its outcome, so the only intents left are those of first |
| // wakes still in flight (planned or under observation), each the host's |
| @@ -1184,10 +1423,11 @@ func (s *sim) observeEnd() { |
| return |
| } |
| h.phase = simAwake |
| - s.goodAt(h, h.gen.Build, h.planAt) |
| h.served[h.gen.Build] = true |
| s.logf("wake %s: %s settled", h.name, h.gen.Build) |
| - s.m.OnGen(activator.GenEvent{Kind: activator.GenSettled, Route: rt, Gen: h.gen, Mode: plan.Mode, FirstWake: true, At: s.now, Token: plan.Token, ConfigRev: plan.ConfigRev}) |
| + s.goodWrite(h, h.gen.Build, h.planAt, true, func() { |
| + s.m.OnGen(activator.GenEvent{Kind: activator.GenSettled, Route: rt, Gen: h.gen, Mode: plan.Mode, FirstWake: true, At: s.now, Token: plan.Token, ConfigRev: plan.ConfigRev}) |
| + }) |
| } |
| |
| // sleep hibernates an instance with no attempt in Swap: at once, or through a |
| @@ -1271,10 +1511,15 @@ func (s *sim) hostRetry() { |
| // The console's grant names the build and the epoch the box reports |
| // for it (Task 8); the sim reads the epoch just as the console would. |
| ok := s.m.RetryHost(h.name, b, s.book.RestrictionEpoch("bab", "blog", b, h.name)) |
| - if s.exempt[h.name] == nil { |
| - s.exempt[h.name] = map[string]bool{} |
| + // The retry exempts h from the record that stands now, and from no |
| + // record written after that one goes (pass): with no record there is |
| + // nothing to exempt it from. |
| + if recorded { |
| + if s.exempt[h.name] == nil { |
| + s.exempt[h.name] = map[string]bool{} |
| + } |
| + s.exempt[h.name][b] = true |
| } |
| - s.exempt[h.name][b] = true |
| if clears { |
| if s.retryAt[h.name] == nil { |
| s.retryAt[h.name] = map[string]time.Time{} |
amadan