diff --git a/modules/messenger/cmd/messenger/adr505_test.go b/modules/messenger/cmd/messenger/adr505_test.go index 2bc1f92f..bf848999 100644 --- a/modules/messenger/cmd/messenger/adr505_test.go +++ b/modules/messenger/cmd/messenger/adr505_test.go @@ -119,3 +119,93 @@ func TestAMachineWhoseDeclarationTheWalkChangesIsHeldAndNotNamedAsReached(t *tes t.Fatalf("a machine the walk also sends to stayed declared: %+v", got) } } + +// ADR 0505 §3: a condition raised 30 seconds after a delivered walk's end, on what it touched, is held; at the end +// plus the settle the end message tells it under "after the delivery of …" when it is still open, and only counts +// it when it cleared. +func TestAConditionRaisedInTheSettleIsHeldAndToldAtItsEnd(t *testing.T) { + for _, clears := range []bool{false, true} { + h, tg, dt, c, _ := newHolder(t) + walk(t, h, "plan-s", WalkStarted, "", c.now(), 600, novox("gitea")) + runFor(h, c, 3*time.Minute) + walk(t, h, "plan-s", WalkEnded, WalkDelivered, c.now(), 0, novox("gitea")) + c.pass(30 * time.Second) + k := cond("machine.novox.uncomposable", Urgent, "novox cannot get new instructions") + k.Machine, k.Raised = "novox", c.now() + h.Condition(EventRaised, k) + runFor(h, c, time.Minute) + if heard(headlineOf(k.Key), tg, dt) || !has(outcomes(h, k.Key), "held") { + t.Fatalf("raised in the settle and not held: %v", outcomes(h, k.Key)) + } + if heard("Delivered", tg, dt) { + t.Fatalf("the end was told before the settle passed: %+v", dt.sends) + } + if clears { + h.Condition(EventCleared, Condition{Key: k.Key, At: c.now()}) + } + runFor(h, c, 2*time.Minute) // the router looks each minute: the settle's end is told at the next look + switch { + case !clears && !heard("Still open after the delivery of gitea to novox:\n- Urgent: "+headlineOf(k.Key), tg, dt): + t.Fatalf("still open at the settle's end and not told under the delivery: %+v", dt.sends) + case clears && (heard(headlineOf(k.Key), tg, dt) || !heard("1 problem it raised resolved during it.", dt)): + t.Fatalf("cleared in the settle: told, or not counted: %+v", dt.sends) + } + } +} + +// ADR 0505 §3: a reminder of an older condition that falls on a touched subject while a walk is open is held like +// any other message, and told at the settle's end only when the condition is still open. +func TestAReminderDuringAWalkIsHeld(t *testing.T) { + h, tg, dt, c, _ := newHolder(t) + k := cond("machine.novox.network", Urgent, "novox lost its default route") + k.Raised = c.now() + h.Condition(EventRaised, k) + runFor(h, c, time.Minute) + first := saidOn(tg, dt) + if first == 0 { + t.Fatalf("the condition was not said before the walk") + } + runFor(h, c, RemindUrgent-3*time.Minute) + walk(t, h, "plan-r", WalkStarted, "", c.now(), 1200, novox("node-tools")) + runFor(h, c, 5*time.Minute) + if saidOn(tg, dt) != first { + t.Fatalf("the reminder was said during the walk: %+v", dt.sends) + } + if !has(outcomes(h, k.Key), "held") { + t.Fatalf("the reminder was not held: %v", outcomes(h, k.Key)) + } + walk(t, h, "plan-r", WalkEnded, WalkDelivered, c.now(), 0) + runFor(h, c, DefaultSettle+time.Minute) + if !heard("Still open after the delivery of node-tools to novox:", dt) { + t.Fatalf("the held reminder was not told at the settle's end: %+v", dt.sends) + } +} + +// ADR 0505 §3: a router that starts again while a walk settles holds on and tells its end once the settle passed. +func TestAWalkThatSettlesSurvivesARouterRestart(t *testing.T) { + h, tg, dt, c, st := newHolder(t) + walk(t, h, "plan-x", WalkStarted, "", c.now(), 1200, novox("mesh-tools")) + runFor(h, c, time.Minute) + walk(t, h, "plan-x", WalkEnded, WalkDelivered, c.now(), 0) + c.pass(10 * time.Second) + again := &Holder{Away: tg, Desk: dt, Store: st, Now: c.now, Logf: t.Logf} + if err := again.Load(); err != nil { + t.Fatal(err) + } + again.Start() + k := cond("machine.novox.tools-silent", Urgent, "the tools on novox are silent") + k.Raised = c.now() + again.Condition(EventRaised, k) + runFor(again, c, time.Minute) + if heard(headlineOf(k.Key), tg, dt) { + t.Fatalf("not held by the settling walk read back: %v", outcomes(again, k.Key)) + } + runFor(again, c, DefaultSettle) + if !heard("Still open after the delivery of mesh-tools to novox:\n- Urgent: "+headlineOf(k.Key), tg, dt) { + t.Fatalf("the settled walk's end was not told after the restart: %+v", dt.sends) + } + walk(t, again, "plan-x", WalkStarted, "", c.now().Add(-5*time.Minute), 1200, novox("mesh-tools")) + if len(again.walks) != 0 { + t.Fatalf("its late start opened it again: %+v", again.walks) + } +} diff --git a/modules/messenger/cmd/messenger/walks.go b/modules/messenger/cmd/messenger/walks.go index 0b056cfa..a0a5081f 100644 --- a/modules/messenger/cmd/messenger/walks.go +++ b/modules/messenger/cmd/messenger/walks.go @@ -42,6 +42,13 @@ package main // that the walk is still running and since when, and the cleared ones counted; it holds nothing more after // that. A walk whose end never comes is forgotten a day after it started. // +// **The settle (novox/hq ADR 0505 §3, §7).** A walk that ended delivered holds on, settling, for the setting +// settle-seconds (two minutes): what it touched stays held, a condition raised then on what it touched is held with +// it, and its end is told when the settle has passed. A walk that failed or stopped is told at once. The bound of +// §5 runs with the settle added: an open walk holds at most its bound and its settle. What a walk touches includes +// the machines whose declaration its merges change (`declared` touches, §2) and, for a walk that moves +// mesh-controller, the controller's own lease, bus and health conditions. +// // **Kept in the module's state** (the bucket `walks`, one key per walk), so a router that restarts mid-walk // holds and tells as if it had not. @@ -135,6 +142,13 @@ type Walk struct { // EndedSaid is the end's moment as the controller said it, by the controller's clock and never capped at // this router's now: a start heard after its end is compared with it on that one clock (issue 538 C). EndedSaid time.Time `json:"ended_said,omitempty"` + // SettleSeconds is the settle taken at its start (the setting settle-seconds, ADR 0505 §3): the hold of an open + // walk lasts its bound and this (§7), and a delivered walk holds this long after its end. + SettleSeconds int `json:"settle_seconds,omitempty"` + // SettleUntil is set on a walk that ended delivered and still holds, settling, until then (ADR 0505 §3); Outcome + // is how it ended. Its end is told when SettleUntil passes. + SettleUntil time.Time `json:"settle_until,omitempty"` + Outcome string `json:"outcome,omitempty"` } func (w *Walk) bound() time.Duration { @@ -144,9 +158,18 @@ func (w *Walk) bound() time.Duration { return time.Duration(w.BoundSeconds) * time.Second } -// holding says whether the walk still holds at a moment: open, and within its bound. +// settleFor is the settle the walk took at its start. +func (w *Walk) settleFor() time.Duration { return time.Duration(w.SettleSeconds) * time.Second } + +// limit is the longest a walk holds anything: its start, its bound and its settle (ADR 0505 §7). +func (w *Walk) limit() time.Time { return w.Started.Add(w.bound() + w.settleFor()) } + +// settling says whether the walk ended delivered and holds on until its settle has passed (ADR 0505 §3). +func (w *Walk) settling() bool { return !w.SettleUntil.IsZero() } + +// holding says whether the walk still holds at a moment: open or settling, and within its bound and settle. func (w *Walk) holding(now time.Time) bool { - return !w.BoundSaid && now.Before(w.Started.Add(w.bound())) + return !w.BoundSaid && now.Before(w.limit()) && (!w.settling() || now.Before(w.SettleUntil)) } // touches says whether the walk touches a subject: a machine it sends to, or — when the subject names no @@ -318,7 +341,8 @@ func (h *Holder) Walked(ev WalkEvent) { } switch ev.Phase { case WalkStarted: - w := &Walk{ID: ev.Walk, Started: at, BoundSeconds: ev.BoundSeconds, Class: ev.Class} + w := &Walk{ID: ev.Walk, Started: at, BoundSeconds: ev.BoundSeconds, Class: ev.Class, + SettleSeconds: int(h.settle() / time.Second)} h.mu.Lock() end := h.ended[ev.Walk] h.mu.Unlock() @@ -348,6 +372,13 @@ func (h *Holder) Walked(ev WalkEvent) { case WalkEnded: h.mu.Lock() w := h.walks[ev.Walk] + if w != nil && w.settling() { + // Its end said again while it settles: the same end, its touches as both sayings name them. + w.Touches = mergeTouches(w.Touches, ev.Touches) + h.mu.Unlock() + h.keepWalk(w) + return + } if w != nil && !ev.StartedAt.IsZero() && w.Started.After(ev.StartedAt) { // The end of an earlier walk under the same id, heard after the next one started: that one stays open. h.mu.Unlock() @@ -356,7 +387,6 @@ func (h *Holder) Walked(ev WalkEvent) { return } if w != nil { - delete(h.walks, ev.Walk) w.Touches = mergeTouches(w.Touches, ev.Touches) if !ev.StartedAt.IsZero() { w.Started = ev.StartedAt @@ -367,7 +397,24 @@ func (h *Holder) Walked(ev WalkEvent) { tomb = prev } h.ended[ev.Walk] = tomb + settles := w != nil && ev.Outcome == WalkDelivered && !w.BoundSaid && w.settleFor() > 0 + if settles { + // Delivered: it holds on, settling, until its settle has passed and never past its limit (ADR 0505 §3, §7). + w.Ended, w.EndedSaid, w.Outcome = at, ev.At, ev.Outcome + w.SettleUntil = at.Add(w.settleFor()) + if l := w.limit(); w.SettleUntil.After(l) { + w.SettleUntil = l + } + } else if w != nil { + delete(h.walks, ev.Walk) + } h.mu.Unlock() + if settles { + h.keepWalk(w) // settling, in place of the open walk: read back as settling after a restart + h.record(Sent{At: now, Channel: "-", Key: "walk." + ev.Walk, What: "ended " + ev.Outcome, + Outcome: "settling: holding what it touched until " + w.SettleUntil.In(h.zone()).Format("15:04:05")}) + return + } h.keepWalk(tomb) // in place of the open walk: a start heard after this end opens nothing if w == nil { h.Logf("[messenger] walk %s %s, and its start was not heard here: nothing held, nothing said", ev.Walk, ev.Outcome) @@ -480,7 +527,11 @@ func (h *Holder) release(w *Walk, now time.Time) (open []*Record, whats map[stri // endWalk tells a walk's end once (ADR 0308 §4). func (h *Holder) endWalk(w *Walk, outcome string, ended, now time.Time) { open, whats, cleared := h.release(w, now) - if now.Sub(ended) > FreshFor && len(open) == 0 { + due := ended + if w.settling() { + due = w.SettleUntil + } + if now.Sub(due) > FreshFor && len(open) == 0 { h.Logf("[messenger] walk %s %s %s ago, heard late: history, nothing said (%d held cleared meanwhile)", w.ID, outcome, roughly(now.Sub(ended)), cleared) h.record(Sent{At: now, Channel: "-", Key: "walk." + w.ID, What: "ended " + outcome, Outcome: "quiet: heard late"}) @@ -498,17 +549,32 @@ func (h *Holder) endWalk(w *Walk, outcome string, ended, now time.Time) { m = Message{Title: head + ": " + reached + ", in " + roughly(took), Quiet: true} } else { lines := []string{"It took " + roughly(took) + "."} - lines = append(lines, h.heldLines(open, whats, cleared)...) + lines = append(lines, h.heldLines(open, whats, cleared, "Still open after the delivery of "+deliveryWords(w.Touches)+":")...) m = Message{Title: head + ": " + reached, Body: strings.Join(lines, "\n")} } h.tellWalk(w, m, open, whats, oneLine, "ended "+outcome, now) } +// endSettled tells the end of a delivered walk whose settle has passed (ADR 0505 §3): what it held still open, one +// line each, and the cleared counted; then it is only the tomb that keeps a late start from opening it again. +func (h *Holder) endSettled(w *Walk, now time.Time) { + h.mu.Lock() + delete(h.walks, w.ID) + tomb := h.ended[w.ID] + if tomb == nil { + tomb = &Walk{ID: w.ID, Started: w.Started, Ended: w.Ended, EndedSaid: w.EndedSaid} + h.ended[w.ID] = tomb + } + h.mu.Unlock() + h.keepWalk(tomb) + h.endWalk(w, w.Outcome, w.Ended, now) +} + // heldLines are the lines a walk's end or bound says of what it held: each still open, then the cleared count. -func (h *Holder) heldLines(open []*Record, whats map[string]string, cleared int) []string { +func (h *Holder) heldLines(open []*Record, whats map[string]string, cleared int, heading string) []string { var lines []string if len(open) > 0 { - lines = append(lines, "Still open after it:") + lines = append(lines, heading) for _, r := range open { what := whats[r.Key] if what == "" { @@ -533,8 +599,12 @@ func (h *Holder) boundWalks(now time.Time) { h.mu.Lock() var due, gone []*Walk var stale []string + var settled []*Walk for _, w := range h.walks { - if !w.BoundSaid && !now.Before(w.Started.Add(w.bound())) { + switch { + case w.settling() && !now.Before(w.SettleUntil): + settled = append(settled, w) + case !w.settling() && !w.BoundSaid && !now.Before(w.limit()): due = append(due, w) } if now.Sub(w.Started) >= WalkForget { @@ -567,6 +637,10 @@ func (h *Holder) boundWalks(now time.Time) { h.forgetWalk(w.ID) } }() + sort.Slice(settled, func(i, j int) bool { return settled[i].SettleUntil.Before(settled[j].SettleUntil) }) + for _, w := range settled { + h.endSettled(w, now) + } sort.Slice(due, func(i, j int) bool { return due[i].Started.Before(due[j].Started) }) for _, w := range due { h.mu.Lock() @@ -586,7 +660,7 @@ func (h *Holder) boundWalks(now time.Time) { if _, ok := Check(lines[0]); !ok { lines[0] = "The walk is still running, since " + since + "." } - lines = append(lines, h.heldLines(open, whats, cleared)...) + lines = append(lines, h.heldLines(open, whats, cleared, "Still open after it:")...) m := Message{Title: "Still running: the delivery to " + touchWords(w.Touches), Body: strings.Join(lines, "\n")} h.tellWalk(w, m, open, whats, false, "past its bound", now) } @@ -717,6 +791,37 @@ func touchWords(touches []Touch) string { return listed(names) + " on " + listed(machines) } +// deliveryWords names a delivery as the operator says it: its modules, then "to" the machines it sent them to +// (ADR 0505 §1); a machine whose declaration alone changed is not among them. +func deliveryWords(touches []Touch) string { + mods := map[string]bool{} + var machines []string + for _, t := range touches { + if t.Declared { + continue + } + machines = append(machines, t.Machine) + for _, m := range t.Modules { + mods[m] = true + } + } + var names []string + for m := range mods { + names = append(names, m) + } + sort.Strings(names) + sort.Strings(machines) + switch { + case len(names) == 0 && len(machines) == 0: + return "nothing" + case len(machines) == 0: + return listed(names) + case len(names) == 0: + return "its builds to " + listed(machines) + } + return listed(names) + " to " + listed(machines) +} + // listed is at most MostNamed names, then how many more. func listed(names []string) string { if len(names) <= MostNamed { @@ -928,6 +1033,16 @@ func (h *Holder) loadWalks() error { } for i := range walks { w := walks[i] + if !w.Ended.IsZero() && w.settling() { + // Settling when the router stopped: it holds on until its settle has passed, and its end keeps a late + // start from opening it again (ADR 0505 §3). + if w.Held == nil { + w.Held = map[string]HeldMessage{} + } + h.walks[w.ID] = &w + h.ended[w.ID] = &Walk{ID: w.ID, Started: w.Started, Ended: w.Ended, EndedSaid: w.EndedSaid} + continue + } if !w.Ended.IsZero() { h.ended[w.ID] = &w continue diff --git a/modules/messenger/cmd/messenger/walks_test.go b/modules/messenger/cmd/messenger/walks_test.go index a7b86909..01fc8c49 100644 --- a/modules/messenger/cmd/messenger/walks_test.go +++ b/modules/messenger/cmd/messenger/walks_test.go @@ -131,7 +131,7 @@ func TestAMessageTouchedByTwoOverlappingWalksIsHeldUntilTheSecondEnds(t *testing h.Condition(EventRaised, k) runFor(h, c, time.Minute) walk(t, h, "plan-a", WalkEnded, WalkDelivered, c.now(), 0, novox("mesh-tools")) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) // its end is told once it settled (ADR 0505 §3) if heard(headlineOf(k.Key), tg, dt) { t.Fatalf("said at the first walk's end, while the second still holds it: %+v %+v", tg.sends, dt.sends) } @@ -139,8 +139,8 @@ func TestAMessageTouchedByTwoOverlappingWalksIsHeldUntilTheSecondEnds(t *testing t.Fatalf("the first walk's end was not told: %+v", dt.sends) } walk(t, h, "plan-b", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) - if !heard("Still open after it:\n- Urgent: "+headlineOf(k.Key), tg, dt) { + runFor(h, c, DefaultSettle+time.Minute) + if !heard("Still open after the delivery of node-tools to ace, novox:\n- Urgent: "+headlineOf(k.Key), tg, dt) { t.Fatalf("the second walk's end did not tell it: telegram %+v, desk %+v", tg.sends, dt.sends) } } @@ -222,7 +222,7 @@ func TestAWalksEndIsToldOnceWithWhatIsStillOpen(t *testing.T) { if m.Title != "Delivery failed: mesh-tools on novox" || !strings.Contains(m.Body, "It took 7 min.") { t.Fatalf("the end does not say its outcome, what it reached and how long: %q", m.Text()) } - want := "Still open after it:\n- " + headlineOf(still.Key) + "\n- Urgent: " + headlineOf(other.Key) + + want := "Still open after the delivery of mesh-tools to novox:\n- " + headlineOf(still.Key) + "\n- Urgent: " + headlineOf(other.Key) + "\n1 problem it raised resolved during it." if !strings.Contains(m.Body, want) || strings.Contains(m.Text(), headlineOf(gone.Key)) { t.Fatalf("the end message %q does not say %q", m.Body, want) @@ -241,7 +241,7 @@ func TestADeliveredWalkWithNothingHeldIsOneLineOrNothing(t *testing.T) { walk(t, h, "plan-4", WalkStarted, "", c.now(), 600, novox("mesh-tools"), Touch{Machine: "ace", Modules: []string{"mesh-tools"}}) runFor(h, c, 3*time.Minute) walk(t, h, "plan-4", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) if len(dt.sends) != 1 || len(tg.sends) != 0 { t.Fatalf("desk %+v, telegram %+v", dt.sends, tg.sends) } @@ -252,7 +252,7 @@ func TestADeliveredWalkWithNothingHeldIsOneLineOrNothing(t *testing.T) { walk(t, h, "plan-5", WalkStarted, "", c.now(), 600, novox("mesh-tools")) runFor(h, c, 3*time.Minute) walk(t, h, "plan-5", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) if len(dt.sends) != 1 || len(tg.sends) != 0 { t.Fatalf("told on a kind that says only what needs the operator: desk %+v, telegram %+v", dt.sends, tg.sends) } @@ -262,8 +262,9 @@ func TestADeliveredWalkWithNothingHeldIsOneLineOrNothing(t *testing.T) { } // §5: the bound is the controller's (bound_seconds: twice the largest budget of the walk's deliveries; none -// given, 15 minutes). At it, what is held and still open is sent with the still-running line, and what -// cleared is counted; before it, nothing; after it, the walk holds nothing more. +// given, 15 minutes), and the settle is added to it (ADR 0505 §7). At it, what is held and still open is sent +// with the still-running line, and what cleared is counted; before it, nothing; after it, the walk holds nothing +// more. func TestAHoldEndsAtTheWalksBound(t *testing.T) { for _, tc := range []struct { name string @@ -287,7 +288,7 @@ func TestAHoldEndsAtTheWalksBound(t *testing.T) { h.Condition(EventRaised, gone) c.pass(30 * time.Second) h.Condition(EventCleared, Condition{Key: gone.Key, At: c.now()}) - runFor(h, c, tc.bound-time.Minute-30*time.Second) + runFor(h, c, tc.bound+DefaultSettle-time.Minute-30*time.Second) if saidOn(tg, dt) != 0 { t.Fatalf("said before the bound: %+v %+v", tg.sends, dt.sends) } @@ -330,7 +331,7 @@ func TestHeldMessagesSurviveARouterRestart(t *testing.T) { again.Start() c.pass(2 * time.Minute) walk(t, again, "plan-8", WalkEnded, WalkDelivered, c.now(), 0) - runFor(again, c, time.Minute) + runFor(again, c, DefaultSettle+time.Minute) if !heard("- Urgent: "+headlineOf(k.Key), dt) || saidOn(tg, dt) != 2 { t.Fatalf("what was held before the restart was not told at the walk's end: desk %+v, telegram %+v", dt.sends, tg.sends) } @@ -462,7 +463,7 @@ func TestWhatAWalkHeldIsSaidOnceAChannelCanSendAgain(t *testing.T) { walk(t, h, "plan-c", WalkEnded, WalkFailed, c.now(), 0) runFor(h, c, time.Minute) } else { - runFor(h, c, 10*time.Minute) + runFor(h, c, 10*time.Minute+DefaultSettle) // the bound and the settle (ADR 0505 §7) } if saidOn(tg, dt) != 0 { t.Fatalf("said on a channel that cannot send: %+v %+v", tg.sends, dt.sends) @@ -491,7 +492,7 @@ func TestAMessageIsHeldOnByALaterWalkThatTouchesIt(t *testing.T) { walk(t, h, "plan-b", WalkStarted, "", c.now(), 1200, novox("node-tools")) runFor(h, c, time.Minute) walk(t, h, "plan-a", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) if heard(headlineOf(k.Key), tg, dt) { t.Fatalf("told at the first walk's end while the second touches it: %+v %+v", tg.sends, dt.sends) } @@ -499,8 +500,8 @@ func TestAMessageIsHeldOnByALaterWalkThatTouchesIt(t *testing.T) { t.Fatalf("the second walk does not hold it on: %v", got) } walk(t, h, "plan-b", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) - if !heard("Still open after it:\n- Urgent: "+headlineOf(k.Key), tg, dt) { + runFor(h, c, DefaultSettle+time.Minute) + if !heard("Still open after the delivery of node-tools to novox:\n- Urgent: "+headlineOf(k.Key), tg, dt) { t.Fatalf("the second walk's end did not tell it: %+v %+v", tg.sends, dt.sends) } } @@ -651,7 +652,7 @@ func TestAHeldMessageIsToldOnlyOnceTheWalksMessageWasSent(t *testing.T) { tg.fail, dt.fail = nil, nil if then == "sent" { runFor(h, c, 2*time.Minute) - if !heard("Still open after it:\n- Urgent: "+headlineOf(k.Key), tg, dt) || saidOn(tg, dt) != 2 { + if !heard("Still open after the delivery of mesh-tools to novox:\n- Urgent: "+headlineOf(k.Key), tg, dt) || saidOn(tg, dt) != 2 { t.Fatalf("not told once in the walk's message: telegram %+v, desk %+v", tg.sends, dt.sends) } if r := h.open[k.Key]; r == nil || !r.told() || r.Owed != "" || r.Sent["telegram"] != "" || r.Sent["desktop"] != "" { @@ -726,7 +727,7 @@ func TestAWalksEndHandsOnOnlyWhatALaterWalkWouldHold(t *testing.T) { } before := map[string]int{quiet.Key: helds(quiet.Key), asked.Key: helds(asked.Key)} walk(t, h, "plan-a", WalkEnded, WalkDelivered, c.now(), 0) - runFor(h, c, time.Minute) + runFor(h, c, DefaultSettle+time.Minute) for _, key := range []string{quiet.Key, asked.Key} { if got := h.heldBy(key, c.now()); len(got) != 0 { t.Errorf("%s was handed on to %v, which a first hold would never hold", key, got)