| new file mode 100644 |
| index 000000000..5cd28ad3c |
| --- /dev/null |
| +++ b/internal/e2e/selfserve/cut_test.go |
| @@ -0,0 +1,831 @@ |
| +//go:build e2e |
| + |
| +package selfserve |
| + |
| +import ( |
| + "encoding/json" |
| + "strings" |
| + "testing" |
| + "time" |
| + |
| + "github.com/carlosframework/platform/internal/console" |
| + "github.com/carlosframework/platform/internal/host" |
| + "github.com/carlosframework/platform/internal/moves" |
| + "github.com/carlosframework/platform/internal/provision" |
| + "github.com/carlosframework/platform/internal/status" |
| +) |
| + |
| +// The cut, the abort, the finaliser, paging and the operator return |
| +// (self-serve moves plan 2 Task 8), witnessed end to end over the |
| +// bridge's two real boxes. |
| + |
| +// toCut brings a fresh row to ready and marks the cut as the cut door |
| +// does. |
| +func (w *jobWorld) toCut() *console.SelfServeMove { |
| + w.t.Helper() |
| + row := w.admit() |
| + w.watch = row.ID |
| + w.phase(row.ID, "ready", 60) |
| + if !w.markCut(row.ID) { |
| + w.t.Fatalf("the cut did not take: %s", describe(w.row(row.ID))) |
| + } |
| + return w.row(row.ID) |
| +} |
| + |
| +// run drives the boxes and the console until done holds: the health |
| +// probes are 30 seconds apart, so the console's clock moves on in health. |
| +func (w *jobWorld) run(max int, what, id string, done func(r *console.SelfServeMove) bool) *console.SelfServeMove { |
| + w.t.Helper() |
| + w.until(max, what, func() bool { |
| + r := w.row(id) |
| + if r.Phase == "health" && r.Outcome == "" { |
| + w.advance(31 * time.Second) |
| + } |
| + return done(r) |
| + }) |
| + return w.row(id) |
| +} |
| + |
| +// cutTo runs a fresh move from the cut until its row is in phase. |
| +func (w *jobWorld) cutTo(phase string) *console.SelfServeMove { |
| + w.t.Helper() |
| + row := w.toCut() |
| + r := w.run(200, "in "+phase, row.ID, func(r *console.SelfServeMove) bool { return r.Phase == phase || r.Outcome != "" }) |
| + if r.Phase != phase { |
| + w.t.Fatalf("the row is %s, want %s", describe(r), phase) |
| + } |
| + return r |
| +} |
| + |
| +// done runs the row to its finished outcome. |
| +func (w *jobWorld) done(id string) *console.SelfServeMove { |
| + w.t.Helper() |
| + return w.run(300, "finished", id, func(r *console.SelfServeMove) bool { |
| + return r.Outcome != "" && !r.ReleasePending && r.EffectsDone |
| + }) |
| +} |
| + |
| +// pastDeadline moves the console's clock past the row's step deadline. |
| +func (w *jobWorld) pastDeadline(r *console.SelfServeMove) { |
| + w.t.Helper() |
| + if r.StepDeadline.IsZero() { |
| + w.t.Fatalf("no step deadline: %s", describe(r)) |
| + } |
| + w.advance(time.Until(r.StepDeadline.Add(-w.skew)) + time.Second) |
| +} |
| + |
| +// paged is when the job last attempted the page for the row's condition. |
| +func (w *jobWorld) paged(id, condition string) (time.Time, bool) { |
| + w.t.Helper() |
| + at, ok, err := w.cst.MovePageAttempt("selfserve:" + id + ":" + condition) |
| + if err != nil { |
| + w.t.Fatal(err) |
| + } |
| + return at, ok |
| +} |
| + |
| +// requireLossless is an aborted move's end: the record back home with no |
| +// move and last_move aborted, the reservations released, and the three |
| +// facts in order. |
| +func (w *jobWorld) requireLossless(r *console.SelfServeMove, region string) { |
| + w.t.Helper() |
| + rec := w.record() |
| + switch { |
| + case r.Outcome != "aborted": |
| + w.t.Fatalf("outcome %s", describe(r)) |
| + case rec.Move != nil || rec.Region != region || rec.LastMove == nil || rec.LastMove.Outcome != provision.OfflineOutcomeAborted: |
| + w.t.Fatalf("record: move %+v region %q last %+v", rec.Move, rec.Region, rec.LastMove) |
| + case len(w.reservations()) != 0: |
| + w.t.Fatalf("reservations left: %v", w.reservations()) |
| + case r.AbortRequestedAt.IsZero() || r.SourceReopenedAt.Before(r.AbortRequestedAt) || r.AbortFinishedAt.Before(r.SourceReopenedAt): |
| + w.t.Fatalf("the abort's facts out of order: requested %v reopened %v finished %v", r.AbortRequestedAt, r.SourceReopenedAt, r.AbortFinishedAt) |
| + } |
| +} |
| + |
| +// TestCutRunsEveryPhaseToDone: from the cut, the job restages, passes the |
| +// barrier, stops, seals, flips, opens, sees the target opened, probes the |
| +// account twice, finishes through both gates and finalises: outcome done, |
| +// the record in the target region with no move and last_move done with |
| +// the job's receipt, the open record written at the open's stamp, the |
| +// reservations released, nothing owed. |
| +func TestCutRunsEveryPhaseToDone(t *testing.T) { |
| + w := newJobWorld(t) |
| + row := w.toCut() |
| + seen := map[string]bool{} |
| + var openedAt *time.Time |
| + r := w.run(200, "done", row.ID, func(r *console.SelfServeMove) bool { |
| + seen[r.Phase] = true |
| + if rec := w.record(); rec.Move != nil && rec.Move.OpenedAt != nil { |
| + openedAt = rec.Move.OpenedAt |
| + } |
| + return r.Outcome != "" && !r.ReleasePending && r.EffectsDone |
| + }) |
| + rec := w.record() |
| + switch { |
| + case r.Outcome != "done" || r.Warning != "" || r.Phase != "done": |
| + t.Fatalf("finished %s warning %q", describe(r), r.Warning) |
| + case rec.Move != nil || rec.Region != host.E2ETargetRegion || rec.LastMove == nil || rec.LastMove.Outcome != provision.OfflineOutcomeDone || rec.LastMove.Request == "": |
| + t.Fatalf("record: move %+v region %q last %+v", rec.Move, rec.Region, rec.LastMove) |
| + case len(w.reservations()) != 0: |
| + t.Fatalf("reservations left: %v", w.reservations()) |
| + case r.OpenRecordPending || r.HealthConsecutiveOK < 2 || r.FinishGate != "lifted": |
| + t.Fatalf("row %s open record %v health %d gate %q", describe(r), r.OpenRecordPending, r.HealthConsecutiveOK, r.FinishGate) |
| + } |
| + o := w.openRecord(row.ID) |
| + if openedAt == nil || !o.OpenedAt.Equal(*openedAt) || o.Incarnation != rec.Incarnation || o.From != "" || o.To != host.E2ETargetRegion { |
| + t.Fatalf("open record %+v, opened_at %v", o, openedAt) |
| + } |
| + for _, p := range []string{"restage", "barrier", "stopping", "sealing", "landing", "landed", "opened", "health", "finishing"} { |
| + if !seen[p] { |
| + t.Errorf("the row never showed phase %s (saw %v)", p, seen) |
| + } |
| + } |
| +} |
| + |
| +// openRecord is the move's open record. |
| +func (w *jobWorld) openRecord(id string) moves.OpenRecord { |
| + w.t.Helper() |
| + raw, _, err := w.raw.Get(w.ctx, moves.OpenRecordKey(host.E2EHost, id)) |
| + if err != nil { |
| + w.t.Fatalf("no open record for %s: %v", id, err) |
| + } |
| + var o moves.OpenRecord |
| + if err := json.Unmarshal(raw, &o); err != nil { |
| + w.t.Fatal(err) |
| + } |
| + return o |
| +} |
| + |
| +// TestEveryDeadlineBeforeCommittedOpenAborts: a wait that runs out at |
| +// restage, barrier, stopping, sealing, landing or landed (the boxes down, |
| +// so nothing answers) aborts, naming what it waited for; the abort runs |
| +// once the boxes are back and ends lossless. |
| +func TestEveryDeadlineBeforeCommittedOpenAborts(t *testing.T) { |
| + for _, c := range []struct{ phase, reason string }{ |
| + {"restage", "could not determine the staged copy on ie-box"}, |
| + {"barrier", ""}, |
| + {"stopping", ""}, |
| + {"sealing", "could not determine the seal on ie-box"}, |
| + {"landing", "could not determine the landing on uk-box"}, |
| + {"landed", ""}, |
| + } { |
| + t.Run(c.phase, func(t *testing.T) { |
| + w := newJobWorld(t) |
| + region := w.record().Region |
| + var r *console.SelfServeMove |
| + if c.phase == "restage" { |
| + row := w.admit() |
| + w.watch = row.ID |
| + w.phase(row.ID, "ready", 60) |
| + w.down() |
| + w.markCut(row.ID) |
| + w.consoleUntil(5, "restage", func() bool { return w.row(row.ID).Phase == "restage" }) |
| + r = w.row(row.ID) |
| + } else { |
| + r = w.cutTo(c.phase) |
| + w.down() |
| + if c.phase == "landed" { |
| + // The open's write cannot land (the boxes' reports would |
| + // pass its check): its deadline is the record's. |
| + w.failKinds["open"] = true |
| + } |
| + } |
| + w.tick() |
| + r = w.row(r.ID) |
| + if r.Phase != c.phase { |
| + t.Fatalf("the row moved with the boxes down: %s", describe(r)) |
| + } |
| + w.pastDeadline(r) |
| + w.consoleUntil(4, "the abort", func() bool { return !w.row(r.ID).AbortRequestedAt.IsZero() }) |
| + r = w.row(r.ID) |
| + if c.reason != "" && r.OutcomeReason != c.reason { |
| + t.Fatalf("aborted %q, want %q", r.OutcomeReason, c.reason) |
| + } |
| + if r.OutcomeReason == "" { |
| + t.Fatalf("aborted with no reason: %s", describe(r)) |
| + } |
| + w.up() |
| + r = w.done(r.ID) |
| + w.requireLossless(r, region) |
| + }) |
| + } |
| +} |
| + |
| +// TestDeadlinesMidCopyAndMidSealAbort is Review Focus 3's first half: the |
| +// deadline runs out while the stager is inside its cut round (copy:) or |
| +// the sealer inside its seal (seal:); the abort is initiated, the box's |
| +// work ends, and the abort completes from the real boxes' reports. |
| +func TestDeadlinesMidCopyAndMidSealAbort(t *testing.T) { |
| + for _, c := range []struct{ name, point, phase string }{ |
| + {"mid-copy", host.FaultCopy + host.E2ESourceBox, "restage"}, |
| + {"mid-seal", host.FaultSeal + host.E2ESourceBox, "sealing"}, |
| + } { |
| + t.Run(c.name, func(t *testing.T) { |
| + w := newJobWorld(t) |
| + region := w.record().Region |
| + row := w.toCut() |
| + fired := false |
| + w.e.Fault(c.point, func() { |
| + r := w.row(row.ID) |
| + if fired || r.Phase != c.phase { |
| + return |
| + } |
| + fired = true |
| + w.pastDeadline(r) |
| + w.tick() // the console decides while the box is inside its work |
| + }) |
| + r := w.done(row.ID) |
| + w.e.Fault(c.point, nil) |
| + if !fired { |
| + t.Fatalf("the fault never fired in %s: %s", c.phase, describe(r)) |
| + } |
| + w.requireLossless(r, region) |
| + }) |
| + } |
| +} |
| + |
| +// TestLandedExpiryDefersToTheRecord: the open committed and the console |
| +// stopped before it saw it; restarted after landed's deadline, it finds the |
| +// receipt on the record: opened, never aborted, the expiry cleared, and |
| +// the move runs to done. |
| +func TestLandedExpiryDefersToTheRecord(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("landed") |
| + w.crashWhen = func(p string, _ *console.SelfServeMove) bool { return p == "open:written" } |
| + w.until(10, "the open written", func() bool { return w.crashWhen == nil }) |
| + if rec := w.record(); rec.Move == nil || rec.Move.State != provision.OfflineOpen { |
| + t.Fatalf("the open did not land: %+v", rec.Move) |
| + } |
| + w.restart() |
| + w.pastDeadline(w.row(r.ID)) |
| + w.consoleUntil(3, "opened", func() bool { return w.row(r.ID).Phase == "opened" }) |
| + r = w.row(r.ID) |
| + if !r.AbortRequestedAt.IsZero() || r.ExpiryPending { |
| + t.Fatalf("after the restart: %s abort %v expiry %v %s", describe(r), r.AbortRequestedAt, r.ExpiryPending, r.ExpiryPhase) |
| + } |
| + if r = w.done(r.ID); r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| +} |
| + |
| +// TestOpenRecordPrecedesTheOpen: the open record is written before the open |
| +// transition; a crash between the two and a crash after both recover, the |
| +// open landing at the open record's stamp, once. |
| +func TestOpenRecordPrecedesTheOpen(t *testing.T) { |
| + for _, point := range []string{"open:recorded", "open:issue", "open:written"} { |
| + t.Run(point, func(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("landed") |
| + w.crashWhen = func(p string, _ *console.SelfServeMove) bool { return p == point } |
| + w.until(10, "the crash", func() bool { return w.crashWhen == nil }) |
| + o := w.openRecord(r.ID) |
| + if rec := w.record(); point != "open:written" && rec.Move.State != provision.OfflineLanded { |
| + t.Fatalf("the open landed before the crash point %s: %+v", point, rec.Move) |
| + } |
| + w.restart() |
| + r = w.done(r.ID) |
| + if r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| + if again := w.openRecord(r.ID); !again.OpenedAt.Equal(o.OpenedAt) { |
| + t.Fatalf("the open record changed: %v, was %v", again.OpenedAt, o.OpenedAt) |
| + } |
| + if w.hits["open:write"] != 1 { |
| + t.Fatalf("the open was written %d times", w.hits["open:write"]) |
| + } |
| + }) |
| + } |
| +} |
| + |
| +// TestOpenUncertainIsReconciledByTheRecord: the open's confirmation cannot |
| +// read the record: the row is open-uncertain and stays, paging after 5 |
| +// minutes; once the record reads again its receipt decides: opened. |
| +func TestOpenUncertainIsReconciledByTheRecord(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("landed") |
| + w.at("open:written", func() { w.fs.setUnreadable(true) }) |
| + w.consoleUntil(5, "open-uncertain", func() bool { return w.row(r.ID).Phase == "open-uncertain" }) |
| + for i := 0; i < 3; i++ { |
| + w.tick() |
| + } |
| + if p := w.row(r.ID).Phase; p != "open-uncertain" { |
| + t.Fatalf("the row left open-uncertain while unreadable: %s", p) |
| + } |
| + if _, ok := w.paged(r.ID, "open-uncertain"); ok { |
| + t.Fatal("paged before 5 minutes") |
| + } |
| + w.advance(6 * time.Minute) |
| + w.tick() |
| + if _, ok := w.paged(r.ID, "open-uncertain"); !ok { |
| + t.Fatal("no page after 5 minutes unreadable") |
| + } |
| + w.fs.setUnreadable(false) |
| + w.consoleUntil(3, "opened", func() bool { return w.row(r.ID).Phase == "opened" }) |
| + if r = w.done(r.ID); r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| +} |
| + |
| +// TestOpenUncertainNeverReplaysAnExpiredOpen: open-uncertain with the |
| +// open's PUT uncommitted; the console restarts after the open's deadline; |
| +// the record reads again, still landed: the open is fenced, voided and the |
| +// move aborted, never replayed. And the PUT racing the fence and winning: |
| +// confirmed, opened. |
| +func TestOpenUncertainNeverReplaysAnExpiredOpen(t *testing.T) { |
| + for _, won := range []bool{false, true} { |
| + name := "the put lost" |
| + if won { |
| + name = "the put won the race" |
| + } |
| + t.Run(name, func(t *testing.T) { |
| + w := newJobWorld(t) |
| + region := w.record().Region |
| + r := w.cutTo("landed") |
| + w.fs.setPut(func(key string, body []byte) putFault { |
| + if strings.Contains(string(body), provision.OfflineOpen+`"`) { |
| + return putHeld |
| + } |
| + return putRun |
| + }) |
| + w.at("open:written", func() { w.fs.setUnreadable(true) }) |
| + w.consoleUntil(5, "open-uncertain", func() bool { return w.row(r.ID).Phase == "open-uncertain" }) |
| + w.fs.setPut(nil) |
| + w.restart() |
| + w.pastDeadline(&console.SelfServeMove{StepDeadline: w.row(r.ID).Request.Deadline}) |
| + w.fs.setUnreadable(false) |
| + if won { |
| + w.at("open:fence", func() { |
| + for _, err := range w.fs.release(w.ctx) { |
| + if err != nil { |
| + t.Errorf("the late open: %v", err) |
| + } |
| + } |
| + }) |
| + w.consoleUntil(5, "opened", func() bool { return w.row(r.ID).Phase == "opened" }) |
| + if r = w.done(r.ID); r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| + return |
| + } |
| + w.consoleUntil(5, "the abort", func() bool { return !w.row(r.ID).AbortRequestedAt.IsZero() }) |
| + if got := w.row(r.ID); !got.Request.Voided || w.hits["open:write"] != 1 { |
| + t.Fatalf("the open: %s, written %d times", describe(got), w.hits["open:write"]) |
| + } |
| + for _, err := range w.fs.release(w.ctx) { |
| + if err == nil { |
| + t.Fatal("the held open landed after the fence") |
| + } |
| + } |
| + w.requireLossless(w.done(r.ID), region) |
| + }) |
| + } |
| +} |
| + |
| +// TestAbortIsInitiatedNotCompleted is Review Focus 3: the target lands and |
| +// then stops reporting; the open's deadline aborts; the real sealer lifts |
| +// the tombstone (its reverting report, durable) and the sources revert, so |
| +// the source reopens without the target; the abort finishes, its detail |
| +// naming the target and what it left. |
| +func TestAbortIsInitiatedNotCompleted(t *testing.T) { |
| + w := newJobWorld(t) |
| + region := w.record().Region |
| + r := w.cutTo("landed") |
| + w.e.Box(host.E2ETargetBox).Down() |
| + w.failKinds["open"] = true // the open never lands |
| + w.tick() |
| + w.pastDeadline(w.row(r.ID)) |
| + w.consoleUntil(4, "the abort", func() bool { return !w.row(r.ID).AbortRequestedAt.IsZero() }) |
| + r = w.done(r.ID) |
| + w.requireLossless(r, region) |
| + if r.Warning != "target uk-box did not report; its staged copy is left for cleanup" { |
| + t.Fatalf("the abort's detail %q", r.Warning) |
| + } |
| + sealer, ok := w.report(r.ID, moves.OfflineRoleSealer, host.E2ESourceBox) |
| + if !ok || sealer.Phase != moves.OfflinePhaseReverted || !sealer.TombstoneLifted || sealer.TombstoneLiftedAt.IsZero() { |
| + t.Fatalf("the sealer's report %+v", sealer) |
| + } |
| + if tgt, _ := w.report(r.ID, moves.OfflineRoleTarget, host.E2ETargetBox); tgt.Phase == moves.OfflinePhaseReverted { |
| + t.Fatal("the target reported its revert while down") |
| + } |
| +} |
| + |
| +// TestOpenedBlockedPagesAndRetries: after the open the target does not |
| +// report opened (it is down): past the deadline the move pages, every 10 |
| +// minutes and not more often, keeps waiting and never aborts; the target |
| +// back, it goes on to done. |
| +func TestOpenedBlockedPagesAndRetries(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("landed") |
| + w.e.Box(host.E2ETargetBox).Down() |
| + w.consoleUntil(5, "opened", func() bool { return w.row(r.ID).Phase == "opened" }) |
| + w.pastDeadline(w.row(r.ID)) |
| + w.tick() |
| + first, ok := w.paged(r.ID, "opened") |
| + if !ok { |
| + t.Fatal("no page past the opened deadline") |
| + } |
| + w.advance(5 * time.Minute) |
| + w.tick() |
| + if again, _ := w.paged(r.ID, "opened"); !again.Equal(first) { |
| + t.Fatal("paged again within 10 minutes") |
| + } |
| + w.advance(6 * time.Minute) |
| + w.tick() |
| + if again, _ := w.paged(r.ID, "opened"); !again.After(first) { |
| + t.Fatal("no second page after 10 minutes") |
| + } |
| + if got := w.row(r.ID); got.Phase != "opened" || !got.AbortRequestedAt.IsZero() { |
| + t.Fatalf("the blocked open moved: %s", describe(got)) |
| + } |
| + w.e.Box(host.E2ETargetBox).Up() |
| + if r = w.done(r.ID); r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| +} |
| + |
| +// TestHealthFailureFinishesWithAWarningAndPages: the account never answers: |
| +// every failed probe is recorded and paged (throttled); the window runs |
| +// out and the move finishes done with the warning, which takes precedence |
| +// over the page rule (it does not stay in health). |
| +func TestHealthFailureFinishesWithAWarningAndPages(t *testing.T) { |
| + w := newJobWorld(t) |
| + w.probe = func() (bool, string) { return false, "the probe did not get an answer" } |
| + r := w.cutTo("health") |
| + w.tick() |
| + if _, ok := w.paged(r.ID, "health"); !ok { |
| + t.Fatal("a failed probe did not page") |
| + } |
| + w.pastDeadline(w.row(r.ID)) |
| + w.consoleUntil(4, "finishing", func() bool { return w.row(r.ID).Phase == "finishing" }) |
| + r = w.done(r.ID) |
| + if r.Outcome != "done" || r.Warning != "the account did not answer on uk within 4 minutes" { |
| + t.Fatalf("finished %s warning %q", describe(r), r.Warning) |
| + } |
| + if r.HealthAttempts == 0 || r.HealthConsecutiveOK != 0 || r.HealthLastError == "" { |
| + t.Fatalf("health %d ok %d error %q", r.HealthAttempts, r.HealthConsecutiveOK, r.HealthLastError) |
| + } |
| +} |
| + |
| +// TestHealthExpiryTakesPrecedence: the health window's expiry, on a record |
| +// that is committed open (where every other expiry pages and waits), warns |
| +// and finishes. |
| +func TestHealthExpiryTakesPrecedence(t *testing.T) { |
| + w := newJobWorld(t) |
| + w.probe = func() (bool, string) { return false, "answered 503" } |
| + r := w.cutTo("health") |
| + w.pastDeadline(w.row(r.ID)) |
| + w.tick() |
| + r = w.row(r.ID) |
| + if r.Phase != "finishing" || r.Warning == "" || !r.AbortRequestedAt.IsZero() { |
| + t.Fatalf("after the health expiry: %s warning %q", describe(r), r.Warning) |
| + } |
| +} |
| + |
| +// TestHealthAttemptsPersist: one passing probe, a console restart, then |
| +// another: the consecutive count survived the restart and two passes |
| +// finish the health check. |
| +func TestHealthAttemptsPersist(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("health") |
| + w.consoleUntil(3, "one probe", func() bool { return w.row(r.ID).HealthAttempts == 1 }) |
| + if got := w.row(r.ID); got.HealthConsecutiveOK != 1 || got.HealthFirstOKAt.IsZero() { |
| + t.Fatalf("after one probe: %+v", got) |
| + } |
| + w.restart() |
| + w.tick() // too soon: no probe |
| + if got := w.row(r.ID); got.HealthAttempts != 1 { |
| + t.Fatalf("probed again within 30 seconds: %d", got.HealthAttempts) |
| + } |
| + w.advance(31 * time.Second) |
| + w.consoleUntil(3, "finishing", func() bool { return w.row(r.ID).Phase == "finishing" }) |
| + if got := w.row(r.ID); got.HealthAttempts != 2 || got.HealthConsecutiveOK != 2 { |
| + t.Fatalf("after the restart: attempts %d ok %d", got.HealthAttempts, got.HealthConsecutiveOK) |
| + } |
| +} |
| + |
| +// TestFinishingNeverBypassesTheGate: the source box stops reporting before |
| +// it parks: gate 1 waits past its 10 minutes, pages, and never writes; |
| +// the box back, both gates pass and the move is done. |
| +func TestFinishingNeverBypassesTheGate(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.toCut() |
| + // Gate 1 passes; then the boxes stop, so gate 2's evidence (the sealer |
| + // lifted, the sources gone) never comes. |
| + w.run(200, "gate 2", r.ID, func(r *console.SelfServeMove) bool { return r.Phase == "finishing" && r.PhaseStep == "gate2" }) |
| + w.down() |
| + for i := 0; i < 3; i++ { |
| + w.tick() |
| + } |
| + w.pastDeadline(w.row(r.ID)) |
| + w.tick() |
| + if _, ok := w.paged(r.ID, "finishing"); !ok { |
| + t.Fatal("no page past finishing's 10 minutes") |
| + } |
| + if rec := w.record(); rec.Move == nil || rec.Move.State != provision.OfflineFinishing || w.hits["finish:write"] != 0 { |
| + t.Fatalf("the gate was bypassed: %+v, %d writes", rec.Move, w.hits["finish:write"]) |
| + } |
| + w.up() |
| + if r = w.done(r.ID); r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| +} |
| + |
| +// TestFinaliseResumesAtEveryStep: a crash at each of the finaliser's steps |
| +// (the outcome, the effects, the release, the release recorded) resumes at |
| +// the first unfinished one: one terminal outcome, the reservations |
| +// released, nothing owed. |
| +func TestFinaliseResumesAtEveryStep(t *testing.T) { |
| + for _, point := range []string{"finalise:outcome", "finalise:effects", "finalise:release", "finalise:released"} { |
| + t.Run(point, func(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("finishing") |
| + w.crashWhen = func(p string, _ *console.SelfServeMove) bool { return p == point } |
| + w.run(60, "the crash", r.ID, func(*console.SelfServeMove) bool { return w.crashWhen == nil }) |
| + w.restart() |
| + r = w.done(r.ID) |
| + if r.Outcome != "done" || len(w.reservations()) != 0 { |
| + t.Fatalf("finished %s, reservations %v", describe(r), w.reservations()) |
| + } |
| + open, err := w.cst.OpenSelfServeMoves() |
| + if err != nil || len(open) != 0 { |
| + t.Fatalf("still owed: %v %v", open, err) |
| + } |
| + }) |
| + } |
| +} |
| + |
| +// TestJobYieldsToAnOperatorTransition: an operator's seal and flip doors |
| +// move the record while the job waits: the job follows the record, writes |
| +// neither again, and runs the move to done. |
| +func TestJobYieldsToAnOperatorTransition(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.toCut() |
| + // The job's own seal cannot land: the operator seals. |
| + w.failKinds["seal"] = true |
| + w.run(100, "stopping at its seal", r.ID, func(r *console.SelfServeMove) bool { return r.Phase == "stopping" && r.PhaseStep == "seal" }) |
| + // Wait for the sources' stop, then seal as the operator. |
| + w.until(30, "the operator's seal", func() bool { |
| + code, out := w.door("POST", "/seal", "") |
| + if code != 202 { |
| + t.Logf("seal: %d %s", code, out) |
| + } |
| + return code == 202 |
| + }) |
| + w.failKinds["seal"] = false |
| + w.run(100, "sealing or later", r.ID, func(r *console.SelfServeMove) bool { return jobPhaseOrder[r.Phase] >= jobPhaseOrder["sealing"] }) |
| + if r = w.done(r.ID); r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| +} |
| + |
| +// TestOperatorDoorsFinaliseASelfServeMove: an operator's restage of a |
| +// ready self-serve move keeps the move's own reservation; an operator's |
| +// abort and finish that clear a self-serve move's record route through the |
| +// finaliser: the row gets its outcome first, and the pass releases the |
| +// reservations under its lease. |
| +func TestOperatorDoorsFinaliseASelfServeMove(t *testing.T) { |
| + t.Run("restage keeps the move's reservation", func(t *testing.T) { |
| + w := newJobWorld(t) |
| + row := w.admit() |
| + w.phase(row.ID, "ready", 60) |
| + if code, out := w.door("POST", "/stage", `{"region":"uk"}`); code != 202 { |
| + t.Fatalf("restage = %d %s", code, out) |
| + } |
| + for _, e := range w.reservations() { |
| + if e.ID != row.ID { |
| + t.Fatalf("a reservation of another operation: %+v", e) |
| + } |
| + } |
| + w.markCut(row.ID) |
| + if r := w.done(row.ID); r.Outcome != "done" || len(w.reservations()) != 0 { |
| + t.Fatalf("finished %s, reservations %v", describe(r), w.reservations()) |
| + } |
| + }) |
| + t.Run("the operator's abort of a queued move", func(t *testing.T) { |
| + w := newJobWorld(t) |
| + row := w.admit() |
| + w.down() |
| + w.consoleUntil(10, "reports", func() bool { return w.row(row.ID).Phase == "reports" }) |
| + if code, out := w.door("POST", "/abort", ""); code != 202 { |
| + t.Fatalf("abort = %d %s", code, out) |
| + } |
| + if r := w.row(row.ID); r.Outcome != "aborted" || !r.ReleasePending || len(w.reservations()) == 0 { |
| + t.Fatalf("after the door: %s, release %v, reservations %v", describe(r), r.ReleasePending, w.reservations()) |
| + } |
| + w.tick() |
| + if r := w.row(row.ID); r.ReleasePending || !r.EffectsDone || len(w.reservations()) != 0 { |
| + t.Fatalf("after the pass: %s, reservations %v", describe(r), w.reservations()) |
| + } |
| + }) |
| + t.Run("the operator's finish", func(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("finishing") |
| + // The console's pass stops; the operator finishes the gates as the |
| + // boxes report. |
| + for i := 0; i < 40 && w.record().Move != nil; i++ { |
| + w.boxes() |
| + w.door("POST", "/finish", "") |
| + } |
| + if rec := w.record(); rec.Move != nil { |
| + t.Fatalf("the operator could not finish: %+v", rec.Move) |
| + } |
| + got := w.row(r.ID) |
| + if got.Outcome == "" { |
| + t.Fatalf("the door left the row without its outcome: %s", describe(got)) |
| + } |
| + r = w.done(r.ID) |
| + if r.Outcome != "done" || len(w.reservations()) != 0 { |
| + t.Fatalf("finished %s, reservations %v", describe(r), w.reservations()) |
| + } |
| + }) |
| +} |
| + |
| +// TestSwitchOffMidFlightCompletesAndRendersAfterRestart: the switch is |
| +// turned off and the console restarted mid-cut: recovery mode keeps the |
| +// pass, the move completes, and the operator's view renders its outcome. |
| +func TestSwitchOffMidFlightCompletesAndRendersAfterRestart(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("sealing") |
| + w.switchOff = true |
| + w.restart() |
| + if r = w.done(r.ID); r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| + w.restart() |
| + code, out := w.door("GET", "", "") |
| + if code != 200 || !strings.Contains(out, `"outcome":"done"`) { |
| + t.Fatalf("the view after the restart: %d %s", code, out) |
| + } |
| +} |
| + |
| +// TestOrphanReservationIsPagedAtBootstrap: a reservation no move owns, past |
| +// the grace period, pages from the console's start and every tick after, |
| +// throttled. |
| +func TestOrphanReservationIsPagedAtBootstrap(t *testing.T) { |
| + w := newJobWorld(t) |
| + orphan := "mv_orphanorphanorphanorphanor" |
| + w.putReservation(moves.OfflineReservation{Kind: moves.OfflineKindMove, ID: orphan, Host: host.E2EHost, Account: w.acct, App: host.E2EApp, |
| + ReservedAt: time.Now().Add(-time.Hour).UTC()}) |
| + w.restart() |
| + if _, ok := w.paged(orphan, "reservation"); !ok { |
| + t.Fatal("no page at the console's start") |
| + } |
| +} |
| + |
| +// putReservation writes active.json with e as its one entry, keyed by a |
| +// box id no box has. |
| +func (w *jobWorld) putReservation(e moves.OfflineReservation) { |
| + w.t.Helper() |
| + body, err := json.Marshal(moves.OfflineActiveBody(map[string]moves.OfflineReservation{"gone-box-id": e})) |
| + if err != nil { |
| + w.t.Fatal(err) |
| + } |
| + _, etag, _ := w.raw.Get(w.ctx, moves.OfflineActiveKey) |
| + if _, err := w.raw.Put(w.ctx, moves.OfflineActiveKey, body, etag); err != nil { |
| + w.t.Fatal(err) |
| + } |
| +} |
| + |
| +// secondHost creates another instance's record of the app (no replica on |
| +// the boxes: its moves are only followed to their reservations). |
| +func (w *jobWorld) secondHost(h string) { |
| + w.t.Helper() |
| + if err := provision.CreateRecord(w.ctx, w.raw, provision.Record{Schema: 1, Host: h, Slug: strings.Split(h, ".")[0], App: host.E2EApp, |
| + Account: w.acct, Channel: "stable", CreatedAt: time.Now().UTC()}); err != nil { |
| + w.t.Fatal(err) |
| + } |
| +} |
| + |
| +// reservedBy reports whether active.json holds a reservation of move id. |
| +func (w *jobWorld) reservedBy(id string) bool { |
| + for _, e := range w.reservations() { |
| + if e.ID == id { |
| + return true |
| + } |
| + } |
| + return false |
| +} |
| + |
| +// TestTwoMovesOnOneBoxQueueInOrder: a second move on the same boxes waits |
| +// in reserving, saying why, through the whole of the first's cut, and |
| +// takes the boxes only once the first is finished and released. |
| +func TestTwoMovesOnOneBoxQueueInOrder(t *testing.T) { |
| + w := newJobWorld(t) |
| + first := w.toCut() |
| + w.secondHost("b.shop.example.com") |
| + second := w.admitFor("b.shop.example.com", w.participants()) |
| + said := false |
| + w.run(300, "the first done", first.ID, func(r *console.SelfServeMove) bool { |
| + if r.Outcome == "" { |
| + s := w.row(second.ID) |
| + if s.Phase != "reserving" && s.Phase != "requested" || w.reservedBy(second.ID) { |
| + t.Fatalf("the second moved while the first is %s: %s", r.Phase, describe(s)) |
| + } |
| + said = said || s.Reason == "waiting for another move on this box" |
| + } |
| + return r.Outcome != "" && !r.ReleasePending |
| + }) |
| + if !said { |
| + t.Fatalf("the second never said why it waits: %s", describe(w.row(second.ID))) |
| + } |
| + w.consoleUntil(10, "the second reserved", func() bool { |
| + s := w.row(second.ID) |
| + return w.reservedBy(second.ID) || s.Phase != "reserving" |
| + }) |
| +} |
| + |
| +// TestTwoMovesOnDisjointBoxesRunAtOnce: a move pinned to other boxes |
| +// reserves them while the first is mid-cut on its own: both reservations |
| +// are held at once. |
| +func TestTwoMovesOnDisjointBoxesRunAtOnce(t *testing.T) { |
| + w := newJobWorld(t) |
| + first := w.cutTo("sealing") |
| + w.secondHost("c.shop.example.com") |
| + disjoint := provision.Participants{ |
| + Source: []provision.Participant{{BoxID: "x-box-id", Label: "x-box", InstanceID: "i-x"}}, |
| + Target: provision.Participant{BoxID: "y-box-id", Label: "y-box", InstanceID: "i-y"}, |
| + } |
| + for _, p := range []provision.Participant{disjoint.Source[0], disjoint.Target} { |
| + if err := status.WriteBox(w.ctx, w.raw, status.Box{Label: p.Label, GeneratedAt: time.Now().Add(-time.Hour).UTC(), |
| + Metrics: &status.BoxMetrics{BoxID: p.BoxID, InstanceID: p.InstanceID}}); err != nil { |
| + t.Fatal(err) |
| + } |
| + } |
| + other := w.admitFor("c.shop.example.com", disjoint) |
| + w.consoleUntil(5, "both reserved", func() bool { return w.reservedBy(other.ID) && w.reservedBy(first.ID) }) |
| + if r := w.row(first.ID); r.Outcome != "" { |
| + t.Fatalf("the first ended: %s", describe(r)) |
| + } |
| + if r := w.done(first.ID); r.Outcome != "done" { |
| + t.Fatalf("the first finished %s", describe(r)) |
| + } |
| +} |
| + |
| +// TestExpiredOpenIsNeverReplayed: the open's write is held (the store has |
| +// not committed it) past the open's deadline: the expiry is decided, the |
| +// record fenced, the request voided and the move aborted; the held write |
| +// never lands after the fence, and the open is written once. |
| +func TestExpiredOpenIsNeverReplayed(t *testing.T) { |
| + w := newJobWorld(t) |
| + region := w.record().Region |
| + r := w.cutTo("landed") |
| + w.fs.setPut(func(key string, body []byte) putFault { |
| + if strings.Contains(string(body), `"`+provision.OfflineOpen+`"`) { |
| + return putHeld |
| + } |
| + return putRun |
| + }) |
| + w.consoleUntil(3, "the open issued", func() bool { return w.hits["open:write"] > 0 }) |
| + w.fs.setPut(nil) |
| + w.pastDeadline(&console.SelfServeMove{StepDeadline: w.row(r.ID).Request.Deadline}) |
| + w.consoleUntil(5, "the open voided", func() bool { return w.row(r.ID).Request.Voided }) |
| + if w.row(r.ID).AbortRequestedAt.IsZero() { |
| + t.Fatalf("voided without the abort: %s", describe(w.row(r.ID))) |
| + } |
| + for _, err := range w.fs.release(w.ctx) { |
| + if err == nil { |
| + t.Fatal("the held open landed after the fence") |
| + } |
| + } |
| + if w.hits["open:write"] < 1 || w.row(r.ID).Request.Kind == "open" && !w.row(r.ID).Request.Voided { |
| + t.Fatalf("the open: %s", describe(w.row(r.ID))) |
| + } |
| + w.requireLossless(w.done(r.ID), region) |
| +} |
| + |
| +// TestExpiredOpenWhosePutWonIsConfirmed: the held open's write lands while |
| +// the expired request is being fenced: its receipt is on the fenced record, |
| +// so the request is confirmed and the move is opened, never aborted. |
| +func TestExpiredOpenWhosePutWonIsConfirmed(t *testing.T) { |
| + w := newJobWorld(t) |
| + r := w.cutTo("landed") |
| + w.fs.setPut(func(key string, body []byte) putFault { |
| + if strings.Contains(string(body), `"`+provision.OfflineOpen+`"`) { |
| + return putHeld |
| + } |
| + return putRun |
| + }) |
| + w.consoleUntil(3, "the open issued", func() bool { return w.hits["open:write"] > 0 }) |
| + w.fs.setPut(nil) |
| + w.pastDeadline(&console.SelfServeMove{StepDeadline: w.row(r.ID).Request.Deadline}) |
| + landed := 0 |
| + w.at("open:fence", func() { |
| + // The held writes are the open and its bound replays: the same |
| + // write, so exactly one lands. |
| + for _, err := range w.fs.release(w.ctx) { |
| + if err == nil { |
| + landed++ |
| + } |
| + } |
| + }) |
| + w.consoleUntil(5, "opened", func() bool { return w.row(r.ID).Phase == "opened" }) |
| + if landed != 1 { |
| + t.Fatalf("%d of the held opens landed", landed) |
| + } |
| + if got := w.row(r.ID); !got.AbortRequestedAt.IsZero() { |
| + t.Fatalf("an open that landed was aborted: %s", describe(got)) |
| + } |
| + if r = w.done(r.ID); r.Outcome != "done" { |
| + t.Fatalf("finished %s", describe(r)) |
| + } |
| +} |
amadan