carlos / platform Public

Download this file

1	package console
2
3	import (
4	"context"
5	"crypto/rand"
6	"encoding/json"
7	"errors"
8	"fmt"
9	"net/http"
10	"os"
11	"path/filepath"
12	"strings"
13	"sync"
14	"testing"
15	"time"
16
17	"github.com/carlosframework/platform/internal/alerting"
18	"github.com/carlosframework/platform/internal/hostclaim"
19	"github.com/carlosframework/platform/internal/hostfence"
20	"github.com/carlosframework/platform/internal/hostfloor"
21	"github.com/carlosframework/platform/internal/hostops"
22	"github.com/carlosframework/platform/internal/moves"
23	"github.com/carlosframework/platform/internal/provision"
24	"github.com/carlosframework/platform/internal/release"
25	"github.com/carlosframework/platform/internal/svcrole"
26	)
27
28	// The console's move pass (moves Plan 5 Task 7; claim Plan 10's
29	// Recovery.Moves hook under the move-recovery grant). The decision table is
30	// tested on values; every action is then driven end to end through the real
31	// recovery pass (ControlWriter.RecoveryPass over hostops.Recovery.Pass) on a
32	// host-claim console whose move the door started.
33
34	// ---- the decision, on values ----
35
36	var mvT0 = time.Date(2026, 10, 10, 12, 0, 0, 0, time.UTC)
37
38	func mvClaim(kind, phase string, mut ...func(*hostclaim.Claim)) *hostclaim.Claim {
39	c := &hostclaim.Claim{Holder: &hostclaim.Holder{Incarnation: "inc"},
40	Op: hostclaim.Op{Kind: kind, Phase: phase, ID: "mv", Exec: "ie-box", Participants: []string{"ie-box", "uk-box"}, StartedAt: mvT0,
41	Intent: map[string]string{"source": "ie-box", "target": "uk-box", "to": "uk"}}}
42	for _, m := range mut {
43	m(c)
44	}
45	return c
46	}
47
48	func mvRecord(state string, mut ...func(*provision.Record)) provision.Record {
49	at := mvT0
50	r := provision.Record{Region: "ie", Move: &provision.MoveState{ID: "mv", Incarnation: "inc", From: "ie", To: "uk", State: state, RequestedAt: mvT0}}
51	switch state {
52	case provision.MoveLanding, provision.MoveCommitted:
53	r.Region = "uk"
54	r.Move.FlippedAt = &at
55	}
56	if state == provision.MoveCommitted {
57	r.Move.CommittedAt = &at
58	}
59	if state == provision.MoveRollingBack {
60	r.Move.FlippedAt = &at
61	r.Move.Rollback = &provision.MoveRollback{ID: "rb", TargetPhase: provision.RbTargetReleasing, SourcePhase: provision.RbSourceWaiting}
62	}
63	for _, m := range mut {
64	m(&r)
65	}
66	return r
67	}
68
69	func mvAt(d time.Duration) *time.Time { t := mvT0.Add(d); return &t }
70
71	func TestRecoveryPassWritesOnlyDecidedHalves(t *testing.T) {
72	now := mvT0.Add(time.Minute)
73	for _, c := range []struct {
74	name string
75	claim *hostclaim.Claim
76	rec provision.Record
77	action moveRecoveryAction
78	half hostops.MoveRecoveryClaimAction
79	}{
80	{"record landing, claim moving/sealed: the flip half", mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed), mvRecord(provision.MoveLanding), moveActClaim, hostops.RecoveryMoveFlip},
81	{"record committed, claim landing/probed: the commit half", mvClaim(hostclaim.KindLanding, hostclaim.PhaseLandingProbed), mvRecord(provision.MoveCommitted), moveActClaim, hostops.RecoveryMoveCommit},
82	{"record rolling_back, claim landing: the rollback half", mvClaim(hostclaim.KindLanding, "probing"), mvRecord(provision.MoveRollingBack), moveActClaim, hostops.RecoveryMoveRollback},
83	{"record rolling_back, claim moving/sealed: RollBackFlipped (K22)", mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed), mvRecord(provision.MoveRollingBack), moveActClaim, hostops.RecoveryMoveRollback},
84	{"record landing, claim landing: in step", mvClaim(hostclaim.KindLanding, "probing"), mvRecord(provision.MoveLanding), moveActNone, ""},
85	{"record cutting, claim moving/sealed: no decision", mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed), mvRecord(provision.MoveCutting), moveActNone, ""},
86	{"record committed, claim landing/probing: the claim is behind the probe", mvClaim(hostclaim.KindLanding, "probing"), mvRecord(provision.MoveCommitted), moveActNone, ""},
87	{"record committed, claim landing/committed, stamps missing", mvClaim(hostclaim.KindLanding, hostclaim.PhaseCommitted), mvRecord(provision.MoveCommitted), moveActNone, ""},
88	{"record landing without its flip stamp", mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed), mvRecord(provision.MoveLanding, func(r *provision.Record) { r.Move.FlippedAt = nil }), moveActNone, ""},
89	{"record rolling_back in the target's region", mvClaim(hostclaim.KindLanding, "probing"), mvRecord(provision.MoveRollingBack, func(r *provision.Record) { r.Region = "uk" }), moveActNone, ""},
90	{"record preparing, claim moving: nothing yet", mvClaim(hostclaim.KindMoving, hostclaim.PhaseMoving), mvRecord(provision.MovePreparing), moveActNone, ""},
91	{"another move's record", mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed), mvRecord(provision.MoveLanding, func(r *provision.Record) { r.Move.ID = "other" }), moveActNone, ""},
92	{"another incarnation's record", mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed), mvRecord(provision.MoveLanding, func(r *provision.Record) { r.Move.Incarnation = "old" }), moveActNone, ""},
93	{"a relocating claim is region HA's", mvClaim(hostclaim.KindRelocating, "pinning"), mvRecord(provision.MoveRelocating), moveActNone, ""},
94	} {
95	t.Run(c.name, func(t *testing.T) {
96	got := decideMoveRecovery(moveRecoveryInput{Now: now, Claim: c.claim, Rec: c.rec})
97	if got.Action != c.action || got.Claim != c.half {
98	t.Fatalf("decided %+v, want %s %s", got, c.action, c.half)
99	}
100	})
101	}
102	}
103
104	// One eligible action per observation, in the brief's order: a pending
105	// claim half comes before the deadline, the deadline before a close, the
106	// lost target's stamp before the close it enables.
107	func TestRecoveryPassOneActionPerObservation(t *testing.T) {
108	past := mvT0.Add(-time.Hour)
109	// Flip half pending and the landing deadline passed: the half first.
110	d := decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed),
111	Rec: mvRecord(provision.MoveLanding, func(r *provision.Record) { r.Move.LandingDeadline = &past })})
112	if d.Action != moveActClaim || d.Claim != hostops.RecoveryMoveFlip {
113	t.Fatalf("flip and deadline: %+v", d)
114	}
115	// With the claim in step, the deadline.
116	d = decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindLanding, "probing"),
117	Rec: mvRecord(provision.MoveLanding, func(r *provision.Record) { r.Move.LandingDeadline = &past })})
118	if d.Action != moveActRecord || d.Record != hostops.RecoveryMoveDeadlineRollback {
119	t.Fatalf("the deadline: %+v", d)
120	}
121	// The earlier of the cut and landing deadlines (J11).
122	d = decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindLanding, "probing"),
123	Rec: mvRecord(provision.MoveLanding, func(r *provision.Record) { r.Move.CutDeadline = &past; r.Move.LandingDeadline = mvAt(time.Hour) })})
124	if d.Action != moveActRecord {
125	t.Fatalf("the cut deadline: %+v", d)
126	}
127	// A lost, released target: the stamp, never the close it enables.
128	lost := func(c *hostclaim.Claim) { c.Lost = []string{"uk-box"}; c.Op.Participants = []string{"ie-box"} }
129	rb := func(r *provision.Record) {
130	r.Move.Rollback.TargetPhase, r.Move.Rollback.SourcePhase = provision.RbTargetReleased, provision.RbSourceOpened
131	r.Move.Rollback.RecoveredAt, r.Move.Rollback.OpenedAt = mvAt(0), mvAt(0)
132	}
133	d = decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindRestoring, hostclaim.PhaseOpened, lost), Rec: mvRecord(provision.MoveRollingBack, rb)})
134	if d.Action != moveActStampLost {
135	t.Fatalf("the lost target: %+v", d)
136	}
137	// A chore of the target's region still owed: neither.
138	owed := func(c *hostclaim.Claim) {
139	c.Obligations = []hostclaim.Obligation{{ID: "o", Op: "mv", Kind: "park-replica", Region: "uk", Owner: "region:uk"}}
140	}
141	d = decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindRestoring, hostclaim.PhaseOpened, lost, owed), Rec: mvRecord(provision.MoveRollingBack, rb)})
142	if d.Action != moveActNone {
143	t.Fatalf("the lost target with its region's chore owed: %+v", d)
144	}
145	// Every close waits for the op's chores (the grant's rule, M4).
146	stamped := func(r *provision.Record) { r.Move.OpenedAt, r.Move.SourceParkedAt = mvAt(0), mvAt(0) }
147	d = decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindLanding, hostclaim.PhaseCommitted, owed), Rec: mvRecord(provision.MoveCommitted, stamped)})
148	if d.Action != moveActNone {
149	t.Fatalf("a close with a chore owed: %+v", d)
150	}
151	d = decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindLanding, hostclaim.PhaseCommitted), Rec: mvRecord(provision.MoveCommitted, stamped)})
152	if d.Action != moveActClose || d.Record != hostops.RecoveryMoveClose {
153	t.Fatalf("the committed close: %+v", d)
154	}
155	for _, c := range []struct {
156	claim *hostclaim.Claim
157	rec provision.Record
158	want hostops.MoveRecoveryRecordAction
159	}{
160	{mvClaim(hostclaim.KindRestoring, hostclaim.PhaseOpened), mvRecord(provision.MoveRollingBack, rb, func(r *provision.Record) { r.Move.Rollback.TargetParkedAt = mvAt(0) }), hostops.RecoveryMoveRolledBackClose},
161	{mvClaim(hostclaim.KindReverting, hostclaim.PhaseOpened), mvRecord(provision.MoveReverting, func(r *provision.Record) { r.Move.ReopenedAt = mvAt(0) }), hostops.RecoveryMoveRevertClose},
162	} {
163	if d := decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: c.claim, Rec: c.rec}); d.Action != moveActClose || d.Record != c.want {
164	t.Fatalf("%s/%s: %+v, want close %s", c.claim.Op.Kind, c.claim.Op.Phase, d, c.want)
165	}
166	}
167	// An abort the console never closes (fix round 1, ruling 1): only the
168	// source closes it, after it retired its own state. Due, it is at most
169	// a page.
170	if d := decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindMoving, hostclaim.PhaseAborting), Rec: mvRecord(provision.MoveAborting)}); d.Action != moveActAbortOverdue || d.Record != "" {
171	t.Fatalf("a due abort: %+v, want only the overdue check", d)
172	}
173	// The record closed, the claim not released: the release.
174	closed := func(r *provision.Record) {
175	r.Move, r.LastMove = nil, &provision.MoveOutcome{ID: "mv", Outcome: "done", At: mvT0}
176	}
177	d = decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindLanding, hostclaim.PhaseCommitted), Rec: mvRecord(provision.MoveCommitted, closed)})
178	if d.Action != moveActClaim || d.Claim != hostops.RecoveryMoveRelease {
179	t.Fatalf("the release from LastMove: %+v", d)
180	}
181	}
182
183	// ---- the pass, end to end ----
184
185	// movePassWorld is a host-claim console whose move the request door
186	// started (j17StartedMove), with the console's own move pass bound as the
187	// Recovery.Moves hook, pages captured from the armed alert sinks, and the
188	// pass's clock under the test's control.
189	type movePassWorld struct {
190	fx *consoleFixture
191	id string
192	auth hostclaim.FenceAuthority
193	clock time.Time
194	mu sync.Mutex
195	pages []pagePayload
196	}
197
198	type pagePayload struct{ Kind, Level, Subject, Body string }
199
200	func newMovePassWorld(t *testing.T, fx *consoleFixture, id string) *movePassWorld {
201	t.Helper()
202	w := &movePassWorld{fx: fx, id: id, clock: time.Now().UTC()}
203	fx.srv.movesClock = func() time.Time { w.mu.Lock(); defer w.mu.Unlock(); return w.clock }
204	alerting.Arm(&alerting.Sinks{WebhookURL: "http://pages.test/hook", Post: func(_ string, body []byte) error {
205	var p pagePayload
206	if err := json.Unmarshal(body, &p); err != nil {
207	return err
208	}
209	w.mu.Lock()
210	w.pages = append(w.pages, p)
211	w.mu.Unlock()
212	return nil
213	}})
214	t.Cleanup(func() { alerting.Arm(nil) })
215	return w
216	}
217
218	func (w *movePassWorld) advance(d time.Duration) {
219	w.mu.Lock()
220	w.clock = w.clock.Add(d)
221	w.mu.Unlock()
222	}
223
224	// pass runs one console recovery pass with only the moves hook live.
225	func (w *movePassWorld) pass(t *testing.T) {
226	t.Helper()
227	a := w.fx.srv.cfg.ClaimAuthority
228	nop := func(context.Context) error { return nil }
229	nopObs := func(context.Context, hostclaim.Observed) error { return nil }
230	r := hostops.Recovery{Moves: w.fx.srv.movesRecovery, MoveLogs: w.fx.srv.drainMoveLog, MoveFenceAuthority: w.auth,
231	Controller: hostops.Controller{Store: w.fx.srv.cfg.Releases, Control: a.Control, Authority: a, Now: time.Now, NewID: claimOperationID},
232	Purge: nopObs, Placement: nopObs, SweepRecords: nop, SweepPurges: nop, SweepAdmissions: nop}
233	if err := a.Control.RecoveryPass(context.Background(), r); err != nil {
234	t.Fatalf("the recovery pass: %v", err)
235	}
236	}
237
238	// passErr is one recovery pass, returning its error.
239	func (w *movePassWorld) passErr() error {
240	a := w.fx.srv.cfg.ClaimAuthority
241	nop := func(context.Context) error { return nil }
242	nopObs := func(context.Context, hostclaim.Observed) error { return nil }
243	r := hostops.Recovery{Moves: w.fx.srv.movesRecovery, MoveLogs: w.fx.srv.drainMoveLog, MoveFenceAuthority: w.auth,
244	Controller: hostops.Controller{Store: w.fx.srv.cfg.Releases, Control: a.Control, Authority: a, Now: time.Now, NewID: claimOperationID},
245	Purge: nopObs, Placement: nopObs, SweepRecords: nop, SweepPurges: nop, SweepAdmissions: nop}
246	return a.Control.RecoveryPass(context.Background(), r)
247	}
248
249	func (w *movePassWorld) claim(t *testing.T) *hostclaim.Claim {
250	t.Helper()
251	o, err := hostclaim.Read(context.Background(), w.fx.rel, "acme.go.tito.io")
252	if err != nil || o.Absent {
253	t.Fatalf("read the claim: %v", err)
254	}
255	return o.Claim
256	}
257
258	func (w *movePassWorld) record(t *testing.T) provision.Record {
259	t.Helper()
260	rec, err := provision.GetRecord(context.Background(), w.fx.rel, "bab", "titogo", "acme.go.tito.io")
261	if err != nil || rec == nil {
262	t.Fatalf("read the record: %v", err)
263	}
264	return *rec
265	}
266
267	// setClaim rewrites the claim under the raw bucket, as a box would.
268	func (w *movePassWorld) setClaim(t *testing.T, mut func(*hostclaim.Claim)) {
269	t.Helper()
270	ctx := context.Background()
271	obs, err := hostclaim.Read(ctx, w.fx.rel, "acme.go.tito.io")
272	if err != nil {
273	t.Fatal(err)
274	}
275	if _, err := hostclaim.Update(ctx, w.fx.rel, obs, func(c *hostclaim.Claim) error { mut(c); return nil }); err != nil {
276	t.Fatalf("rewrite the claim: %v", err)
277	}
278	}
279
280	func (w *movePassWorld) startEffect(t *testing.T) hostops.Effect {
281	t.Helper()
282	a, err := hostops.ReadAdmission(context.Background(), w.fx.rel, "bab", "titogo", claimMoveAppID)
283	if err != nil {
284	t.Fatal(err)
285	}
286	return a.Value.Effects[w.id]
287	}
288
289	// setStartEffect rewrites the move-start effect of the admission object.
290	func (w *movePassWorld) setStartEffect(t *testing.T, mut func(*hostops.Effect)) {
291	t.Helper()
292	ctx := context.Background()
293	body, etag, err := w.fx.rel.Get(ctx, "apps/bab/titogo/admission.json")
294	if err != nil {
295	t.Fatal(err)
296	}
297	var a hostops.AppAdmission
298	if err := json.Unmarshal(body, &a); err != nil {
299	t.Fatal(err)
300	}
301	e := a.Effects[w.id]
302	mut(&e)
303	a.Effects[w.id] = e
304	if body, err = json.Marshal(a); err != nil {
305	t.Fatal(err)
306	}
307	if _, err := w.fx.rel.Put(ctx, "apps/bab/titogo/admission.json", body, etag); err != nil {
308	t.Fatal(err)
309	}
310	}
311
312	func (w *movePassWorld) paged(t *testing.T) []pagePayload {
313	t.Helper()
314	w.mu.Lock()
315	defer w.mu.Unlock()
316	return append([]pagePayload(nil), w.pages...)
317	}
318
319	func startedMovePass(t *testing.T, code string) *movePassWorld {
320	t.Helper()
321	fx, _, _, id := j17StartedMove(t, code)
322	return newMovePassWorld(t, fx, id)
323	}
324
325	func landingMovePass(t *testing.T, code string) *movePassWorld {
326	t.Helper()
327	fx, _, _ := j4LandingMove(t, code)
328	return newMovePassWorld(t, fx, j17MoveState(t, fx).ID)
329	}
330
331	func newRollbackID(t *testing.T) string {
332	t.Helper()
333	id, err := moves.NewRollbackID(rand.Reader)
334	if err != nil {
335	t.Fatal(err)
336	}
337	return id
338	}
339
340	// TestRecoveryPassRollsBackAtTheLandingDeadline: a landing past the earlier
341	// of its deadlines is rolled back by the record (one pass), and the claim
342	// follows on the next (the rollback half). Each pass writes one object.
343	func TestRecoveryPassRollsBackAtTheLandingDeadline(t *testing.T) {
344	w := landingMovePass(t, "code-mvpass-deadline")
345	claim := claimBytes(t, w.fx, "acme.go.tito.io")
346	w.pass(t)
347	if m := w.record(t).Move; m.State != provision.MoveLanding {
348	t.Fatalf("rolled back before the deadline: %+v", m)
349	}
350	past := time.Now().UTC().Add(-time.Minute)
351	j17SetRecord(t, w.fx, func(r *provision.Record) { r.Move.LandingDeadline = &past })
352	w.pass(t)
353	rec := w.record(t)
354	if rec.Move.State != provision.MoveRollingBack || rec.Move.Rollback == nil || rec.Move.Rollback.Reason != provision.RollbackLandingDeadline || rec.Region != "ie" {
355	t.Fatalf("the deadline's rollback: region %s %+v", rec.Region, rec.Move)
356	}
357	if claimBytes(t, w.fx, "acme.go.tito.io") != claim {
358	t.Fatal("the pass that wrote the record wrote the claim too")
359	}
360	w.pass(t)
361	c := w.claim(t)
362	if c.Op.Kind != hostclaim.KindRestoring || c.Op.ID != w.id {
363	t.Fatalf("the claim did not follow the rollback: %+v", c.Op)
364	}
365	if after := w.record(t); after.Move.Rollback.ID != rec.Move.Rollback.ID || after.RecordSeq != rec.RecordSeq {
366	t.Fatalf("the claim's pass wrote the record: %+v", after.Move)
367	}
368	}
369
370	// TestRecoveryPassSettlesAnOrphanStartThenReleases (K3): the request door's
371	// record write was lost, so the claim is moving/"" and the record carries no
372	// move, with the start effect uncertain. Under ten minutes the pass leaves
373	// it. After, it settles the start not-applied from record_seq (no handle),
374	// and on the next pass releases the claim to serving under the source. A
375	// landing orphan is paged once and never released.
376	func TestRecoveryPassSettlesAnOrphanStartThenReleases(t *testing.T) {
377	w := startedMovePass(t, "code-mvpass-orphan")
378	j17SetRecord(t, w.fx, func(r *provision.Record) { r.Move = nil })
379	w.setStartEffect(t, func(e *hostops.Effect) { e.State, e.ResultReference = "uncertain", "" })
380	w.pass(t)
381	if c := w.claim(t); c.Op.Kind != hostclaim.KindMoving || w.startEffect(t).State != "uncertain" {
382	t.Fatalf("acted inside ten minutes: claim %+v effect %+v", c.Op, w.startEffect(t))
383	}
384	w.setClaim(t, func(c *hostclaim.Claim) { c.Op.StartedAt = time.Now().UTC().Add(-11 * time.Minute) })
385	w.pass(t)
386	if e := w.startEffect(t); e.State != "complete" || e.ResultReference != "not-applied" {
387	t.Fatalf("the start was not settled: %+v", e)
388	}
389	if c := w.claim(t); c.Op.Kind != hostclaim.KindMoving {
390	t.Fatalf("the settling pass released too: %+v", c.Op)
391	}
392	w.pass(t)
393	c := w.claim(t)
394	if c.Op.Kind != hostclaim.KindServing || c.Op.Exec != "ie-box" || hostclaim.RequireReleasedMove(w.id)(c) != nil {
395	t.Fatalf("the orphan was not released: %+v", c.Op)
396	}
397	if p := w.paged(t); len(p) != 0 {
398	t.Fatalf("a moving orphan paged: %+v", p)
399	}
400
401	// A landing orphan pages once, and is left.
402	l := landingMovePass(t, "code-mvpass-orphan-landing")
403	j17SetRecord(t, l.fx, func(r *provision.Record) { r.Move = nil })
404	before := claimBytes(t, l.fx, "acme.go.tito.io")
405	l.pass(t)
406	l.pass(t)
407	if claimBytes(t, l.fx, "acme.go.tito.io") != before {
408	t.Fatal("a landing orphan's claim was written")
409	}
410	p := l.paged(t)
411	if len(p) != 1 || p[0].Level != alerting.LevelIncident || !strings.Contains(p[0].Subject, "acme.go.tito.io") || !strings.Contains(p[0].Body, l.id) {
412	t.Fatalf("the landing orphan's pages: %+v", p)
413	}
414	}
415
416	// oneBoxFenceAuthority is c7MoveAuthority with the one-box-region check the
417	// grant's Convert needs (the console's hostfence.ClaimFenceAuthority has
418	// both).
419	type oneBoxFenceAuthority struct{ c7MoveAuthority }
420
421	func (oneBoxFenceAuthority) CheckOneBoxRegion(context.Context, string, string) error { return nil }
422
423	// TestRecoveryPassConvertsAFencedSourceInTwoPasses (K13): a source
424	// terminated before the flip. The first pass writes the record's relocation
425	// decision, the second the claim's conversion to relocating.
426	func TestRecoveryPassConvertsAFencedSourceInTwoPasses(t *testing.T) {
427	w := startedMovePass(t, "code-mvpass-convert")
428	w.auth = oneBoxFenceAuthority{c7MoveAuthority{region: "ie"}}
429	w.pass(t)
430	if m := w.record(t).Move; m.State != provision.MovePreparing {
431	t.Fatalf("converted with no fence: %+v", m)
432	}
433	terminatedSourceFence(t, w.fx, "ie-box", "uk-box")
434	w.pass(t)
435	if m := w.record(t).Move; m.State != provision.MoveRelocating {
436	t.Fatalf("the decision pass: %+v", m)
437	}
438	if c := w.claim(t); c.Op.Kind != hostclaim.KindMoving {
439	t.Fatalf("the decision pass converted the claim: %+v", c.Op)
440	}
441	w.pass(t)
442	if c := w.claim(t); c.Op.Kind != hostclaim.KindRelocating || c.Op.Phase != "pinning" || c.Op.ID != w.id {
443	t.Fatalf("the conversion pass: %+v", c.Op)
444	}
445	w.pass(t) // a relocating claim is region HA's: nothing
446	if c := w.claim(t); c.Op.Kind != hostclaim.KindRelocating {
447	t.Fatalf("after the conversion: %+v", c.Op)
448	}
449	}
450
451	// lostTargetRollback puts the landing world into a rollback whose target
452	// box was lost and released: the source recovered and opened, the claim
453	// restoring/opened under the source.
454	func lostTargetRollback(t *testing.T, w *movePassWorld) {
455	t.Helper()
456	w.setClaim(t, func(c *hostclaim.Claim) {
457	c.Op.Kind, c.Op.Phase, c.Op.Exec = hostclaim.KindRestoring, hostclaim.PhaseOpened, "ie-box"
458	c.Lost = []string{"uk-box"}
459	c.Op.Participants = []string{"ie-box"}
460	c.Op.Intent["to"] = "uk"
461	c.Obligations = nil
462	})
463	rb, at := newRollbackID(t), time.Now().UTC().Add(-time.Hour)
464	deadline := at.Add(15 * time.Minute)
465	j17SetRecord(t, w.fx, func(r *provision.Record) {
466	r.Region = "ie"
467	r.Move.State = provision.MoveRollingBack
468	r.Move.Rollback = &provision.MoveRollback{ID: rb, RequestedAt: &at, Reason: provision.RollbackDeclaredLost, TargetPhase: provision.RbTargetReleased,
469	SourcePhase: provision.RbSourceOpened, RecoveredAt: &at, OpenedAt: &at, ReleaseDeadline: &deadline}
470	})
471	}
472
473	// TestRecoveryPassStampsALostTargetThenCloses (p10 Task G): with the target
474	// lost and released and nothing of its box or region owed, the pass stamps
475	// target_parked_at through the grant; the close follows once overdue, then
476	// the release.
477	func TestRecoveryPassStampsALostTargetThenCloses(t *testing.T) {
478	w := landingMovePass(t, "code-mvpass-lost")
479	lostTargetRollback(t, w)
480	w.pass(t)
481	rb := w.record(t).Move.Rollback
482	if rb.TargetParkedAt == nil || rb.TargetPhase != provision.RbTargetCleaned {
483	t.Fatalf("the lost target was not stamped: %+v", rb)
484	}
485	w.pass(t)
486	if w.record(t).Move == nil {
487	t.Fatal("closed inside the boxes' grace")
488	}
489	w.advance(moveCloseGrace + time.Minute)
490	w.pass(t)
491	rec := w.record(t)
492	if rec.Move != nil || rec.LastMove == nil || rec.LastMove.Outcome != "rolled_back" {
493	t.Fatalf("not closed: %+v %+v", rec.Move, rec.LastMove)
494	}
495	if c := w.claim(t); c.Op.Kind != hostclaim.KindRestoring {
496	t.Fatalf("the close's pass released too: %+v", c.Op)
497	}
498	w.pass(t)
499	if c := w.claim(t); c.Op.Kind != hostclaim.KindServing || c.Op.Exec != "ie-box" {
500	t.Fatalf("not released: %+v", c.Op)
501	}
502	}
503
504	// committedAndOpened puts the landing world at a committed, opened and
505	// source-parked move with nothing owed: the close is due.
506	func committedAndOpened(t *testing.T, w *movePassWorld) {
507	t.Helper()
508	w.setClaim(t, func(c *hostclaim.Claim) { c.Op.Phase, c.Obligations = hostclaim.PhaseCommitted, nil })
509	at := time.Now().UTC().Add(-time.Hour)
510	j17SetRecord(t, w.fx, func(r *provision.Record) {
511	r.Move.State, r.Move.LandingPhase = provision.MoveCommitted, provision.LandProbed
512	r.Move.CommittedAt, r.Move.OpenedAt, r.Move.SourceParkedAt = &at, &at, &at
513	})
514	}
515
516	// TestRecoveryPassFinishesTheClose: a close the boxes did not write within
517	// moveCloseGrace is overdue. The pass pages it once, closes the record
518	// (LastMove done) and, on the next pass, releases under the target.
519	func TestRecoveryPassFinishesTheClose(t *testing.T) {
520	w := landingMovePass(t, "code-mvpass-close")
521	committedAndOpened(t, w)
522	w.pass(t)
523	if w.record(t).Move == nil || len(w.paged(t)) != 0 {
524	t.Fatalf("closed or paged inside the grace: %+v", w.paged(t))
525	}
526	w.advance(moveCloseGrace + time.Minute)
527	w.pass(t)
528	rec := w.record(t)
529	if rec.Move != nil || rec.LastMove == nil || rec.LastMove.ID != w.id || rec.LastMove.Outcome != "done" {
530	t.Fatalf("not closed: %+v %+v", rec.Move, rec.LastMove)
531	}
532	if c := w.claim(t); c.Op.Kind != hostclaim.KindLanding || c.Op.Phase != hostclaim.PhaseCommitted {
533	t.Fatalf("released in the close's pass: %+v", c.Op)
534	}
535	if p := w.paged(t); len(p) != 1 || p[0].Level != alerting.LevelWarning || !strings.Contains(p[0].Body, w.id) {
536	t.Fatalf("the overdue close's page: %+v", p)
537	}
538	w.pass(t)
539	c := w.claim(t)
540	if c.Op.Kind != hostclaim.KindServing || c.Op.Exec != "uk-box" || hostclaim.RequireReleasedMove(w.id)(c) != nil {
541	t.Fatalf("not released under the target: %+v", c.Op)
542	}
543	if len(w.paged(t)) != 1 {
544	t.Fatalf("paged again: %+v", w.paged(t))
545	}
546	}
547
548	// TestRecordFirstCloseCrashIsFinishedByThePass (ruling M4): a box closed the
549	// record and crashed before the claim's release. The record carries
550	// LastMove and no move; the claim is still in the move's closing op. The
551	// console's pass releases from LastMove, under the executor the outcome
552	// names, with no grace (the release is the record's decision).
553	func TestRecordFirstCloseCrashIsFinishedByThePass(t *testing.T) {
554	for _, c := range []struct {
555	name, outcome, exec string
556	setup func(*testing.T, *movePassWorld)
557	}{
558	{"committed", "done", "uk-box", func(t *testing.T, w *movePassWorld) {
559	w.setClaim(t, func(c *hostclaim.Claim) { c.Op.Phase, c.Obligations = hostclaim.PhaseCommitted, nil })
560	}},
561	{"rolled back", "rolled_back", "ie-box", func(t *testing.T, w *movePassWorld) {
562	w.setClaim(t, func(c *hostclaim.Claim) {
563	c.Op.Kind, c.Op.Phase, c.Op.Exec, c.Obligations = hostclaim.KindRestoring, hostclaim.PhaseOpened, "ie-box", nil
564	})
565	}},
566	} {
567	t.Run(c.name, func(t *testing.T) {
568	w := landingMovePass(t, "code-mvpass-crash-"+strings.ReplaceAll(c.name, " ", "-"))
569	c.setup(t, w)
570	j17SetRecord(t, w.fx, func(r *provision.Record) {
571	if c.outcome == "rolled_back" {
572	r.Region = "ie"
573	}
574	r.Move, r.LastMove = nil, &provision.MoveOutcome{ID: w.id, Outcome: c.outcome, At: time.Now().UTC()}
575	})
576	w.pass(t)
577	got := w.claim(t)
578	if got.Op.Kind != hostclaim.KindServing || got.Op.Exec != c.exec || hostclaim.RequireReleasedMove(w.id)(got) != nil {
579	t.Fatalf("not released: %+v", got.Op)
580	}
581	})
582	}
583	t.Run("reverted", func(t *testing.T) {
584	w := startedMovePass(t, "code-mvpass-crash-reverted")
585	w.setClaim(t, func(c *hostclaim.Claim) {
586	c.Op.Kind, c.Op.Phase, c.Obligations = hostclaim.KindReverting, hostclaim.PhaseOpened, nil
587	if c.Op.Journal == nil {
588	c.Op.Journal = map[string]string{}
589	}
590	c.Op.Journal[hostclaim.JournalRevPhase] = hostclaim.PhaseOpened
591	})
592	j17SetRecord(t, w.fx, func(r *provision.Record) {
593	r.Move, r.LastMove = nil, &provision.MoveOutcome{ID: w.id, Outcome: "rolled_back", At: time.Now().UTC()}
594	})
595	w.pass(t)
596	got := w.claim(t)
597	if got.Op.Kind != hostclaim.KindServing || got.Op.Exec != "ie-box" || hostclaim.RequireReleasedMove(w.id)(got) != nil {
598	t.Fatalf("not released: %+v", got.Op)
599	}
600	})
601	t.Run("aborted", func(t *testing.T) {
602	w := startedMovePass(t, "code-mvpass-crash-aborted")
603	w.setClaim(t, func(c *hostclaim.Claim) { c.Op.Phase, c.Obligations = hostclaim.PhaseAborting, nil })
604	j17SetRecord(t, w.fx, func(r *provision.Record) {
605	r.Move, r.LastMove = nil, &provision.MoveOutcome{ID: w.id, Outcome: "aborted", At: time.Now().UTC()}
606	})
607	w.pass(t)
608	got := w.claim(t)
609	if got.Op.Kind != hostclaim.KindServing || got.Op.Exec != "ie-box" || hostclaim.RequireReleasedMove(w.id)(got) != nil {
610	t.Fatalf("not released: %+v", got.Op)
611	}
612	})
613	}
614
615	// TestRecoveryPassAbortsAfterSixHours (K18): a move still preparing
616	// moves.AbortAfter after its request is aborted through ConsoleMove; before
617	// that the pass pages once at an hour and writes nothing.
618	// Preflight L29: the 60-minute preparing page and the six-hour abort run
619	// from one start, moves.PreparingSince (the later of the request and the
620	// readiness), so the two can never disagree about how long a move prepared.
621	func TestPreparingPageRunsFromPreparingSince(t *testing.T) {
622	ready := mvAt(30 * time.Minute)
623	for name, c := range map[string]struct {
624	ready *time.Time
625	at time.Duration
626	want bool
627	}{
628	"an hour after the request": {nil, time.Hour, true},
629	"short of it": {nil, time.Hour - time.Second, false},
630	"an hour after the request, ready 30": {ready, time.Hour, false},
631	"an hour after the readiness": {ready, 90 * time.Minute, true},
632	} {
633	rec := mvRecord(provision.MovePreparing, func(r *provision.Record) { r.Move.ReadyAt = c.ready })
634	now := mvT0.Add(c.at)
635	d := decideMoveRecovery(moveRecoveryInput{Now: now, Claim: mvClaim(hostclaim.KindMoving, hostclaim.PhaseMoving), Rec: rec})
636	paged := false
637	for _, k := range d.Pages {
638	paged = paged || k == movePagePreparing
639	}
640	if paged != c.want {
641	t.Errorf("%s: preparing page %v, want %v (pages %v)", name, paged, c.want, d.Pages)
642	}
643	if since := moves.PreparingSince(rec.Move); paged != !now.Before(since.Add(movePreparingPage)) {
644	t.Errorf("%s: the page does not run from moves.PreparingSince (%v)", name, since)
645	}
646	}
647	}
648
649	func TestRecoveryPassAbortsAfterSixHours(t *testing.T) {
650	w := startedMovePass(t, "code-mvpass-abort")
651	claim := claimBytes(t, w.fx, "acme.go.tito.io")
652	requested := w.record(t).Move.RequestedAt
653	w.advance(30 * time.Minute)
654	w.pass(t)
655	if len(w.paged(t)) != 0 {
656	t.Fatalf("paged at 30 minutes: %+v", w.paged(t))
657	}
658	w.advance(time.Hour)
659	w.pass(t)
660	w.pass(t)
661	if m := w.record(t).Move; m.State != provision.MovePreparing {
662	t.Fatalf("aborted early: %+v", m)
663	}
664	p := w.paged(t)
665	if len(p) != 1 || p[0].Level != alerting.LevelWarning || !strings.Contains(p[0].Subject, "acme.go.tito.io") {
666	t.Fatalf("the hour's page: %+v", p)
667	}
668	w.mu.Lock()
669	w.clock = requested.Add(moves.AbortAfter + time.Minute)
670	w.mu.Unlock()
671	w.pass(t)
672	if m := w.record(t).Move; m.State != provision.MoveAborting {
673	t.Fatalf("not aborted at six hours: %+v", m)
674	}
675	if claimBytes(t, w.fx, "acme.go.tito.io") != claim {
676	t.Fatal("the abort wrote the claim (the source's abort takes it to aborting)")
677	}
678	}
679
680	// TestRecoveryPassNeverClosesAnAbort (fix round 1, ruling 1): the source's
681	// retirement of its own state is blocked, so it never closes the aborting
682	// record, though nothing is owed under the op. The console does not close
683	// it either: once the abort has been due past the lane's horizon (the
684	// claim's quiet_after for the target region) plus moveCloseGrace, it pages
685	// once, and the record stays aborting.
686	func TestRecoveryPassNeverClosesAnAbort(t *testing.T) {
687	w := startedMovePass(t, "code-mvpass-abort-blocked")
688	horizon := w.clock.Add(20 * time.Minute)
689	w.setClaim(t, func(c *hostclaim.Claim) {
690	c.Op.Phase, c.Obligations = hostclaim.PhaseAborting, nil
691	if c.QuietAfter == nil {
692	c.QuietAfter = map[string]time.Time{}
693	}
694	c.QuietAfter["uk"] = horizon
695	})
696	j17SetRecord(t, w.fx, func(r *provision.Record) { r.Move.State = provision.MoveAborting })
697	claim := claimBytes(t, w.fx, "acme.go.tito.io")
698	w.pass(t)
699	w.advance(moveCloseGrace + time.Minute)
700	w.pass(t)
701	if len(w.paged(t)) != 0 {
702	t.Fatalf("paged before the lane's horizon plus the grace: %+v", w.paged(t))
703	}
704	w.advance(20 * time.Minute) // past quiet_after + the grace
705	w.pass(t)
706	w.advance(2 * time.Hour)
707	w.pass(t)
708	w.pass(t)
709	if m := w.record(t).Move; m == nil || m.State != provision.MoveAborting {
710	t.Fatalf("the console closed the abort: %+v %+v", m, w.record(t).LastMove)
711	}
712	if claimBytes(t, w.fx, "acme.go.tito.io") != claim {
713	t.Fatal("the console wrote the aborting claim")
714	}
715	p := w.paged(t)
716	if len(p) != 1 || p[0].Level != alerting.LevelWarning || !strings.Contains(p[0].Body, w.id) || !strings.Contains(p[0].Body, "ie-box") {
717	t.Fatalf("the overdue abort's pages: %+v", p)
718	}
719	}
720
721	// TestConsolePagesThroughAlerting (§13, M14; fix round 1, ruling 3): the
722	// pass pages through alerting.Page on the armed sinks. A rollback waiting
723	// past its release deadline is an incident, paged again only a full hour
724	// after the last attempt: two passes either side of a whole hour since the
725	// deadline do not both page. The last attempt's time is durable, in the
726	// console's store, so a restarted console keeps the spacing.
727	func TestConsolePagesThroughAlerting(t *testing.T) {
728	w := landingMovePass(t, "code-mvpass-pages")
729	rb, at := newRollbackID(t), w.clock.Add(-74*time.Minute)
730	deadline := at.Add(15 * time.Minute) // 59 minutes ago
731	j17SetRecord(t, w.fx, func(r *provision.Record) {
732	r.Region = "ie"
733	r.Move.State = provision.MoveRollingBack
734	r.Move.Rollback = &provision.MoveRollback{ID: rb, RequestedAt: &at, Reason: provision.RollbackLandingDeadline, TargetPhase: provision.RbTargetReleasing,
735	SourcePhase: provision.RbSourceWaiting, ReleaseDeadline: &deadline}
736	})
737	w.setClaim(t, func(c *hostclaim.Claim) { c.Op.Kind, c.Op.Phase = hostclaim.KindRestoring, hostclaim.PhaseClaimed })
738	first := w.clock
739	w.pass(t)
740	p := w.paged(t)
741	if len(p) != 1 || p[0].Kind != "page" || p[0].Level != alerting.LevelIncident || !strings.Contains(p[0].Subject, "uk") || !strings.Contains(p[0].Body, w.id) {
742	t.Fatalf("the release deadline's page: %+v", p)
743	}
744	// Across the whole hour since the deadline (59 to 61 minutes): no page.
745	w.advance(2 * time.Minute)
746	w.pass(t)
747	if len(w.paged(t)) != 1 {
748	t.Fatalf("paged again two minutes later, across the hour since the deadline: %+v", w.paged(t))
749	}
750	// A restarted console: the in-memory state is gone, the store is not.
751	w.fx.srv.moveCloseSeen = nil
752	if last, ok, err := w.fx.st.MovePageAttempt("release-deadline acme.go.tito.io " + w.id); err != nil || !ok || !last.Equal(first.Truncate(time.Second)) {
753	t.Fatalf("the last attempt's durable time: %v %v %v, want %v", last, ok, err, first)
754	}
755	w.advance(56 * time.Minute) // 58 minutes after the first page
756	w.pass(t)
757	if len(w.paged(t)) != 1 {
758	t.Fatalf("paged again inside the hour: %+v", w.paged(t))
759	}
760	w.advance(3 * time.Minute) // 61 minutes after the first page
761	w.pass(t)
762	if len(w.paged(t)) != 2 {
763	t.Fatalf("not paged again a full hour after the last attempt: %+v", w.paged(t))
764	}
765	}
766
767	// moveLogOf is the move's log as written to the deployment bucket.
768	func moveLogOf(t *testing.T, w *movePassWorld) map[string]moves.LogEvent {
769	t.Helper()
770	got, err := moves.ReadLog(context.Background(), w.fx.rel, moves.ReportPrefix("bab", "titogo", "acme.go.tito.io", w.id))
771	if err != nil {
772	t.Fatal(err)
773	}
774	out := map[string]moves.LogEvent{}
775	for _, ev := range got {
776	out[ev.Identity] = ev
777	}
778	return out
779	}
780
781	// Plan 6 Task 3 fix round 1, ruling 3, and fix round 3: the console's move
782	// pass logs the transitions it makes: the close and the claim's release after
783	// it, the landing deadline's rollback, and the six-hour abort. Each entry is
784	// the console's, under the identity the box would give it, queued in the
785	// console's outbox and delivered by the pass's drainer (drainMoveLog).
786	func TestRecoveryPassWritesTheMoveLog(t *testing.T) {
787	t.Run("close and release", func(t *testing.T) {
788	w := landingMovePass(t, "code-mvpass-log-close")
789	committedAndOpened(t, w)
790	w.pass(t) // the close's grace runs from the pass's first sighting
791	w.advance(moveCloseGrace + time.Minute)
792	w.pass(t) // the close
793	w.pass(t) // the claim's release
794	log := moveLogOf(t, w)
795	done, released := log["done"], log["claim-released"]
796	if done.Event != "done" || done.Actor != "console" || done.Op != w.id || released.Event != "claim_released" || released.Actor != "console" {
797	t.Fatalf("log %+v", log)
798	}
799	if done.Fields["offline_s"] == "" || done.Fields["from"] != "ie" {
800	t.Fatalf("the close's entry lacks its evidence: %+v", done.Fields)
801	}
802	noPendingLog(t, w)
803	})
804	t.Run("deadline rollback", func(t *testing.T) {
805	w := landingMovePass(t, "code-mvpass-log-deadline")
806	past := time.Now().UTC().Add(-time.Minute)
807	j17SetRecord(t, w.fx, func(r *provision.Record) { r.Move.LandingDeadline = &past })
808	w.pass(t)
809	if ev := moveLogOf(t, w)["rolling_back"]; ev.Event != "rolling_back" || ev.Actor != "console" || ev.Fields["reason"] == "" {
810	t.Fatalf("log %+v", moveLogOf(t, w))
811	}
812	})
813	t.Run("six-hour abort", func(t *testing.T) {
814	w := startedMovePass(t, "code-mvpass-log-abort")
815	requested := w.record(t).Move.RequestedAt
816	w.mu.Lock()
817	w.clock = requested.Add(moves.AbortAfter + time.Minute)
818	w.mu.Unlock()
819	w.pass(t)
820	if ev := moveLogOf(t, w)["aborting"]; ev.Event != "aborting" || ev.Actor != "console" {
821	t.Fatalf("log %+v", moveLogOf(t, w))
822	}
823	})
824	}
825
826	// blockMoveLog makes every write under the move's log fail (a file where
827	// its directory goes) until the returned func is called.
828	func blockMoveLog(t *testing.T, w *movePassWorld) func() {
829	t.Helper()
830	root := w.fx.rel.(*deletableStore).root
831	p := filepath.Join(root, filepath.FromSlash(moves.ReportPrefix("bab", "titogo", "acme.go.tito.io", w.id)+"log"))
832	if err := os.MkdirAll(filepath.Dir(p), 0o755); err != nil {
833	t.Fatal(err)
834	}
835	if err := os.WriteFile(p, nil, 0o644); err != nil {
836	t.Fatal(err)
837	}
838	return func() {
839	if err := os.Remove(p); err != nil {
840	t.Fatal(err)
841	}
842	}
843	}
844
845	// blockMoveLogEntry makes the write of one entry fail (a directory where its
846	// object goes) until the returned func is called.
847	func blockMoveLogEntry(t *testing.T, w *movePassWorld, name string) func() {
848	t.Helper()
849	root := w.fx.rel.(*deletableStore).root
850	p := filepath.Join(root, filepath.FromSlash(moves.LogKeyFor(moves.ReportPrefix("bab", "titogo", "acme.go.tito.io", w.id), name)))
851	if err := os.MkdirAll(p, 0o755); err != nil {
852	t.Fatal(err)
853	}
854	return func() {
855	if err := os.Remove(p); err != nil {
856	t.Fatal(err)
857	}
858	}
859	}
860
861	func pendingLog(t *testing.T, w *movePassWorld) []string {
862	t.Helper()
863	got, err := w.fx.st.MoveLogPending("acme.go.tito.io", w.id)
864	if err != nil {
865	t.Fatal(err)
866	}
867	var names []string
868	for _, e := range got {
869	n := e.Name
870	if !e.Confirmed {
871	n += "(unconfirmed)"
872	}
873	if e.Held {
874	n += "(held)"
875	}
876	names = append(names, n)
877	}
878	return names
879	}
880
881	func noPendingLog(t *testing.T, w *movePassWorld) {
882	t.Helper()
883	if p := pendingLog(t, w); len(p) != 0 {
884	t.Fatalf("entries still pending: %v", p)
885	}
886	}
887
888	// Fix round 3, ruling 1: the console's log delivery is the pass's drainer,
889	// independent of any move's state or grant, and no release waits for it. A
890	// row whose write fails is retried with backoff, indefinitely, and warned of
891	// once in the journal when it is an hour old; it is still delivered after
892	// the claim's release.
893	func TestRecoveryPassLogOutboxRetries(t *testing.T) {
894	journal := captureLog(t)
895	w := landingMovePass(t, "code-mvpass-outbox-close")
896	committedAndOpened(t, w)
897	w.pass(t)
898	w.advance(moveCloseGrace + time.Minute)
899	unblock := blockMoveLog(t, w)
900	w.pass(t) // the close; its entry is queued and its delivery fails
901	if rec := w.record(t); rec.Move != nil {
902	t.Fatalf("not closed: %+v", rec.Move)
903	}
904	w.pass(t) // the release does not wait for the log
905	if c := w.claim(t); c.Op.Kind != hostclaim.KindServing {
906	t.Fatalf("the release waited for the log: %+v", c.Op)
907	}
908	if p := pendingLog(t, w); strings.Join(p, " ") != "done claim-released" {
909	t.Fatalf("pending %v, want the close's and the release's entries", p)
910	}
911	for i := 0; i < 8; i++ { // over an hour of failing passes
912	w.advance(10 * time.Minute)
913	w.pass(t)
914	}
915	for i := 0; i < 6; i++ { // and more failed attempts after the warning
916	w.advance(30 * time.Minute)
917	w.pass(t)
918	}
919	if n := strings.Count(journal.String(), "unwritten for over an hour"); n != 2 {
920	t.Fatalf("%d hour-old warnings, want one per row:\n%s", n, journal.String())
921	}
922	unblock()
923	w.advance(2 * time.Hour) // past any backoff
924	w.pass(t)
925	log := moveLogOf(t, w)
926	if log["done"].Actor != "console" || log["claim-released"].Event != "claim_released" {
927	t.Fatalf("log %+v", log)
928	}
929	noPendingLog(t, w)
930	}
931
932	// Fix round 3, ruling 2: claim_released is published only from a successful
933	// release. The pass queues it unconfirmed before the release and confirms it
934	// after; the drainer delivers confirmed rows only, and settles an unconfirmed
935	// one by the claim.
936	func TestClaimReleasedIsPublishedOnlyAfterTheRelease(t *testing.T) {
937	closed := func(t *testing.T, code string) *movePassWorld {
938	w := landingMovePass(t, code)
939	committedAndOpened(t, w)
940	w.pass(t)
941	w.advance(moveCloseGrace + time.Minute)
942	w.pass(t) // the close
943	return w
944	}
945	t.Run("a release that fails publishes nothing", func(t *testing.T) {
946	w := closed(t, "code-mvpass-release-fails")
947	w.fx.srv.moveReleaseFault = func() error { return hostops.ErrPending }
948	w.pass(t)
949	if c := w.claim(t); c.Op.Kind == hostclaim.KindServing {
950	t.Fatal("released despite the fault")
951	}
952	if _, ok := moveLogOf(t, w)["claim-released"]; ok {
953	t.Fatal("claim_released published for a release that failed")
954	}
955	if p := pendingLog(t, w); strings.Join(p, " ") != "claim-released(unconfirmed)" {
956	t.Fatalf("pending %v", p)
957	}
958	w.pass(t) // the claim is still held: the row is left for the release
959	if _, ok := moveLogOf(t, w)["claim-released"]; ok {
960	t.Fatal("claim_released published while the claim is held")
961	}
962	w.fx.srv.moveReleaseFault = nil
963	w.pass(t)
964	if ev := moveLogOf(t, w)["claim-released"]; ev.Event != "claim_released" {
965	t.Fatalf("not published after the release: %+v", moveLogOf(t, w))
966	}
967	noPendingLog(t, w)
968	})
969	t.Run("a crash between the release and its confirmation", func(t *testing.T) {
970	w := closed(t, "code-mvpass-release-crash")
971	unblock := blockMoveLogEntry(t, w, "claim-released")
972	w.pass(t) // the release; its entry is confirmed, its delivery fails
973	if c := w.claim(t); c.Op.Kind != hostclaim.KindServing {
974	t.Fatalf("not released: %+v", c.Op)
975	}
976	// As if the console stopped after the release and before the confirm.
977	if _, err := w.fx.st.db.Exec(`UPDATE move_log_outbox SET confirmed = 0 WHERE op = ? AND name = 'claim-released'`, w.id); err != nil {
978	t.Fatal(err)
979	}
980	unblock()
981	w.advance(2 * time.Hour)
982	w.pass(t)
983	if ev := moveLogOf(t, w)["claim-released"]; ev.Event != "claim_released" {
984	t.Fatalf("the released claim's entry was not confirmed and published: %+v", moveLogOf(t, w))
985	}
986	noPendingLog(t, w)
987	})
988	t.Run("an unconfirmed row whose claim another move holds", func(t *testing.T) {
989	journal := captureLog(t)
990	w := closed(t, "code-mvpass-release-other")
991	body := []byte(`{"v":1}`)
992	if err := w.fx.st.QueueMoveLog("acme.go.tito.io", "mv_another", "claim-released", w.claim(t).Holder.Incarnation, body, false, w.clock); err != nil {
993	t.Fatal(err)
994	}
995	w.pass(t)
996	got, err := w.fx.st.MoveLogPending("acme.go.tito.io", "mv_another")
997	if err != nil || len(got) != 0 {
998	t.Fatalf("pending %+v %v", got, err)
999	}
1000	if !strings.Contains(journal.String(), "mv_another") {
1001	t.Fatalf("no journal line for the dropped row:\n%s", journal.String())
1002	}
1003	})
1004	}
1005
1006	// Fix round 4, ruling 2: a row the drainer cannot settle yet (unconfirmed,
1007	// its claim still the move's) takes the same backoff and one-hour warning as
1008	// a failed delivery, and the batch picks rows by their next attempt, so a
1009	// full batch of them never starves a confirmed row.
1010	func TestUnresolvedMoveLogRowsDoNotStarveTheBatch(t *testing.T) {
1011	journal := captureLog(t)
1012	w := landingMovePass(t, "code-mvpass-starve")
1013	body := func(name string) []byte {
1014	b, err := json.Marshal(moves.LogEvent{V: 1, Op: w.id, Host: "acme.go.tito.io", Event: "x", Identity: name, Actor: "console", At: w.clock})
1015	if err != nil {
1016	t.Fatal(err)
1017	}
1018	return b
1019	}
1020	inc := w.claim(t).Holder.Incarnation
1021	for i := 0; i < moveLogDrainBatch; i++ {
1022	name := fmt.Sprintf("held-%03d", i)
1023	if err := w.fx.st.QueueMoveLog("acme.go.tito.io", w.id, name, inc, body(name), false, w.clock); err != nil {
1024	t.Fatal(err)
1025	}
1026	}
1027	if err := w.fx.st.QueueMoveLog("acme.go.tito.io", w.id, "late", inc, body("late"), true, w.clock); err != nil {
1028	t.Fatal(err)
1029	}
1030	for i := 0; i < 2 && moveLogOf(t, w)["late"].Identity == ""; i++ {
1031	w.pass(t)
1032	}
1033	if moveLogOf(t, w)["late"].Identity != "late" {
1034	t.Fatal("the confirmed row was starved by a full batch of unresolved rows")
1035	}
1036	// The unresolved rows are warned of once, an hour on.
1037	for i := 0; i < 10; i++ {
1038	w.advance(30 * time.Minute)
1039	w.pass(t)
1040	}
1041	if n := strings.Count(journal.String(), "unwritten for over an hour"); n != moveLogDrainBatch {
1042	t.Fatalf("%d hour-old warnings, want one per unresolved row (%d)", n, moveLogDrainBatch)
1043	}
1044	}
1045
1046	// Fix round 4, ruling (b): a real CAS conflict inside g.Claim. Another writer
1047	// updates the claim between the grant's observation and the release's CAS,
1048	// so the release fails: nothing is published, the row stays unconfirmed,
1049	// and a later pass releases, confirms and publishes it.
1050	func TestReleaseCASConflictPublishesNothing(t *testing.T) {
1051	w := landingMovePass(t, "code-mvpass-release-cas")
1052	committedAndOpened(t, w)
1053	w.pass(t)
1054	w.advance(moveCloseGrace + time.Minute)
1055	w.pass(t) // the close
1056	d := w.fx.rel.(*deletableStore)
1057	claimKey, err := hostclaim.Key("acme.go.tito.io")
1058	if err != nil {
1059	t.Fatal(err)
1060	}
1061	conflicts := 0
1062	d.putHook = func(ctx context.Context, key string) {
1063	if key != claimKey || conflicts > 0 {
1064	return
1065	}
1066	conflicts++
1067	body, etag, err := d.Store.Get(ctx, key)
1068	if err != nil {
1069	t.Fatal(err)
1070	}
1071	// The concurrent writer: the same claim, rewritten, so its version
1072	// moves on under the release's CAS.
1073	if _, err := d.Store.Put(ctx, key, append(body, '\n'), etag); err != nil {
1074	t.Fatal(err)
1075	}
1076	}
1077	err = w.passErr()
1078	d.putHook = nil
1079	if conflicts != 1 || !errors.Is(err, release.ErrCASConflict) {
1080	t.Fatalf("the release's claim CAS: conflicts=%d err=%v, want a CAS conflict", conflicts, err)
1081	}
1082	if c := w.claim(t); c.Op.Kind == hostclaim.KindServing {
1083	t.Fatal("released despite the conflict")
1084	}
1085	if _, ok := moveLogOf(t, w)["claim-released"]; ok {
1086	t.Fatal("claim_released published for a release that lost its CAS")
1087	}
1088	if p := pendingLog(t, w); strings.Join(p, " ") != "claim-released(unconfirmed)" {
1089	t.Fatalf("pending %v", p)
1090	}
1091	w.advance(2 * time.Hour) // past the unresolved row's backoff
1092	w.pass(t)
1093	if c := w.claim(t); c.Op.Kind != hostclaim.KindServing {
1094	t.Fatalf("not released on the next pass: %+v", c.Op)
1095	}
1096	if ev := moveLogOf(t, w)["claim-released"]; ev.Event != "claim_released" {
1097	t.Fatalf("not published after the release: %+v", moveLogOf(t, w))
1098	}
1099	noPendingLog(t, w)
1100	}
1101
1102	// Fix round 4, ruling 3: a row is bound to the instance incarnation its
1103	// move's evidence carried, and the writer takes the account and app from the
1104	// host's claim only when its holder is that incarnation, for a move its
1105	// record names. A row for another app's host, a row whose instance was
1106	// recreated under the same names, and the rows of a retired instance are
1107	// never written, and are dropped.
1108	func TestMoveLogRowsAreBoundToTheirIncarnation(t *testing.T) {
1109	w := landingMovePass(t, "code-mvpass-tenancy")
1110	inc := w.claim(t).Holder.Incarnation
1111	entry := func(host, op, name string) []byte {
1112	b, err := json.Marshal(moves.LogEvent{V: 1, Op: op, Host: host, Event: "x", Identity: name, Actor: "console", At: w.clock})
1113	if err != nil {
1114	t.Fatal(err)
1115	}
1116	return b
1117	}
1118	queue := func(host, op, name, inc string) {
1119	t.Helper()
1120	if err := w.fx.st.QueueMoveLog(host, op, name, inc, entry(host, op, name), true, w.clock); err != nil {
1121	t.Fatal(err)
1122	}
1123	}
1124	// Another app's host (the fixture's kass instance, which has no claim
1125	// here), under this instance's incarnation.
1126	queue("kass.carlosapp.dev", w.id, "elsewhere", inc)
1127	// This host, after a recreation under the same names: another incarnation.
1128	queue("acme.go.tito.io", w.id, "stale", strings.Repeat("ef", 32))
1129	// This host and incarnation, but a move its record never named.
1130	queue("acme.go.tito.io", "mv_forged", "forged", inc)
1131	// The instance's own row, written.
1132	queue("acme.go.tito.io", w.id, "genuine", inc)
1133	w.pass(t)
1134	log := moveLogOf(t, w)
1135	if log["genuine"].Identity != "genuine" || log["stale"].Identity != "" {
1136	t.Fatalf("log %+v", log)
1137	}
1138	if forged, err := moves.ReadLog(context.Background(), w.fx.rel, moves.ReportPrefix("bab", "titogo", "acme.go.tito.io", "mv_forged")); err != nil || len(forged) != 0 {
1139	t.Fatalf("a move the record never named was logged: %+v %v", forged, err)
1140	}
1141	// Final fix, ruling 1: a confirmed row the writer refuses is never
1142	// deleted; it is held, with its bytes, until its incarnation's purge.
1143	held := func(host, op string) []string {
1144	t.Helper()
1145	got, err := w.fx.st.MoveLogPending(host, op)
1146	if err != nil {
1147	t.Fatal(err)
1148	}
1149	var names []string
1150	for _, e := range got {
1151	if !e.Held {
1152	t.Fatalf("%s %s %s refused but not held: %+v", host, op, e.Name, e)
1153	}
1154	names = append(names, e.Name)
1155	}
1156	return names
1157	}
1158	if h := held("acme.go.tito.io", w.id); strings.Join(h, " ") != "stale" {
1159	t.Fatalf("held %v, want the stale incarnation's row", h)
1160	}
1161	if h := held("acme.go.tito.io", "mv_forged"); strings.Join(h, " ") != "forged" {
1162	t.Fatalf("held %v, want the forged move's row", h)
1163	}
1164	if h := held("kass.carlosapp.dev", w.id); strings.Join(h, " ") != "elsewhere" {
1165	t.Fatalf("held %v, want the other app's host's row", h)
1166	}
1167	// A claim gone (retired outside the console's door): the instance's own
1168	// row is held too, never written.
1169	queue("acme.go.tito.io", w.id, "retired", inc)
1170	claimKey, err := hostclaim.Key("acme.go.tito.io")
1171	if err != nil {
1172	t.Fatal(err)
1173	}
1174	if err := w.fx.rel.Delete(context.Background(), claimKey); err != nil {
1175	t.Fatal(err)
1176	}
1177	if err := w.passErr(); err != nil {
1178	t.Fatal(err)
1179	}
1180	if h := held("acme.go.tito.io", w.id); strings.Join(h, " ") != "stale retired" {
1181	t.Fatalf("held %v", h)
1182	}
1183	if moveLogOf(t, w)["retired"].Identity != "" {
1184	t.Fatal("a row whose claim is gone was written")
1185	}
1186	}
1187
1188	// Final fix, ruling 1: a confirmed row whose delivery failed, and whose move
1189	// a later move then replaced as the record's last, is refused by the writer
1190	// (the record names neither) and held: never written, never retried, warned
1191	// of once, its bytes kept until its incarnation's purge.
1192	func TestARefusedConfirmedRowIsHeldNotDeleted(t *testing.T) {
1193	journal := captureLog(t)
1194	w := landingMovePass(t, "code-mvpass-held")
1195	committedAndOpened(t, w)
1196	w.pass(t)
1197	w.advance(moveCloseGrace + time.Minute)
1198	unblock := blockMoveLog(t, w)
1199	w.pass(t) // the close; its entry's delivery fails
1200	w.pass(t) // the release
1201	inc := w.claim(t).Holder.Incarnation
1202	j17SetRecord(t, w.fx, func(r *provision.Record) {
1203	r.LastMove = &provision.MoveOutcome{ID: "mv_later", Outcome: "done", At: time.Now().UTC()}
1204	})
1205	unblock()
1206	for i := 0; i < 3; i++ {
1207	w.advance(2 * time.Hour)
1208	w.pass(t)
1209	}
1210	if _, ok := moveLogOf(t, w)["done"]; ok {
1211	t.Fatal("a row whose move the record no longer names was written")
1212	}
1213	got, err := w.fx.st.MoveLogPending("acme.go.tito.io", w.id)
1214	if err != nil {
1215	t.Fatal(err)
1216	}
1217	var done *MoveLogPendingEntry
1218	for i := range got {
1219	if got[i].Name == "done" {
1220	done = &got[i]
1221	}
1222	}
1223	if done == nil || !done.Held || !done.Confirmed || len(done.Body) == 0 {
1224	t.Fatalf("the refused row was not kept and held: %+v", got)
1225	}
1226	if n := strings.Count(journal.String(), "the log of move "+w.id+" at done is held"); n != 1 {
1227	t.Fatalf("%d held warnings, want one:\n%s", n, journal.String())
1228	}
1229	if err := w.fx.st.PurgeMoveLogIncarnation("acme.go.tito.io", inc); err != nil {
1230	t.Fatal(err)
1231	}
1232	if got, _ := w.fx.st.MoveLogPending("acme.go.tito.io", w.id); len(got) != 0 {
1233	t.Fatalf("the incarnation's purge left %+v", got)
1234	}
1235	}
1236
1237	// declaredLostEntries counts the move's log objects named
1238	// rolling_back-target-lost.
1239	func declaredLostEntries(t *testing.T, w *movePassWorld) int {
1240	t.Helper()
1241	got, err := moves.ReadLog(context.Background(), w.fx.rel, moves.ReportPrefix("bab", "titogo", "acme.go.tito.io", w.id))
1242	if err != nil {
1243	t.Fatal(err)
1244	}
1245	n := 0
1246	for _, ev := range got {
1247	if ev.Identity == "rolling_back-target-lost" {
1248	n++
1249	}
1250	}
1251	return n
1252	}
1253
1254	// Final review I4: declared_lost is logged by the console that performs the
1255	// declaration, as claim_released is: queued unconfirmed before the
1256	// declaration, confirmed once it succeeds, and a row left unconfirmed is
1257	// settled by a later pass from the loss the claim records. The declaration
1258	// moves the target on to released within the request, so no box pass ever
1259	// sees it lost; the event is still logged, once.
1260	func TestDeclaredLostIsLoggedByTheConsole(t *testing.T) {
1261	declare := func(t *testing.T, code string) (*movePassWorld, string, string, hostfence.Submission) {
1262	t.Helper()
1263	fx, token, moveURL := j4LandingMove(t, code)
1264	w := newMovePassWorld(t, fx, j17MoveState(t, fx).ID)
1265	c, _, out := rawReq(t, http.MethodPost, moveURL+"/resolve", token, `{"declare_lost":"uk-box"}`)
1266	if c != http.StatusOK {
1267	t.Fatalf("inspect = %d %s", c, out)
1268	}
1269	return w, token, moveURL, j4Submission(t, fx, out)
1270	}
1271	t.Run("the declaration completes before any box pass", func(t *testing.T) {
1272	w, token, moveURL, sub := declare(t, "code-mvlog-declared")
1273	body := j4Body(t, map[string]any{"declare_lost": "uk-box", "submission": sub})
1274	if c, _, out := rawReq(t, http.MethodPost, moveURL+"/resolve", token, body); c != http.StatusAccepted {
1275	t.Fatalf("declare = %d %s", c, out)
1276	}
1277	if rb := w.record(t).Move.Rollback; rb == nil || rb.TargetPhase != provision.RbTargetReleased {
1278	t.Fatalf("the declaration did not move the target on: %+v", rb)
1279	}
1280	w.pass(t)
1281	ev := moveLogOf(t, w)["rolling_back-target-lost"]
1282	if ev.Event != "declared_lost" || ev.Actor != "console" || ev.Op != w.id || ev.Fields["from"] != "ie" || ev.Fields["to"] != "uk" {
1283	t.Fatalf("declared_lost %+v in %+v", ev, moveLogOf(t, w))
1284	}
1285	// A replay of the same declaration, and more passes, log nothing more.
1286	if c, _, out := rawReq(t, http.MethodPost, moveURL+"/resolve", token, body); c != http.StatusAccepted {
1287	t.Fatalf("replay = %d %s", c, out)
1288	}
1289	w.pass(t)
1290	w.pass(t)
1291	if n := declaredLostEntries(t, w); n != 1 {
1292	t.Fatalf("%d declared_lost entries, want one", n)
1293	}
1294	noPendingLog(t, w)
1295	})
1296	t.Run("a crash between the declaration and its confirmation", func(t *testing.T) {
1297	w, token, moveURL, sub := declare(t, "code-mvlog-declared-crash")
1298	if c, _, out := rawReq(t, http.MethodPost, moveURL+"/resolve", token, j4Body(t, map[string]any{"declare_lost": "uk-box", "submission": sub})); c != http.StatusAccepted {
1299	t.Fatalf("declare = %d %s", c, out)
1300	}
1301	// As if the console stopped after the declaration and before the
1302	// confirm.
1303	res, err := w.fx.st.db.Exec(`UPDATE move_log_outbox SET confirmed = 0 WHERE op = ? AND name = 'rolling_back-target-lost'`, w.id)
1304	if err != nil {
1305	t.Fatal(err)
1306	}
1307	if n, _ := res.RowsAffected(); n != 1 {
1308	t.Fatalf("the declaration queued %d rows, want one", n)
1309	}
1310	w.pass(t)
1311	if ev := moveLogOf(t, w)["rolling_back-target-lost"]; ev.Event != "declared_lost" {
1312	t.Fatalf("the committed loss's entry was not settled and published: %+v", moveLogOf(t, w))
1313	}
1314	noPendingLog(t, w)
1315	})
1316	t.Run("a declaration that is refused publishes nothing", func(t *testing.T) {
1317	w, token, moveURL, sub := declare(t, "code-mvlog-declared-stale")
1318	j17SetRecord(t, w.fx, func(r *provision.Record) { r.Move.LandingPhase = provision.LandProbed })
1319	if c, _, out := rawReq(t, http.MethodPost, moveURL+"/resolve", token, j4Body(t, map[string]any{"declare_lost": "uk-box", "submission": sub})); c != http.StatusConflict {
1320	t.Fatalf("stale = %d %s", c, out)
1321	}
1322	if p := pendingLog(t, w); strings.Join(p, " ") != "rolling_back-target-lost(unconfirmed)" {
1323	t.Fatalf("pending %v, want the declaration's row unconfirmed", p)
1324	}
1325	// Final re-review 1, I4: the move can still be declared lost, so the
1326	// row is kept, unpublished, however many passes run.
1327	w.pass(t)
1328	w.advance(2 * time.Hour)
1329	w.pass(t)
1330	if n := declaredLostEntries(t, w); n != 0 {
1331	t.Fatalf("a refused declaration published %d entries", n)
1332	}
1333	if p := pendingLog(t, w); strings.Join(p, " ") != "rolling_back-target-lost(unconfirmed)" {
1334	t.Fatalf("pending %v, want the row kept while the move can still be declared lost", p)
1335	}
1336	// The claim gone (the incarnation retired): the row is dropped.
1337	key, err := hostclaim.Key("acme.go.tito.io")
1338	if err != nil {
1339	t.Fatal(err)
1340	}
1341	if err := w.fx.rel.Delete(context.Background(), key); err != nil {
1342	t.Fatal(err)
1343	}
1344	w.advance(2 * time.Hour)
1345	w.pass(t)
1346	noPendingLog(t, w)
1347	})
1348	// Final re-review 1, I4: the drainer reads the claim with no loss in it;
1349	// the declaration then commits and confirms its row; the drainer, going on
1350	// from its earlier read, must not drop the row. It survives and is
1351	// published once.
1352	t.Run("a declaration that commits while the drainer settles its row", func(t *testing.T) {
1353	w, token, moveURL, sub := declare(t, "code-mvlog-declared-race")
1354	rec := w.record(t)
1355	e, ok := moves.DeclaredLost(rec.Move)
1356	if !ok {
1357	t.Fatal("no entry for the fixture's move")
1358	}
1359	// A declaration in flight: its row queued, its claim CAS not yet.
1360	o := hostops.ConsoleMoveObservation{Host: rec.Host, OpID: rec.Move.ID, Incarnation: rec.Move.Incarnation}
1361	w.fx.srv.queueMoveLogAs(o, e, w.fx.srv.movesNow(), false)
1362	declared := false
1363	w.fx.srv.moveLogSettleHook = func() {
1364	if declared {
1365	return
1366	}
1367	declared = true
1368	if c, _, out := rawReq(t, http.MethodPost, moveURL+"/resolve", token, j4Body(t, map[string]any{"declare_lost": "uk-box", "submission": sub})); c != http.StatusAccepted {
1369	t.Errorf("declare = %d %s", c, out)
1370	}
1371	}
1372	w.pass(t)
1373	if !declared {
1374	t.Fatal("the drainer never settled the row")
1375	}
1376	if p := pendingLog(t, w); strings.Join(p, " ") != "rolling_back-target-lost" {
1377	t.Fatalf("pending %v: the row the declaration confirmed was dropped", p)
1378	}
1379	w.advance(2 * time.Hour)
1380	w.pass(t)
1381	w.pass(t)
1382	if n := declaredLostEntries(t, w); n != 1 {
1383	t.Fatalf("%d declared_lost entries, want one", n)
1384	}
1385	noPendingLog(t, w)
1386	})
1387	// Final re-review 1, I4: a declaration whose row cannot be queued is
1388	// refused, through either door, and nothing is declared.
1389	t.Run("a row that cannot be queued refuses the declaration", func(t *testing.T) {
1390	for _, door := range []string{"move", "host"} {
1391	t.Run(door, func(t *testing.T) {
1392	w, token, moveURL, sub := declare(t, "code-mvlog-declared-noqueue-"+door)
1393	url, body := moveURL+"/resolve", j4Body(t, map[string]any{"declare_lost": "uk-box", "submission": sub})
1394	if door == "host" {
1395	url, body = j4HostDoor(t, w.fx), j4Body(t, map[string]any{"action": "declare-lost", "submission": sub})
1396	}
1397	before := j4World(t, w.fx)
1398	if _, err := w.fx.st.db.Exec(`DROP TABLE move_log_outbox`); err != nil {
1399	t.Fatal(err)
1400	}
1401	if c, _, out := rawReq(t, http.MethodPost, url, token, body); c == http.StatusAccepted || c == http.StatusOK {
1402	t.Fatalf("declare with no outbox = %d %s, want a refusal", c, out)
1403	}
1404	if j4World(t, w.fx) != before {
1405	t.Fatal("a declaration whose log row could not be queued wrote")
1406	}
1407	})
1408	}
1409	})
1410	}
1411
1412	// j4HostDoor registers the host operator door on fx (NewServer registers it
1413	// only with the host claim on at build) and returns its resolve URL for the
1414	// j4 host.
1415	func j4HostDoor(t *testing.T, fx *consoleFixture) string {
1416	t.Helper()
1417	fx.srv.cfg.Bucket = moveTestBucket
1418	fx.srv.cliRoute("POST /api/cli/ops/hosts/{host}/resolve/inspect", svcrole.Set{}, fx.srv.handleAPIHostResolveInspect)
1419	fx.srv.cliRoute("POST /api/cli/ops/hosts/{host}/resolve", svcrole.Set{}, fx.srv.handleAPIHostResolve)
1420	if err := hostfloor.Publish(context.Background(), fx.rel, release.RootSigner(fx.priv), moveTestBucket, hostfloor.Floor{Min: 1, MinRelease: "v1.0.0"}); err != nil {
1421	t.Fatal(err)
1422	}
1423	return fx.ts.URL + "/api/cli/ops/hosts/" + j4Host + "/resolve"
1424	}
1425
1426	// Final re-review 1, N1: only a declaration whose signed consequence is the
1427	// loss of the move's target (the rollback path, move-target-lost) is
1428	// declared_lost. A destroyed-local-only declaration, here for a committed
1429	// move's retired source, changes no move state and logs no move event,
1430	// through either door.
1431	func TestDestroyedLocalOnlyLogsNoMoveEvent(t *testing.T) {
1432	for _, door := range []string{"move", "host"} {
1433	t.Run(door, func(t *testing.T) {
1434	ctx := context.Background()
1435	fx, token, moveURL := j4LandingMove(t, "code-mvlog-localonly-"+door)
1436	w := newMovePassWorld(t, fx, j17MoveState(t, fx).ID)
1437	obs, err := hostclaim.Read(ctx, fx.rel, j4Host)
1438	if err != nil {
1439	t.Fatal(err)
1440	}
1441	if _, err := hostclaim.Update(ctx, fx.rel, obs, func(c *hostclaim.Claim) error {
1442	c.Op.Phase = hostclaim.PhaseCommitted
1443	c.Obligations = append(c.Obligations, hostclaim.Obligation{ID: "local", Op: w.id, Kind: "park-local", Box: "ie-box", Retirement: "ret-local", Owner: "box:ie-box"})
1444	return nil
1445	}); err != nil {
1446	t.Fatal(err)
1447	}
1448	committed := time.Now().UTC()
1449	j17SetRecord(t, fx, func(r *provision.Record) { r.Move.State, r.Move.CommittedAt = provision.MoveCommitted, &committed })
1450	inspectURL, inspectBody, declURL := moveURL+"/resolve", `{"declare_lost":"ie-box"}`, moveURL+"/resolve"
1451	if door == "host" {
1452	base := j4HostDoor(t, fx)
1453	inspectURL, inspectBody, declURL = base+"/inspect", `{"action":"declare-lost","box":"ie-box"}`, base
1454	}
1455	c, _, out := rawReq(t, http.MethodPost, inspectURL, token, inspectBody)
1456	if c != http.StatusOK || !strings.Contains(out, "destroyed-local-only") {
1457	t.Fatalf("inspect = %d %s, want a destroyed-local-only challenge", c, out)
1458	}
1459	sub := j4Submission(t, fx, out)
1460	body := j4Body(t, map[string]any{"declare_lost": "ie-box", "submission": sub})
1461	if door == "host" {
1462	body = j4Body(t, map[string]any{"action": "declare-lost", "submission": sub})
1463	}
1464	if c, _, out := rawReq(t, http.MethodPost, declURL, token, body); c != http.StatusAccepted && c != http.StatusOK {
1465	t.Fatalf("declare = %d %s", c, out)
1466	}
1467	if m := w.record(t).Move; m.State != provision.MoveCommitted {
1468	t.Fatalf("a local-only declaration changed the move: %+v", m)
1469	}
1470	if p := pendingLog(t, w); len(p) != 0 {
1471	t.Fatalf("a local-only declaration queued %v", p)
1472	}
1473	w.pass(t)
1474	if n := declaredLostEntries(t, w); n != 0 {
1475	t.Fatalf("a local-only declaration logged %d declared_lost entries", n)
1476	}
1477	})
1478	}
1479	}
1480
1481	// ---- the target fence (moves after claim Plan 12, Task 5, ruling Q8) ----
1482
1483	// mvTargetFence is a target fence reference, on values.
1484	var mvTargetFence = hostclaim.FenceRef{Enrollment: strings.Repeat("b", 32), Key: "control/box-fences/" + strings.Repeat("b", 32) + ".json", SHA256: strings.Repeat("c", 64)}
1485
1486	// TestRecoveryPassTargetFenceDecision: on values, when the target's fence has
1487	// a step left for the grant, and where it sits in the order (Q8): after the
1488	// flip, ahead of the claim's rollback half and the deadline's rollback, and
1489	// never once the record carries the consumed fence as its evidence. A dirty
1490	// target's fence comes after the rollback half, since the grant takes
1491	// neither half of it.
1492	func TestRecoveryPassTargetFenceDecision(t *testing.T) {
1493	ref := mvTargetFence
1494	past := mvT0.Add(-time.Hour)
1495	target := func(phase string, dirty bool) func(*provision.Record) {
1496	return func(r *provision.Record) { r.Move.Rollback.TargetPhase, r.Move.Rollback.Dirty = phase, dirty }
1497	}
1498	lost := func(key string) func(*provision.Record) {
1499	return func(r *provision.Record) {
1500	r.Move.Rollback.TargetPhase, r.Move.Rollback.LossRef = provision.RbTargetLost, key
1501	}
1502	}
1503	committedLoss := func(r *provision.Record) {
1504	r.Move.Rollback.TargetPhase, r.Move.Rollback.LossRef, r.Move.Rollback.Evidence = provision.RbTargetReleased, ref.Key, ref.Key
1505	}
1506	restoring := func(phase, exec string) *hostclaim.Claim {
1507	return mvClaim(hostclaim.KindRestoring, phase, func(c *hostclaim.Claim) { c.Op.Exec = exec })
1508	}
1509	for _, c := range []struct {
1510	name string
1511	claim *hostclaim.Claim
1512	rec provision.Record
1513	consumed bool
1514	action moveRecoveryAction
1515	half hostops.MoveRecoveryClaimAction
1516	}{
1517	{"moving/sealed, record landing: the flip, never the fence", mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed), mvRecord(provision.MoveLanding), false, moveActClaim, hostops.RecoveryMoveFlip},
1518	{"a landing: the fence rolls the record back", mvClaim(hostclaim.KindLanding, "probing"), mvRecord(provision.MoveLanding), false, moveActFence, ""},
1519	{"a landing past its deadline: the fence, not the deadline's rollback", mvClaim(hostclaim.KindLanding, "probing"),
1520	mvRecord(provision.MoveLanding, func(r *provision.Record) { r.Move.LandingDeadline = &past }), false, moveActFence, ""},
1521	{"rolling back, the claim landing: the fence, not the rollback half", mvClaim(hostclaim.KindLanding, "probing"), mvRecord(provision.MoveRollingBack), false, moveActFence, ""},
1522	{"rolling back, the target lost under this fence: the fence (its claim half)", mvClaim(hostclaim.KindLanding, "probing"), mvRecord(provision.MoveRollingBack, lost(ref.Key)), false, moveActFence, ""},
1523	{"rolling back, the target lost under another loss (J4): not the fence", restoring(hostclaim.PhaseReleased, "none"), mvRecord(provision.MoveRollingBack, lost("control/host-loss/other")), false, moveActNone, ""},
1524	{"released clean, the claim restoring/releasing under the target: the fence", restoring(hostclaim.PhaseReleasing, "uk-box"), mvRecord(provision.MoveRollingBack, target(provision.RbTargetReleased, false)), false, moveActFence, ""},
1525	{"released clean, the claim past releasing: not the fence", restoring(hostclaim.PhaseClaimed, "ie-box"), mvRecord(provision.MoveRollingBack, target(provision.RbTargetReleased, false)), false, moveActNone, ""},
1526	{"cleaned: nothing left for the fence", restoring(hostclaim.PhaseOpened, "ie-box"), mvRecord(provision.MoveRollingBack, target(provision.RbTargetCleaned, false)), false, moveActNone, ""},
1527	{"dirty, the claim landing: the rollback half first", mvClaim(hostclaim.KindLanding, "probing"), mvRecord(provision.MoveRollingBack, target(provision.RbTargetReleased, true)), false, moveActClaim, hostops.RecoveryMoveRollback},
1528	{"dirty, the claim restoring: the fence (which leaves it to J4)", restoring(hostclaim.PhaseReleasing, "uk-box"), mvRecord(provision.MoveRollingBack, target(provision.RbTargetReleased, true)), false, moveActFence, ""},
1529	{"a committed landing: never the fence", mvClaim(hostclaim.KindLanding, hostclaim.PhaseCommitted), mvRecord(provision.MoveLanding), false, moveActNone, ""},
1530	{"consumed, the loss not yet on the record: the fence", restoring(hostclaim.PhaseReleased, "none"), mvRecord(provision.MoveRollingBack, lost(ref.Key)), true, moveActFence, ""},
1531	{"consumed, LossRef and Evidence the fence: stop", restoring(hostclaim.PhaseReleased, "none"), mvRecord(provision.MoveRollingBack, committedLoss), true, moveActNone, ""},
1532	{"consumed, the target released on its own evidence: stop", restoring(hostclaim.PhaseReleased, "none"), mvRecord(provision.MoveRollingBack, target(provision.RbTargetReleased, false)), true, moveActNone, ""},
1533	} {
1534	t.Run(c.name, func(t *testing.T) {
1535	got := decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: c.claim, Rec: c.rec, TargetFence: &ref, TargetFenceConsumed: c.consumed})
1536	if got.Action != c.action || got.Claim != c.half || got.Record != "" {
1537	t.Fatalf("decided %+v, want %s %s", got, c.action, c.half)
1538	}
1539	})
1540	}
1541	// With no fence, a landing past its deadline is the deadline's rollback,
1542	// as before.
1543	d := decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindLanding, "probing"),
1544	Rec: mvRecord(provision.MoveLanding, func(r *provision.Record) { r.Move.LandingDeadline = &past })})
1545	if d.Action != moveActRecord || d.Record != hostops.RecoveryMoveDeadlineRollback {
1546	t.Fatalf("no fence, past the deadline: %+v", d)
1547	}
1548	}
1549
1550	// fencedTargetWorld is the landing world (j4LandingMove) with its target,
1551	// uk-box, terminated: the regional worker's fence for it in the bucket, and
1552	// the pass's fence authority binding it to uk. calls lists the fences the
1553	// pass's fence calls named.
1554	func fencedTargetWorld(t *testing.T, code string) (*movePassWorld, hostclaim.FenceRef, func() []hostclaim.FenceRef) {
1555	t.Helper()
1556	w := landingMovePass(t, code)
1557	w.auth = oneBoxFenceAuthority{c7MoveAuthority{region: "uk"}}
1558	ref := terminatedSourceFence(t, w.fx, "uk-box", "ie-box")
1559	if c := w.claim(t); c.Op.Intent["target_enrollment"] != ref.Enrollment {
1560	t.Fatalf("the fence is not the target's: %s, claim %s", ref.Enrollment, c.Op.Intent["target_enrollment"])
1561	}
1562	var mu sync.Mutex
1563	var seen []hostclaim.FenceRef
1564	w.fx.srv.moveFenceCall = func(r hostclaim.FenceRef) { mu.Lock(); seen = append(seen, r); mu.Unlock() }
1565	return w, ref, func() []hostclaim.FenceRef {
1566	mu.Lock()
1567	defer mu.Unlock()
1568	return append([]hostclaim.FenceRef(nil), seen...)
1569	}
1570	}
1571
1572	// TestRecoveryPassReleasesAFencedTargetInThreePasses (Q8): a landing whose
1573	// target was terminated. The grant takes one step a pass, record first: the
1574	// record's rollback with the target lost under the fence, then the claim's
1575	// release that consumes it, then the record's loss commit (released, the
1576	// fence as its evidence). Each pass writes one object; the fourth writes
1577	// nothing. The console logs its writes: the rollback, the claim's rollback
1578	// and the target's release.
1579	func TestRecoveryPassReleasesAFencedTargetInThreePasses(t *testing.T) {
1580	w, ref, calls := fencedTargetWorld(t, "code-mvpass-fence")
1581	claim := claimBytes(t, w.fx, j4Host)
1582
1583	w.pass(t)
1584	rec := w.record(t)
1585	rb := rec.Move.Rollback
1586	if rec.Move.State != provision.MoveRollingBack || rec.Region != "ie" || rb == nil || rb.Reason != provision.RollbackTargetFenced || rb.TargetPhase != provision.RbTargetLost || rb.LossRef != ref.Key {
1587	t.Fatalf("the first pass: region %s %+v %+v", rec.Region, rec.Move, rb)
1588	}
1589	if claimBytes(t, w.fx, j4Host) != claim {
1590	t.Fatal("the record's pass wrote the claim too")
1591	}
1592
1593	w.pass(t)
1594	c := w.claim(t)
1595	if got, ok := hostclaim.ConsumedMoveTargetFence(c); !ok || got != ref || c.Op.Kind != hostclaim.KindRestoring {
1596	t.Fatalf("the second pass did not consume the fence: %+v %v %+v", got, ok, c.Op)
1597	}
1598	if after := w.record(t); after.RecordSeq != rec.RecordSeq {
1599	t.Fatalf("the claim's pass wrote the record: %d after %d", after.RecordSeq, rec.RecordSeq)
1600	}
1601
1602	claim = claimBytes(t, w.fx, j4Host)
1603	w.pass(t)
1604	rec = w.record(t)
1605	rb = rec.Move.Rollback
1606	if rb.TargetPhase != provision.RbTargetReleased || rb.Dirty || rb.Evidence != ref.Key || rb.LossRef != ref.Key {
1607	t.Fatalf("the third pass did not commit the loss on the record: %+v", rb)
1608	}
1609	if claimBytes(t, w.fx, j4Host) != claim {
1610	t.Fatal("the record's loss commit wrote the claim")
1611	}
1612
1613	w.pass(t)
1614	if after := w.record(t); after.RecordSeq != rec.RecordSeq || claimBytes(t, w.fx, j4Host) != claim {
1615	t.Fatalf("the fourth pass wrote: record %d after %d", after.RecordSeq, rec.RecordSeq)
1616	}
1617	for i, r := range calls() {
1618	if r != ref {
1619	t.Fatalf("call %d named %+v, not the target's fence %+v", i, r, ref)
1620	}
1621	}
1622	log := moveLogOf(t, w)
1623	if ev := log["rolling_back"]; ev.Actor != "console" || ev.Fields["reason"] != provision.RollbackTargetFenced {
1624	t.Fatalf("the fenced rollback's entry: %+v in %+v", ev, log)
1625	}
1626	if ev := log["rolling_back-target-released"]; ev.Actor != "console" || ev.Event != provision.RbTargetReleased {
1627	t.Fatalf("the loss commit's entry: %+v in %+v", ev, log)
1628	}
1629	if ev := log["claim-rollback"]; ev.Actor != "console" || ev.Event != "claim_rollback" {
1630	t.Fatalf("the claim release's rollback entry: %+v in %+v", ev, log)
1631	}
1632	if p := w.paged(t); len(p) != 0 {
1633	t.Fatalf("a clean fenced target paged: %+v", p)
1634	}
1635	}
1636
1637	// TestRecoveryPassFenceBeatsTheDeadlineRollback (Q8): a landing past its
1638	// deadline whose target was terminated is rolled back by the fence (the
1639	// grant does both halves), not by the deadline.
1640	func TestRecoveryPassFenceBeatsTheDeadlineRollback(t *testing.T) {
1641	w, ref, _ := fencedTargetWorld(t, "code-mvpass-fence-deadline")
1642	past := time.Now().UTC().Add(-time.Minute)
1643	j17SetRecord(t, w.fx, func(r *provision.Record) { r.Move.LandingDeadline = &past })
1644	w.pass(t)
1645	rb := w.record(t).Move.Rollback
1646	if rb == nil || rb.Reason != provision.RollbackTargetFenced || rb.TargetPhase != provision.RbTargetLost || rb.LossRef != ref.Key {
1647	t.Fatalf("the deadline won: %+v", rb)
1648	}
1649	}
1650
1651	// TestRecoveryPassFlipsBeforeTheFence (Q8): with the claim still moving/sealed
1652	// and the record landing, the pass writes the flip and does not call the
1653	// fence (the grant refuses a moving claim). The fence follows on the next
1654	// pass.
1655	func TestRecoveryPassFlipsBeforeTheFence(t *testing.T) {
1656	d := decideMoveRecovery(moveRecoveryInput{Now: mvT0, Claim: mvClaim(hostclaim.KindMoving, hostclaim.PhaseSealed), Rec: mvRecord(provision.MoveLanding), TargetFence: &mvTargetFence})
1657	if d.Action != moveActClaim || d.Claim != hostops.RecoveryMoveFlip {
1658	t.Fatalf("decided %+v, want the flip", d)
1659	}
1660	w, ref, calls := fencedTargetWorld(t, "code-mvpass-fence-flip")
1661	w.setClaim(t, func(c *hostclaim.Claim) {
1662	c.Op.Kind, c.Op.Phase, c.Op.Exec = hostclaim.KindMoving, hostclaim.PhaseSealed, ""
1663	c.Op.Participants = []string{"ie-box", "uk-box"}
1664	})
1665	w.pass(t)
1666	if c := w.claim(t); c.Op.Kind != hostclaim.KindLanding {
1667	t.Fatalf("not flipped: %+v", c.Op)
1668	}
1669	if n := len(calls()); n != 0 {
1670	t.Fatalf("the flip's pass called the fence %d times", n)
1671	}
1672	if m := w.record(t).Move; m.State != provision.MoveLanding {
1673	t.Fatalf("the flip's pass rolled the record back: %+v", m)
1674	}
1675	w.pass(t)
1676	if rb := w.record(t).Move.Rollback; rb == nil || rb.LossRef != ref.Key {
1677	t.Fatalf("the fence did not follow the flip: %+v", rb)
1678	}
1679	}
1680
1681	// TestRecoveryPassLeavesADirtyFencedTargetToJ4AndPagesOnce (Q8): a target
1682	// terminated after it released dirty holds writes the source does not have.
1683	// The grant refuses it (no return lane can be built from a dead box), so the
1684	// pass writes nothing for the fence, pages once that an operator must declare
1685	// the target lost, and leaves it for J4.
1686	func TestRecoveryPassLeavesADirtyFencedTargetToJ4AndPagesOnce(t *testing.T) {
1687	w, _, calls := fencedTargetWorld(t, "code-mvpass-fence-dirty")
1688	rbID := dirtyFencedRollback(t, w)
1689	w.pass(t) // the claim's rollback half, which the fence does not take for a dirty target
1690	if c := w.claim(t); c.Op.Kind != hostclaim.KindRestoring || c.Op.Intent["rollback"] != rbID {
1691	t.Fatalf("the rollback half: %+v", c.Op)
1692	}
1693	if n := len(calls()); n != 0 {
1694	t.Fatalf("the fence was called before the rollback half: %d", n)
1695	}
1696	claim, rec := claimBytes(t, w.fx, j4Host), w.record(t)
1697	w.pass(t)
1698	w.pass(t)
1699	w.advance(2 * time.Hour)
1700	w.pass(t)
1701	if n := len(calls()); n == 0 {
1702	t.Fatal("the fence was never tried: its verification is the page's evidence")
1703	}
1704	if after := w.record(t); after.RecordSeq != rec.RecordSeq || claimBytes(t, w.fx, j4Host) != claim {
1705	t.Fatalf("a dirty fenced target was written: %+v", after.Move.Rollback)
1706	}
1707	p := w.paged(t)
1708	if len(p) != 1 {
1709	t.Fatalf("pages %+v, want one", p)
1710	}
1711	subject, body := moveTargetFencedDirtyPage(j4Host, w.id, "uk-box", "uk", "ie")
1712	if p[0].Level != alerting.LevelIncident || p[0].Subject != subject || p[0].Body != body {
1713	t.Fatalf("the page: %+v", p[0])
1714	}
1715	if !strings.Contains(body, "--declare-lost uk-box") || !strings.Contains(body, j4Host) {
1716	t.Fatalf("the page does not say how to declare the target lost: %q", body)
1717	}
1718	}
1719
1720	// dirtyFencedRollback puts the fenced world at a rollback whose target
1721	// released dirty, the claim still landing, and returns the rollback's id.
1722	func dirtyFencedRollback(t *testing.T, w *movePassWorld) string {
1723	t.Helper()
1724	rbID, at := newRollbackID(t), time.Now().UTC().Add(-time.Minute)
1725	deadline := at.Add(time.Hour)
1726	j17SetRecord(t, w.fx, func(r *provision.Record) {
1727	r.Region = "ie"
1728	r.Move.State = provision.MoveRollingBack
1729	r.Move.Rollback = &provision.MoveRollback{ID: rbID, RequestedAt: &at, Reason: provision.RollbackLandingDeadline, TargetPhase: provision.RbTargetReleased, Dirty: true,
1730	SourcePhase: provision.RbSourceWaiting, ReleaseDeadline: &deadline}
1731	})
1732	return rbID
1733	}
1734
1735	// TestRecoveryPassPagesOnlyAVerifiedDirtyTarget (Task 5 fix round 1, item
1736	// 1): the dirty page rests only on the grant's verified-dirty outcome. The
1737	// move's registration withdrawn from the admission between the pass's
1738	// observation and the fence call makes the grant answer ErrPending before it
1739	// verifies anything: the pass sends no page, then or on a later pass.
1740	func TestRecoveryPassPagesOnlyAVerifiedDirtyTarget(t *testing.T) {
1741	w, _, calls := fencedTargetWorld(t, "code-mvpass-fence-dirty-admission")
1742	dirtyFencedRollback(t, w)
1743	w.pass(t) // the claim's rollback half
1744	ctx := context.Background()
1745	withdraw := func(hostclaim.FenceRef) {
1746	body, etag, err := w.fx.rel.Get(ctx, "apps/bab/titogo/admission.json")
1747	if err != nil {
1748	t.Error(err)
1749	return
1750	}
1751	var a hostops.AppAdmission
1752	if err := json.Unmarshal(body, &a); err != nil {
1753	t.Error(err)
1754	return
1755	}
1756	if _, ok := a.Registrations[w.id]; !ok {
1757	return
1758	}
1759	delete(a.Registrations, w.id)
1760	if body, err = json.Marshal(a); err != nil {
1761	t.Error(err)
1762	return
1763	}
1764	if _, err := w.fx.rel.Put(ctx, "apps/bab/titogo/admission.json", body, etag); err != nil {
1765	t.Error(err)
1766	}
1767	}
1768	w.fx.srv.moveFenceCall = withdraw
1769	w.pass(t)
1770	w.pass(t)
1771	if len(calls()) != 0 {
1772	t.Fatal("the seam was replaced; the world's own counter should not run")
1773	}
1774	if p := w.paged(t); len(p) != 0 {
1775	t.Fatalf("paged without a verified fence: %+v", p)
1776	}
1777	}
1778
1779	// TestRecoveryPassLogsOnlyItsOwnFenceWrites (Task 5 fix round 1, item 2):
1780	// the console logs a fence step from the grant's own evidence, never from a
1781	// record read after it. A box's record write that lands just after the
1782	// grant's write (the claim's release, then the record's rollback) is not
1783	// logged as the console's, and the console's own entries are all there:
1784	// claim_rollback for the claim's step, rolling_back for the record's.
1785	func TestRecoveryPassLogsOnlyItsOwnFenceWrites(t *testing.T) {
1786	recordKey := provision.RecordKey("bab", "titogo", j4Host)
1787	claimKey, err := hostclaim.Key(j4Host)
1788	if err != nil {
1789	t.Fatal(err)
1790	}
1791	// landAfter writes the record once, as the source box would (its
1792	// rollback's source phase), right after the next accepted Put of key.
1793	landAfter := func(t *testing.T, w *movePassWorld, key string) *bool {
1794	t.Helper()
1795	st := w.fx.rel.(*deletableStore)
1796	landed := new(bool)
1797	st.afterPut = func(_ context.Context, k string) {
1798	if k != key {
1799	return
1800	}
1801	st.afterPut = nil
1802	*landed = true
1803	j17SetRecord(t, w.fx, func(r *provision.Record) {
1804	if r.Move != nil && r.Move.Rollback != nil {
1805	r.Move.Rollback.SourcePhase = provision.RbSourceRestoring
1806	}
1807	})
1808	}
1809	t.Cleanup(func() { st.afterPut = nil })
1810	return landed
1811	}
1812	notTheConsoles := func(t *testing.T, w *movePassWorld) {
1813	t.Helper()
1814	if ev, ok := moveLogOf(t, w)["rolling_back-source-"+provision.RbSourceRestoring]; ok {
1815	t.Fatalf("the box's write was logged as the console's: %+v", ev)
1816	}
1817	}
1818	t.Run("the claim's step", func(t *testing.T) {
1819	w, _, _ := fencedTargetWorld(t, "code-mvpass-fence-log-claim")
1820	w.pass(t) // the record's rollback
1821	landed := landAfter(t, w, claimKey)
1822	w.pass(t) // the claim's release, which rolls the landing claim back
1823	if !*landed {
1824	t.Fatal("the box's write did not land after the claim's step")
1825	}
1826	if ev := moveLogOf(t, w)["claim-rollback"]; ev.Actor != "console" || ev.Event != "claim_rollback" {
1827	t.Fatalf("the claim's rollback was not logged: %+v in %+v", ev, moveLogOf(t, w))
1828	}
1829	notTheConsoles(t, w)
1830	})
1831	t.Run("the record's step", func(t *testing.T) {
1832	w, _, _ := fencedTargetWorld(t, "code-mvpass-fence-log-record")
1833	landed := landAfter(t, w, recordKey)
1834	w.pass(t) // the record's rollback
1835	if !*landed {
1836	t.Fatal("the box's write did not land after the record's step")
1837	}
1838	log := moveLogOf(t, w)
1839	if ev := log["rolling_back"]; ev.Actor != "console" || ev.Fields["reason"] != provision.RollbackTargetFenced {
1840	t.Fatalf("the fenced rollback was not logged: %+v in %+v", ev, log)
1841	}
1842	if _, ok := log["claim-rollback"]; ok {
1843	t.Fatalf("a record step logged a claim rollback: %+v", log)
1844	}
1845	notTheConsoles(t, w)
1846	})
1847	}
1848
1849	// TestRecoveryPassStopsCallingTheFenceOnceConsumed (Q8): once the claim
1850	// carries the consumed fence and the record its loss (LossRef and Evidence
1851	// the fence's key), the pass never calls the fence again.
1852	func TestRecoveryPassStopsCallingTheFenceOnceConsumed(t *testing.T) {
1853	w, ref, calls := fencedTargetWorld(t, "code-mvpass-fence-stop")
1854	for range 3 {
1855	w.pass(t)
1856	}
1857	if rb := w.record(t).Move.Rollback; rb == nil || rb.LossRef != ref.Key || rb.Evidence != ref.Key {
1858	t.Fatalf("not at the stop condition: %+v", rb)
1859	}
1860	n := len(calls())
1861	if n != 3 {
1862	t.Fatalf("%d fence calls for three steps", n)
1863	}
1864	for range 3 {
1865	w.pass(t)
1866	}
1867	if got := len(calls()); got != n {
1868	t.Fatalf("the fence was called %d more times after its loss was committed", got-n)
1869	}
1870	}
1871
1872	// TestRecoveryPassReadsTheConsumedFenceNotTheBucket (Q8): after the claim
1873	// consumed the fence, the pass takes the reference from the claim, never the
1874	// bucket: the fence object deleted, the record's loss commit still follows.
1875	func TestRecoveryPassReadsTheConsumedFenceNotTheBucket(t *testing.T) {
1876	w, ref, calls := fencedTargetWorld(t, "code-mvpass-fence-consumed")
1877	w.pass(t)
1878	w.pass(t)
1879	if _, ok := hostclaim.ConsumedMoveTargetFence(w.claim(t)); !ok {
1880	t.Fatal("the fence was not consumed in two passes")
1881	}
1882	if err := w.fx.rel.(*deletableStore).Delete(context.Background(), ref.Key); err != nil {
1883	t.Fatal(err)
1884	}
1885	w.pass(t)
1886	if rb := w.record(t).Move.Rollback; rb == nil || rb.TargetPhase != provision.RbTargetReleased || rb.Evidence != ref.Key {
1887	t.Fatalf("the loss commit did not follow the deleted fence: %+v", rb)
1888	}
1889	if got := calls(); len(got) != 3 || got[2] != ref {
1890	t.Fatalf("the third call: %+v", got)
1891	}
1892	}
1893