carlos / platform Public

Clone
git clone https://amadan.net/carlos/platform

Plain git — no account needed to clone.

Download

Download this file

1package hostactors
2
3import (
4 "context"
5 "encoding/json"
6 "errors"
7 "fmt"
8 "os"
9 "strings"
10 "testing"
11 "time"
12
13 "github.com/carlosframework/platform/internal/boxid"
14 "github.com/carlosframework/platform/internal/boxid/boxidtest"
15 "github.com/carlosframework/platform/internal/release"
16 "github.com/carlosframework/platform/internal/status"
17)
18
19// enrollWorld is plan9Fixture's published deployment (boxes a, b and w,
20// active in ie under a published host floor) with ie's group, and a box
21// (instance i-new, reference newRef) that the group launched: its
22// identity record is published, and nothing else. The console reads the
23// cloud through cloud.
24type enrollWorld struct {
25 plan9World
26 e *AutoEnroller
27 cloud *fakeMembership
28 signer *boxidtest.Signer
29 clock time.Time
30 logs []string
31}
32
33func newEnrollWorld(t *testing.T, role string) *enrollWorld {
34 t.Helper()
35 w, _ := plan9Fixture(t, func(r *Roster) {
36 r.Regions = map[string]Region{"ie": {Account: "123", AWSRegion: "eu-west-1", GroupName: "routers-ie",
37 GroupARN: "arn:aws:autoscaling:eu-west-1:123:autoScalingGroup:x:autoScalingGroupName/routers-ie", Namespaces: []string{"platform"}, Pools: []string{"default"}, Role: role}}
38 })
39 signer := boxidtest.NewSigner(t)
40 _, raw := signer.Record(t, newRef, "123", "eu-west-1", "i-new")
41 if _, err := w.d.Store.Put(context.Background(), boxid.Key(newRef), raw, ""); err != nil {
42 t.Fatal(err)
43 }
44 ew := &enrollWorld{plan9World: w, clock: time.Now().UTC(), signer: signer,
45 cloud: &fakeMembership{members: map[string]Membership{"i-new": member("routers-ie")}}}
46 ew.e = &AutoEnroller{Directory: w.d, Signer: w.sg, Evidence: ExactEvidence{PublicKey: w.d.PublicKey, Store: w.d.Store, Boxes: w.d.PrivateBoxReport},
47 Members: ew.cloud, Certs: signer.Certs(), Namespace: "platform", Pool: "default", Now: func() time.Time { return ew.clock }, Patience: 2 * time.Minute,
48 Logf: func(format string, args ...any) { ew.logs = append(ew.logs, fmt.Sprintf(format, args...)) }}
49 return ew
50}
51
52// pass runs the enrollment pass and returns new's step.
53func (w *enrollWorld) pass(t *testing.T) string {
54 t.Helper()
55 steps, err := w.e.EnrollPass(context.Background())
56 if err != nil {
57 t.Fatal(err)
58 }
59 for _, s := range steps {
60 if s.Box == newRef {
61 return s.Step
62 }
63 }
64 return ""
65}
66
67// guardReady is the joining box, its guard armed, publishing the report
68// every hosting box publishes.
69func (w *enrollWorld) guardReady(t *testing.T, enrollment string, ready bool) {
70 t.Helper()
71 box := status.Box{GeneratedAt: time.Now().UTC(), Metrics: &status.BoxMetrics{Enrollment: enrollment, InstanceID: "i-new", Release: "v1.0.0", ReleaseTag: "v1.0.0",
72 Platform: "linux-amd64", BinarySHA256: w.hash, MovesProtocol: 1, BootID: "boot", FloorSHA256: w.floor.Digest, FloorGuardReady: ready, SystemChannel: "stable"}}
73 raw, _ := json.Marshal(box)
74 _, etag, _ := w.d.Store.Get(context.Background(), "status/boxes/"+newRef+".json")
75 if _, err := w.d.Store.Put(context.Background(), "status/boxes/"+newRef+".json", raw, etag); err != nil {
76 t.Fatal(err)
77 }
78}
79
80func (w *enrollWorld) invitation(t *testing.T) (Invitation, bool) {
81 t.Helper()
82 ctx := context.Background()
83 wire, _, err := w.d.Store.Get(ctx, "control/host-actor-invitations/"+newRef+".json")
84 if errors.Is(err, os.ErrNotExist) {
85 return Invitation{}, false
86 }
87 if err != nil {
88 t.Fatal(err)
89 }
90 var got Invitation
91 if err := release.VerifyRootEnvelope(w.d.PublicKey, wire, &got); err != nil {
92 t.Fatal(err)
93 }
94 // Read only, never Invite (get-or-create): the invitation verifies
95 // for the box's record, and nothing is written.
96 raw, err := boxid.Load(ctx, w.d.Store, newRef)
97 if err != nil {
98 t.Fatal(err)
99 }
100 nonce, err := w.d.enrollmentNonce(ctx, EnrollmentRequest{Reference: newRef, Namespace: "platform"}, raw)
101 if err != nil || nonce != got.Enrollment {
102 t.Fatalf("invitation %+v: %v", got, err)
103 }
104 return got, true
105}
106
107func (w *enrollWorld) attempt(t *testing.T) EnrollmentAttempt {
108 t.Helper()
109 o, err := w.d.Read(context.Background())
110 if err != nil {
111 t.Fatal(err)
112 }
113 return o.Roster.EnrollmentAttempts[newRef]
114}
115
116// The whole sequence (spec 2 §5 step 5, §11): attempt, the console's own
117// membership read and the invitation, guard-ready, the console's second
118// read and the enrollment. The deployment's floor is published, so the
119// enrolling write passes membership.go's rule only because the guard-ready
120// report is there; the box takes its group's role in it.
121func TestAutomaticEnrollmentFromRecordToRoster(t *testing.T) {
122 w := newEnrollWorld(t, RoleLegacy)
123 if got := w.pass(t); got != "began an attempt" {
124 t.Fatalf("first pass: %q", got)
125 }
126 if _, ok := w.invitation(t); ok || len(w.cloud.calls) != 0 {
127 t.Fatalf("invited before membership was read: calls %v", w.cloud.calls)
128 }
129 if got := w.pass(t); got != "invited" {
130 t.Fatalf("second pass: %q", got)
131 }
132 inv, ok := w.invitation(t)
133 if !ok || len(w.cloud.calls) != 1 {
134 t.Fatalf("invitation %v, calls %v", ok, w.cloud.calls)
135 }
136 // Invited, but the guard is not armed: nothing more, and no read.
137 // First no report at all, then a report from a box whose guard is not
138 // ready.
139 if got := w.pass(t); got != "waiting for its guard-ready report" {
140 t.Fatalf("invited, no report: %q", got)
141 }
142 w.guardReady(t, inv.Enrollment, false)
143 if got := w.pass(t); got != "waiting for its guard-ready report" || len(w.cloud.calls) != 1 {
144 t.Fatalf("invited, guard not ready: %q, calls %v", got, w.cloud.calls)
145 }
146 w.guardReady(t, inv.Enrollment, true)
147 w.clock = w.clock.Add(5 * time.Minute)
148 if got := w.pass(t); !strings.HasPrefix(got, "enrolled in ie") {
149 t.Fatalf("ready: %q", got)
150 }
151 // The enrollment read membership again, itself.
152 if len(w.cloud.calls) != 2 || len(w.logs) != 2 || !strings.Contains(w.logs[1], "attempt "+w.attempt(t).AttemptID+", instance i-new, request ids asg-req, ec2-req") || !strings.HasSuffix(w.logs[1], "): enrolled") {
153 t.Fatalf("calls %v, logs %q", w.cloud.calls, w.logs)
154 }
155 o, err := w.d.Read(context.Background())
156 if err != nil {
157 t.Fatal(err)
158 }
159 b, ok := o.Roster.Boxes[newRef]
160 if !ok || b.State != "active" || b.Enrollment != inv.Enrollment || b.Cloud.InstanceID != "i-new" || b.Group != "routers-ie" || b.Role != RoleLegacy || b.Namespace != "platform" || b.Pool != "default" {
161 t.Fatalf("roster entry %+v", b)
162 }
163 if !o.Roster.EnrollmentAttempts[newRef].Consumed {
164 t.Fatal("the attempt was not consumed")
165 }
166 // Enrolled: the pass has nothing left to do for it.
167 if got := w.pass(t); got != "" {
168 t.Fatalf("enrolled box stepped again: %q", got)
169 }
170}
171
172// R1: an instance in the deployment's account that the cloud does not
173// place in the region's group is never invited and never enrolled, however
174// long it waits; and one that leaves the group after its invitation is not
175// enrolled on a guard-ready report.
176func TestAnInstanceOutsideTheGroupIsNeverInvitedOrEnrolled(t *testing.T) {
177 for name, m := range map[string]Membership{
178 "another group": member("routers-uk"),
179 "no group": {Owner: "123", InstanceState: "running", AvailabilityZoneRegion: "eu-west-1", RequestIDs: []string{"a", "b"}},
180 } {
181 t.Run(name, func(t *testing.T) {
182 w := newEnrollWorld(t, "")
183 w.cloud.members["i-new"] = m
184 for i := 0; i < 12; i++ {
185 w.pass(t)
186 w.clock = w.clock.Add(time.Minute)
187 }
188 if _, ok := w.invitation(t); ok {
189 t.Fatal("an instance outside the group was invited")
190 }
191 if o, _ := w.d.Read(context.Background()); o.Roster.Boxes[newRef].Enrollment != "" {
192 t.Fatal("an instance outside the group was enrolled")
193 }
194 })
195 }
196 w := newEnrollWorld(t, "")
197 w.pass(t)
198 if got := w.pass(t); got != "invited" {
199 t.Fatal(got)
200 }
201 inv, _ := w.invitation(t)
202 w.guardReady(t, inv.Enrollment, true)
203 w.cloud.members["i-new"] = func() Membership { m := member("routers-ie"); m.LifecycleState = "Detaching"; return m }()
204 if got := w.pass(t); !strings.Contains(got, "not confirmed") {
205 t.Fatalf("left the group: %q", got)
206 }
207 if o, _ := w.d.Read(context.Background()); o.Roster.Boxes[newRef].Enrollment != "" {
208 t.Fatal("an instance that left the group was enrolled")
209 }
210}
211
212// R1 (#7): a read that fails is unknown. The attempt stands, its wait does
213// not grow, and the next read that answers goes on from it.
214func TestAMembershipReadThatFailsKeepsTheAttempt(t *testing.T) {
215 w := newEnrollWorld(t, "")
216 w.pass(t)
217 first := w.attempt(t).AttemptID
218 w.cloud.err = errors.New("Throttling: rate exceeded")
219 for i := 0; i < 10; i++ {
220 w.clock = w.clock.Add(time.Hour)
221 if got := w.pass(t); !strings.Contains(got, "could not be read") {
222 t.Fatalf("failed read: %q", got)
223 }
224 }
225 if got := w.attempt(t).AttemptID; got != first || w.e.attempts[newRef].tries != 1 {
226 t.Fatalf("a failed read superseded the attempt (%s, was %s) or grew its wait (%d)", got, first, w.e.attempts[newRef].tries)
227 }
228 w.cloud.err = nil
229 if got := w.pass(t); got != "invited" || w.attempt(t).AttemptID != first {
230 t.Fatalf("after the outage: %q", got)
231 }
232}
233
234// stalledMembership is a describe whose connection stalls for one
235// instance: Member returns only when its context ends. Every other
236// instance is answered by the cloud underneath.
237type stalledMembership struct {
238 stalled string
239 cloud *fakeMembership
240 deadline bool
241}
242
243func (s *stalledMembership) Member(ctx context.Context, awsRegion, instance string) (Membership, error) {
244 if instance != s.stalled {
245 return s.cloud.Member(ctx, awsRegion, instance)
246 }
247 _, s.deadline = ctx.Deadline()
248 <-ctx.Done()
249 return Membership{}, ctx.Err()
250}
251
252// A membership read that stalls is cut off at storeCallTimeout and is
253// unknown: the pass returns within the bound, the stalled box's attempt
254// stands with its wait unchanged, and the box after it in the same pass is
255// still invited.
256func TestAStalledMembershipReadIsCutOffAndThePassGoesOn(t *testing.T) {
257 was := storeCallTimeout
258 storeCallTimeout = 100 * time.Millisecond
259 t.Cleanup(func() { storeCallTimeout = was })
260 w := newEnrollWorld(t, "")
261 // A second box the group launched, whose reference sorts after
262 // newRef's, so it waits in the pass behind the stalled read.
263 twoRef := GroupBoxReference("123", "i-two")
264 if twoRef <= newRef {
265 t.Fatalf("%s does not sort after %s", twoRef, newRef)
266 }
267 _, raw := w.signer.Record(t, twoRef, "123", "eu-west-1", "i-two")
268 if _, err := w.d.Store.Put(context.Background(), boxid.Key(twoRef), raw, ""); err != nil {
269 t.Fatal(err)
270 }
271 w.cloud.members["i-two"] = member("routers-ie")
272 stalled := &stalledMembership{stalled: "i-new", cloud: w.cloud}
273 w.e.Members = stalled
274 steps, err := w.e.EnrollPass(context.Background())
275 if err != nil || len(steps) != 2 || steps[0].Step != "began an attempt" || steps[1].Step != "began an attempt" {
276 t.Fatalf("first pass: %v, %v", steps, err)
277 }
278 first := w.attempt(t).AttemptID
279
280 done := make(chan []EnrollStep, 1)
281 start := time.Now()
282 go func() {
283 steps, err := w.e.EnrollPass(context.Background())
284 if err != nil {
285 t.Error(err)
286 }
287 done <- steps
288 }()
289 select {
290 case steps = <-done:
291 case <-time.After(10 * time.Second):
292 t.Fatal("the pass is still waiting on the stalled read")
293 }
294 if took := time.Since(start); took > storeCallTimeout+5*time.Second {
295 t.Fatalf("the pass took %s", took)
296 }
297 if !stalled.deadline {
298 t.Fatal("the read was given no deadline")
299 }
300 if len(steps) != 2 || steps[0].Box != newRef || !strings.Contains(steps[0].Step, "could not be read") || !strings.Contains(steps[0].Step, "did not finish in time") {
301 t.Fatalf("stalled box: %v", steps)
302 }
303 if got := w.attempt(t).AttemptID; got != first || w.e.attempts[newRef].tries != 1 || w.e.attempts[newRef].refused != "" {
304 t.Fatalf("the stalled read superseded the attempt (%s, was %s), grew its wait (%d) or refused it (%q)", got, first, w.e.attempts[newRef].tries, w.e.attempts[newRef].refused)
305 }
306 if _, ok := w.invitation(t); ok {
307 t.Fatal("the stalled box was invited")
308 }
309 if steps[1].Box != twoRef || steps[1].Step != "invited" {
310 t.Fatalf("the box behind the stalled read: %v", steps[1])
311 }
312 if _, _, err := w.d.Store.Get(context.Background(), "control/host-actor-invitations/"+twoRef+".json"); err != nil {
313 t.Fatalf("the box behind the stalled read has no invitation: %v", err)
314 }
315}
316
317// C2: the invitation is written only while the console's read is under a
318// minute old. Here every look at the clock takes 31 seconds: the read is
319// fresh when checkConfirmed has it, and over a minute old by the time the
320// invitation would be written. That is unknown: the attempt and its wait
321// stand.
322func TestAnInvitationNeedsAReadUnderAMinuteOldAtTheWrite(t *testing.T) {
323 w := newEnrollWorld(t, "")
324 w.pass(t)
325 first := w.attempt(t).AttemptID
326 w.e.Now = func() time.Time { w.clock = w.clock.Add(31 * time.Second); return w.clock }
327 if got := w.pass(t); !strings.Contains(got, "more than a minute after its membership read") {
328 t.Fatalf("slow pass: %q", got)
329 }
330 if _, ok := w.invitation(t); ok {
331 t.Fatal("invited on a read over a minute old")
332 }
333 if w.attempt(t).AttemptID != first || w.e.attempts[newRef].tries != 1 || w.e.attempts[newRef].refused != "" {
334 t.Fatalf("a missed deadline counted against the attempt: %+v", w.e.attempts[newRef])
335 }
336}
337
338// slowStore is the deployment bucket with one slow read: the first Get of
339// slow after armed is set moves the console's clock on by exactly 60
340// seconds, to the deadline itself, as a bucket that answers late would. It honours its context, as the S3
341// store does, and records every Put.
342type slowStore struct {
343 release.Store
344 slow string
345 armed bool
346 late func()
347 puts []string
348}
349
350func (s *slowStore) Get(ctx context.Context, key string) ([]byte, string, error) {
351 if err := ctx.Err(); err != nil {
352 return nil, "", err
353 }
354 if s.armed && key == s.slow {
355 s.armed = false
356 s.late()
357 }
358 return s.Store.Get(ctx, key)
359}
360
361func (s *slowStore) Put(ctx context.Context, key string, body []byte, ifMatch string) (string, error) {
362 if err := ctx.Err(); err != nil {
363 return "", err
364 }
365 s.puts = append(s.puts, key)
366 return s.Store.Put(ctx, key, body, ifMatch)
367}
368
369// slowAfterRead makes the store slow on key after the console's next
370// membership read.
371func (w *enrollWorld) slowAfterRead(key string) *slowStore {
372 ss := &slowStore{Store: w.e.Directory.Store, slow: key, late: func() { w.clock = w.clock.Add(60 * time.Second) }}
373 w.e.Directory.Store = ss
374 w.cloud.during = func() { ss.armed = true }
375 return ss
376}
377
378// S1: a read inside the sealed Invite that answers late (here, its own
379// read of the invitation key) leaves the invitation unwritten: no Put is
380// issued after the deadline. The attempt and its wait stand, and the next
381// pass, with a fresh read, invites.
382func TestASlowReadInsideInviteWritesNothing(t *testing.T) {
383 w := newEnrollWorld(t, "")
384 w.pass(t)
385 first := w.attempt(t).AttemptID
386 ss := w.slowAfterRead("control/host-actor-invitations/" + newRef + ".json")
387 if got := w.pass(t); !strings.Contains(got, "more than a minute after its membership read") {
388 t.Fatalf("slow invite: %q", got)
389 }
390 if len(ss.puts) != 0 {
391 t.Fatalf("written after the deadline: %v", ss.puts)
392 }
393 if _, ok := w.invitation(t); ok || w.attempt(t).AttemptID != first || w.e.attempts[newRef].tries != 1 {
394 t.Fatalf("invited %v, attempt %+v", ok, w.e.attempts[newRef])
395 }
396 w.cloud.during = nil
397 if got := w.pass(t); got != "invited" || w.attempt(t).AttemptID != first {
398 t.Fatalf("next pass: %q", got)
399 }
400}
401
402// S1: a read inside the sealed checkMembership that answers late (the
403// guard-ready report Replace checks before its CAS) leaves the roster
404// unwritten. The attempt stays unconsumed, and the next pass enrolls.
405func TestASlowReadInsideTheRosterCheckWritesNothing(t *testing.T) {
406 w := newEnrollWorld(t, "")
407 w.pass(t)
408 if got := w.pass(t); got != "invited" {
409 t.Fatal(got)
410 }
411 inv, _ := w.invitation(t)
412 w.guardReady(t, inv.Enrollment, true)
413 first, tries := w.attempt(t).AttemptID, w.e.attempts[newRef].tries
414 ss := w.slowAfterRead("status/boxes/" + newRef + ".json")
415 if got := w.pass(t); !strings.Contains(got, "more than a minute after its membership read") {
416 t.Fatalf("slow enrolment: %q", got)
417 }
418 if len(ss.puts) != 0 {
419 t.Fatalf("written after the deadline: %v", ss.puts)
420 }
421 if a := w.attempt(t); a.AttemptID != first || a.Consumed || w.e.attempts[newRef].tries != tries || w.e.attempts[newRef].refused != "" {
422 t.Fatalf("attempt %+v, seen %+v", a, w.e.attempts[newRef])
423 }
424 if o, _ := w.d.Read(context.Background()); o.Roster.Boxes[newRef].Enrollment != "" {
425 t.Fatal("enrolled after the deadline")
426 }
427 w.cloud.during = nil
428 w.guardReady(t, inv.Enrollment, true)
429 if got := w.pass(t); !strings.HasPrefix(got, "enrolled in ie") {
430 t.Fatalf("next pass: %q", got)
431 }
432}
433
434// The ruling's second test: a box cannot satisfy another box's report
435// check. A report under newRef's key that another instance wrote is not
436// newRef's guard-ready report, and a record under a key that is not its
437// instance's group reference is never invited.
438func TestABoxCannotStandInForAnother(t *testing.T) {
439 w := newEnrollWorld(t, "")
440 w.pass(t)
441 if got := w.pass(t); got != "invited" {
442 t.Fatal(got)
443 }
444 inv, _ := w.invitation(t)
445 box := status.Box{GeneratedAt: time.Now().UTC(), Metrics: &status.BoxMetrics{Enrollment: inv.Enrollment, InstanceID: "i-other", Release: "v1.0.0", ReleaseTag: "v1.0.0",
446 Platform: "linux-amd64", BinarySHA256: w.hash, MovesProtocol: 1, BootID: "boot", FloorSHA256: w.floor.Digest, FloorGuardReady: true, SystemChannel: "stable"}}
447 raw, _ := json.Marshal(box)
448 if _, err := w.d.Store.Put(context.Background(), "status/boxes/"+newRef+".json", raw, ""); err != nil {
449 t.Fatal(err)
450 }
451 if got := w.pass(t); got != "waiting for its guard-ready report" {
452 t.Fatalf("another instance's report: %q", got)
453 }
454 // A record its box published under a key of its own choosing.
455 v := newEnrollWorld(t, "")
456 _, chosen := v.signer.Record(t, "chosen", "123", "eu-west-1", "i-chosen")
457 if _, err := v.d.Store.Put(context.Background(), boxid.Key("chosen"), chosen, ""); err != nil {
458 t.Fatal(err)
459 }
460 steps, err := v.e.EnrollPass(context.Background())
461 if err != nil {
462 t.Fatal(err)
463 }
464 for _, s := range steps {
465 if s.Box == "chosen" && !strings.Contains(s.Step, "not under its group reference") {
466 t.Fatalf("chosen key: %q", s.Step)
467 }
468 }
469 if _, _, err := v.d.Store.Get(context.Background(), "control/host-actor-invitations/chosen.json"); err == nil {
470 t.Fatal("a box with a chosen key was invited")
471 }
472}
473
474// inflightStore is the bucket with one slow Put: the first Put of key
475// after armed is set commits (when commit is set) and then, by mode,
476// waits for its context as an S3 request cut off by the deadline does
477// ("cancelled"), ignores its context and never answers ("ignores"), or
478// answers success only after the console's clock has passed the deadline
479// ("late"). In mode "delayed" it commits nothing until hang is closed,
480// whatever its context says, then commits and reports on done: a write
481// the console gave up on that the bucket applies later.
482type inflightStore struct {
483 release.Store
484 key string
485 armed, commit bool
486 mode string
487 late func()
488 hang chan struct{}
489 done chan error
490}
491
492func (s *inflightStore) Put(ctx context.Context, key string, body []byte, ifMatch string) (string, error) {
493 if s.armed && key == s.key {
494 s.armed = false
495 if s.mode == "delayed" {
496 <-s.hang
497 etag, err := s.Store.Put(ctx, key, body, ifMatch)
498 s.done <- err
499 return etag, err
500 }
501 etag := ""
502 if s.commit {
503 var err error
504 if etag, err = s.Store.Put(ctx, key, body, ifMatch); err != nil {
505 return "", err
506 }
507 }
508 switch s.mode {
509 case "ignores":
510 <-s.hang
511 return etag, nil
512 case "late":
513 s.late()
514 return etag, nil
515 }
516 <-ctx.Done()
517 return "", ctx.Err()
518 }
519 return s.Store.Put(ctx, key, body, ifMatch)
520}
521
522// inflightAfterRead makes key's next Put slow in mode: the next
523// membership read takes 59.95 seconds, so its write has 50 milliseconds,
524// and a late answer comes a second after that.
525func (w *enrollWorld) inflightAfterRead(key string, commit bool, mode string) *inflightStore {
526 is := &inflightStore{Store: w.e.Directory.Store, key: key, commit: commit, mode: mode, hang: make(chan struct{}), done: make(chan error, 1),
527 late: func() { w.clock = w.clock.Add(time.Second) }}
528 w.e.Directory.Store = is
529 w.cloud.during = func() { w.clock = w.clock.Add(59950 * time.Millisecond); is.armed = true }
530 return is
531}
532
533// S1: a Put still in flight at the deadline is cancelled there, and its
534// result is unknown: the attempt and its wait stand, and the next pass
535// reads the bucket as it does every pass. Here the invitation did not
536// land, then (a second time) it did, and the next pass finds it.
537func TestAPutInFlightAtTheDeadlineIsUnknown(t *testing.T) {
538 w := newEnrollWorld(t, "")
539 w.pass(t)
540 first, tries := w.attempt(t).AttemptID, w.e.attempts[newRef].tries
541 w.inflightAfterRead("control/host-actor-invitations/"+newRef+".json", false, "cancelled")
542 if got := w.pass(t); !strings.Contains(got, "in flight at the deadline") {
543 t.Fatalf("in flight: %q", got)
544 }
545 if _, ok := w.invitation(t); ok || w.attempt(t).AttemptID != first || w.e.attempts[newRef].tries != tries || w.e.attempts[newRef].refused != "" {
546 t.Fatalf("invited %v, seen %+v", ok, w.e.attempts[newRef])
547 }
548 w.inflightAfterRead("control/host-actor-invitations/"+newRef+".json", true, "cancelled")
549 if got := w.pass(t); !strings.Contains(got, "in flight at the deadline") {
550 t.Fatalf("in flight, landed: %q", got)
551 }
552 w.cloud.during = nil
553 if got := w.pass(t); got != "waiting for its guard-ready report" {
554 t.Fatalf("read back: %q", got)
555 }
556}
557
558// U2: a store that ignores its context and never answers is cut off by
559// the hard per-call timeout, well before the deadline: the outcome is
560// unknown, the attempt and its wait stand, and nothing was invited.
561func TestAStoreThatIgnoresItsContextIsCutOffAtTheHardTimeout(t *testing.T) {
562 was := storeCallTimeout
563 storeCallTimeout = 100 * time.Millisecond
564 t.Cleanup(func() { storeCallTimeout = was })
565 w := newEnrollWorld(t, "")
566 w.pass(t)
567 first, tries := w.attempt(t).AttemptID, w.e.attempts[newRef].tries
568 is := &inflightStore{Store: w.e.Directory.Store, key: "control/host-actor-invitations/" + newRef + ".json", mode: "ignores", hang: make(chan struct{}), armed: true}
569 t.Cleanup(func() { close(is.hang) })
570 w.e.Directory.Store = is
571 start := time.Now()
572 got := w.pass(t)
573 if !strings.Contains(got, "did not answer in time") || time.Since(start) > 5*time.Second {
574 t.Fatalf("after %s: %q", time.Since(start), got)
575 }
576 if _, ok := w.invitation(t); ok || w.attempt(t).AttemptID != first || w.e.attempts[newRef].tries != tries || w.e.attempts[newRef].refused != "" {
577 t.Fatalf("invited %v, seen %+v", ok, w.e.attempts[newRef])
578 }
579}
580
581// U1, U2: an enrolling write whose outcome is unknown is settled by the
582// next pass's roster read, with nothing more. Not landed: the same
583// attempt, its wait unchanged, enrols on the next pass. Landed, whether
584// cut off in flight or answering success only after the deadline: the
585// roster lists the box, and the pass has nothing left to do for it.
586func TestAnUnknownEnrolmentIsSettledByTheRoster(t *testing.T) {
587 ready := func(t *testing.T) *enrollWorld {
588 w := newEnrollWorld(t, "")
589 w.pass(t)
590 if got := w.pass(t); got != "invited" {
591 t.Fatal(got)
592 }
593 inv, _ := w.invitation(t)
594 w.guardReady(t, inv.Enrollment, true)
595 return w
596 }
597 t.Run("did not land", func(t *testing.T) {
598 w := ready(t)
599 first, tries := w.attempt(t).AttemptID, w.e.attempts[newRef].tries
600 w.inflightAfterRead(Key, false, "cancelled")
601 if got := w.pass(t); !strings.Contains(got, "in flight at the deadline") {
602 t.Fatalf("in flight: %q", got)
603 }
604 if a := w.attempt(t); a.Consumed || a.AttemptID != first || w.e.attempts[newRef].tries != tries {
605 t.Fatalf("attempt %+v, seen %+v", a, w.e.attempts[newRef])
606 }
607 w.cloud.during = nil
608 if got := w.pass(t); !strings.HasPrefix(got, "enrolled in ie") {
609 t.Fatalf("next pass: %q", got)
610 }
611 })
612 for name, mode := range map[string]string{"landed, cut off in flight": "cancelled", "landed, answered after the deadline": "late"} {
613 t.Run(name, func(t *testing.T) {
614 w := ready(t)
615 w.inflightAfterRead(Key, true, mode)
616 want := map[string]string{"cancelled": "in flight at the deadline", "late": "answered only after the deadline"}[mode]
617 if got := w.pass(t); !strings.Contains(got, want) {
618 t.Fatalf("unknown: %q", got)
619 }
620 w.cloud.during = nil
621 calls := len(w.cloud.calls)
622 steps, err := w.e.EnrollPass(context.Background())
623 if err != nil || len(steps) != 0 || len(w.cloud.calls) != calls {
624 t.Fatalf("settled by the roster: %+v %v, calls %v", steps, err, w.cloud.calls)
625 }
626 o, _ := w.d.Read(context.Background())
627 if b := o.Roster.Boxes[newRef]; b.State != "active" || !o.Roster.EnrollmentAttempts[newRef].Consumed {
628 t.Fatalf("roster %+v", b)
629 }
630 })
631 }
632}
633
634// V1, the accepted exposure: the console waits for no write past its
635// bound, but a write it gave up on can still commit. Here the enrolling
636// Put is issued before the deadline and blocks; the pass returns unknown;
637// the instance is detached from its group (still running); the next pass
638// finds the box absent from the roster, and its fresh describe refuses
639// without writing anything; then the bucket applies the delayed Put, on
640// the roster revision it was built against, which nothing has moved. The
641// pass after that finds the box enrolled and does nothing more. Such an
642// enrolment rests on a membership read that was true when its write was
643// issued: the same exposure as an instance detached after enrolment,
644// which spec 3's regional worker reconciles.
645func TestAWriteTheConsoleGaveUpOnCanCommitLater(t *testing.T) {
646 w := newEnrollWorld(t, "")
647 w.pass(t)
648 if got := w.pass(t); got != "invited" {
649 t.Fatal(got)
650 }
651 inv, _ := w.invitation(t)
652 w.guardReady(t, inv.Enrollment, true)
653 before, _ := w.d.Read(context.Background())
654 is := w.inflightAfterRead(Key, false, "delayed")
655 if got := w.pass(t); !strings.Contains(got, "in flight at the deadline") {
656 t.Fatalf("unknown: %q", got)
657 }
658 // Detached: the group no longer lists the instance, which still runs.
659 w.cloud.during = nil
660 w.cloud.members["i-new"] = member("")
661 calls := len(w.cloud.calls)
662 if got := w.pass(t); !strings.Contains(got, "not confirmed") || len(w.cloud.calls) != calls+1 {
663 t.Fatalf("absent, then refused: %q, calls %v", got, w.cloud.calls)
664 }
665 if o, _ := w.d.Read(context.Background()); o.ETag != before.ETag {
666 t.Fatalf("the refusing pass wrote the roster: %s, was %s", o.ETag, before.ETag)
667 }
668 close(is.hang)
669 if err := <-is.done; err != nil {
670 t.Fatalf("the delayed write did not commit: %v", err)
671 }
672 calls = len(w.cloud.calls)
673 steps, err := w.e.EnrollPass(context.Background())
674 if err != nil || len(steps) != 0 || len(w.cloud.calls) != calls {
675 t.Fatalf("enrolled: %+v %v, calls %v", steps, err, w.cloud.calls)
676 }
677 o, _ := w.d.Read(context.Background())
678 if b := o.Roster.Boxes[newRef]; b.State != "active" || o.Roster.Revision != before.Roster.Revision+1 {
679 t.Fatalf("roster %+v, revision %d", b, o.Roster.Revision)
680 }
681}
682
683// A refused attempt is kept, with no more reads, for its wait, then begun
684// again; each refusal doubles the wait, up to 32 times Patience.
685func TestARefusedAttemptIsBegunAgainWithADoublingWait(t *testing.T) {
686 w := newEnrollWorld(t, "")
687 w.cloud.members["i-new"] = member("")
688 if got := w.pass(t); got != "began an attempt" {
689 t.Fatal(got)
690 }
691 first := w.attempt(t).AttemptID
692 if got := w.pass(t); !strings.Contains(got, "not confirmed") {
693 t.Fatal(got)
694 }
695 w.clock = w.clock.Add(time.Minute + 59*time.Second)
696 if got := w.pass(t); !strings.Contains(got, "waiting before another attempt") || len(w.cloud.calls) != 1 {
697 t.Fatalf("inside the wait: %q, calls %v", got, w.cloud.calls)
698 }
699 w.clock = w.clock.Add(time.Second)
700 if got := w.pass(t); got != "began an attempt" || w.attempt(t).AttemptID == first {
701 t.Fatalf("after two minutes: %q", got)
702 }
703 if got := w.pass(t); !strings.Contains(got, "not confirmed") {
704 t.Fatal(got)
705 }
706 // The second refusal waits four minutes.
707 w.clock = w.clock.Add(3*time.Minute + 59*time.Second)
708 if got := w.pass(t); !strings.Contains(got, "waiting before another attempt") {
709 t.Fatalf("second attempt before its four minutes: %q", got)
710 }
711 w.clock = w.clock.Add(time.Second)
712 if got := w.pass(t); got != "began an attempt" {
713 t.Fatalf("second attempt after four minutes: %q", got)
714 }
715 if got := w.e.wait(10); got != 64*time.Minute {
716 t.Fatalf("the wait is not capped: %s", got)
717 }
718}
719
720func TestAutomaticEnrollmentRefusesWhatItCannotProve(t *testing.T) {
721 // A box from an account or region with no group is left alone.
722 w := newEnrollWorld(t, "")
723 _, raw := boxidtest.NewSigner(t).Record(t, "elsewhere", "999", "eu-west-1", "i-x")
724 if _, err := w.d.Store.Put(context.Background(), boxid.Key("elsewhere"), raw, ""); err != nil {
725 t.Fatal(err)
726 }
727 steps, err := w.e.EnrollPass(context.Background())
728 if err != nil {
729 t.Fatal(err)
730 }
731 for _, s := range steps {
732 if s.Box == "elsewhere" && !strings.Contains(s.Step, "no region's group") {
733 t.Fatalf("elsewhere: %q", s.Step)
734 }
735 }
736 // A record whose signature does not verify under the certificates.
737 w.e.Certs = boxidtest.NewSigner(t).Certs()
738 if got := w.pass(t); !strings.Contains(got, "does not verify") {
739 t.Fatalf("unverified record: %q", got)
740 }
741 // A deployment with no published floor enrolls nothing.
742 d, sg, _ := fixture(t)
743 unpublished := &AutoEnroller{Directory: d, Signer: sg, Namespace: "platform", Pool: "default", Now: time.Now}
744 if _, err := unpublished.EnrollPass(context.Background()); !errors.Is(err, ErrNoFloor) {
745 t.Fatalf("unpublished: %v", err)
746 }
747}
748
749// S5: every membership read is logged with the box, its attempt, its
750// instance and the request ids the read's own confirmation kept, whatever
751// came of it: a failed read, unknown (the ids the cloud gave, "none" for a
752// call it never answered), a refusal, and an invitation.
753func TestEveryMembershipReadIsLoggedWithItsIds(t *testing.T) {
754 w := newEnrollWorld(t, "")
755 w.pass(t)
756 id := w.attempt(t).AttemptID
757 head := "membership read for " + newRef + " (attempt " + id + ", instance i-new, request ids "
758 w.cloud.err, w.cloud.failIDs = errors.New("Throttling: rate exceeded"), []string{"asg-req", NoRequestID}
759 w.pass(t)
760 w.cloud.err, w.cloud.failIDs = nil, nil
761 w.cloud.members["i-new"] = member("routers-uk")
762 w.pass(t)
763 if len(w.logs) != 2 || !strings.Contains(w.logs[0], head+"asg-req, none, read at ") || !strings.Contains(w.logs[0], "): unknown: "+ErrMembershipUnknown.Error()) ||
764 !strings.Contains(w.logs[1], head+"asg-req, ec2-req, read at ") || !strings.Contains(w.logs[1], "): refused: "+ErrNotMember.Error()) {
765 t.Fatalf("logs %q", w.logs)
766 }
767 // A check that failed before any read was made is not a membership
768 // read, and is not logged as one.
769 w.e.logRead(EnrollmentRequest{Reference: newRef, AttemptID: id}, "i-new", MembershipEvidence{}, "invited", ErrRoster)
770 if len(w.logs) != 2 {
771 t.Fatalf("a check with no read was logged: %q", w.logs[2:])
772 }
773 // A describe that took a minute is a refusal too.
774 x := newEnrollWorld(t, "")
775 x.pass(t)
776 x.cloud.during = func() { x.clock = x.clock.Add(time.Minute) }
777 if got := x.pass(t); !strings.Contains(got, "not confirmed") || len(x.logs) != 1 || !strings.Contains(x.logs[0], "): refused: "+ErrMembershipStale.Error()) {
778 t.Fatalf("stale: %q, logs %q", got, x.logs)
779 }
780 v := newEnrollWorld(t, "")
781 v.pass(t)
782 if got := v.pass(t); got != "invited" {
783 t.Fatal(got)
784 }
785 vhead := "membership read for " + newRef + " (attempt " + v.attempt(t).AttemptID + ", instance i-new, request ids asg-req, ec2-req, read at "
786 if len(v.logs) != 1 || !strings.Contains(v.logs[0], vhead) || !strings.HasSuffix(v.logs[0], "): invited") {
787 t.Fatalf("logs %q", v.logs)
788 }
789}
790
791// conflictStore refuses the next Put of key with the store's own conflict,
792// as a conditional write another writer got to first is refused.
793type conflictStore struct {
794 release.Store
795 key string
796 armed bool
797}
798
799func (s *conflictStore) Put(ctx context.Context, key string, body []byte, ifMatch string) (string, error) {
800 if s.armed && key == s.key {
801 s.armed = false
802 return "", release.ErrCASConflict
803 }
804 return s.Store.Put(ctx, key, body, ifMatch)
805}
806
807// Only a positive answer counts against an attempt. A store that refuses
808// the invitation's or the enrolment's write with its own error (a
809// conflict, which a call failing after the deadline also returns) is
810// unknown: the attempt stands, its wait does not grow, and the next pass
811// goes on from it.
812func TestAStoreErrorIsUnknownAndKeepsTheAttempt(t *testing.T) {
813 for _, key := range []string{"control/host-actor-invitations/" + newRef + ".json", Key} {
814 t.Run(key, func(t *testing.T) {
815 w := newEnrollWorld(t, "")
816 w.pass(t)
817 if key == Key {
818 if got := w.pass(t); got != "invited" {
819 t.Fatal(got)
820 }
821 inv, _ := w.invitation(t)
822 w.guardReady(t, inv.Enrollment, true)
823 }
824 first, tries := w.attempt(t).AttemptID, w.e.attempts[newRef].tries
825 w.e.Directory.Store = &conflictStore{Store: w.e.Directory.Store, key: key, armed: true}
826 if got := w.pass(t); !strings.Contains(got, release.ErrCASConflict.Error()) {
827 t.Fatalf("conflict: %q", got)
828 }
829 if a := w.attempt(t); a.AttemptID != first || a.Consumed || w.e.attempts[newRef].tries != tries || w.e.attempts[newRef].refused != "" {
830 t.Fatalf("attempt %+v, seen %+v", a, w.e.attempts[newRef])
831 }
832 want := map[string]string{Key: "enrolled in ie"}[key]
833 if want == "" {
834 want = "invited"
835 }
836 if got := w.pass(t); !strings.HasPrefix(got, want) || w.attempt(t).AttemptID != first {
837 t.Fatalf("next pass: %q", got)
838 }
839 })
840 }
841}
842
843// vanishingStore answers the next Get of key, once armed, with the stored
844// object and then removes it, as an invitation deleted just after the
845// pass read it would be. It records each Put of key in events.
846type vanishingStore struct {
847 release.Store
848 key string
849 armed bool
850 events *[]string
851}
852
853func (s *vanishingStore) Get(ctx context.Context, key string) ([]byte, string, error) {
854 body, etag, err := s.Store.Get(ctx, key)
855 if s.armed && key == s.key && err == nil {
856 s.armed = false
857 if err := s.Store.Delete(ctx, key); err != nil {
858 return nil, "", err
859 }
860 }
861 return body, etag, err
862}
863
864func (s *vanishingStore) Put(ctx context.Context, key string, body []byte, ifMatch string) (string, error) {
865 if key == s.key {
866 *s.events = append(*s.events, "put")
867 }
868 return s.Store.Put(ctx, key, body, ifMatch)
869}
870
871// An invitation is never written without a membership read just before
872// it. Here the invitation vanishes right after the pass reads it: that
873// pass waits for the box's report and writes nothing, and the next one
874// reads membership and only then invites again.
875func TestAVanishedInvitationIsNeverWrittenWithoutARead(t *testing.T) {
876 w := newEnrollWorld(t, "")
877 w.pass(t)
878 var events []string
879 w.cloud.during = func() { events = append(events, "read") }
880 key := "control/host-actor-invitations/" + newRef + ".json"
881 vs := &vanishingStore{Store: w.e.Directory.Store, key: key, events: &events}
882 w.e.Directory.Store = vs
883 if got := w.pass(t); got != "invited" {
884 t.Fatal(got)
885 }
886 vs.armed = true
887 if got := w.pass(t); got != "waiting for its guard-ready report" {
888 t.Fatalf("read, then vanished: %q", got)
889 }
890 if _, ok := w.invitation(t); ok {
891 t.Fatal("the invitation was written again in the pass that read it")
892 }
893 if got := w.pass(t); got != "invited" {
894 t.Fatalf("after it vanished: %q", got)
895 }
896 if got := w.pass(t); got != "waiting for its guard-ready report" {
897 t.Fatalf("invited again: %q", got)
898 }
899 last := ""
900 for _, ev := range events {
901 if ev == "put" && last != "read" {
902 t.Fatalf("an invitation Put with no membership read just before it: %v", events)
903 }
904 last = ev
905 }
906 if fmt.Sprint(events) != "[read put read put]" {
907 t.Fatalf("events %v", events)
908 }
909}
910