jschoubben
2711e812c8
mesh/merge-gate pass: builds mesh-delivery → novox; no bus step; every machine composes with the change as it did without (4 of 4 compose)
mesh/repo-check pass: its merge-check.sh passed, each part in its toolchain: merge-check.sh (go), merge-check-typescript.sh (typescript)
mesh/delivery delivered
mesh/delivery-group group feat/525-leaf-budget-three-minutes merged: every member is merged
ADR 0304 lowered a leaf module's delivery budget from five minutes to three; times says each class against the controller's same budget.
262 lines
11 KiB
Go
262 lines
11 KiB
Go
package main
|
|
|
|
import (
|
|
"strings"
|
|
"testing"
|
|
"time"
|
|
)
|
|
|
|
// novox/hq ADR 0282 (issue 382): a delivery keeps its delivery time, class and phases from its walk, from its
|
|
// own merge; `times` answers each class's median and worst against its budget. Measurement only.
|
|
|
|
func ms(t time.Time) *time.Time { return &t }
|
|
|
|
// phasesOf is a walk's phases as the controller says them: its earliest merge at from, then each phase of the
|
|
// given lengths one after the other, the last ending the walk.
|
|
func phasesOf(class string, from time.Time, lengths ...struct {
|
|
name string
|
|
d time.Duration
|
|
}) *WalkPhases {
|
|
p := &WalkPhases{Class: class, From: ms(from)}
|
|
at := from
|
|
for _, l := range lengths {
|
|
start := at
|
|
at = at.Add(l.d)
|
|
p.Phases = append(p.Phases, WalkPhase{Name: l.name, Tier: -1, State: phaseMeasured, Start: ms(start), End: ms(at),
|
|
TookMS: l.d.Milliseconds()})
|
|
}
|
|
p.End = ms(at)
|
|
p.TotalMS = at.Sub(from).Milliseconds()
|
|
return p
|
|
}
|
|
|
|
type ph = struct {
|
|
name string
|
|
d time.Duration
|
|
}
|
|
|
|
// walkedOnce is a merge walked to the end, the walk's phases given: its delivery's id.
|
|
func walkedOnce(w *world, number int, head, merge string, phases *WalkPhases) string {
|
|
w.t.Helper()
|
|
repo := "novox/mesh-catalog"
|
|
p := pr(repo, number, head, "feat/x")
|
|
w.h.PullUpdated(p)
|
|
w.h.Checked(verdictMoving(repo, number, head, "app"))
|
|
w.h.PullMerged(mergedAt(p, merge, phases.From.Add(10*time.Second)))
|
|
walk := aWalk("plan-"+merge[:6], repo, merge, false)
|
|
walk.Delivery = &WalkDelivery{Merges: []WalkMerge{{Repository: repo, Commit: merge}}}
|
|
w.h.WalkMoved(w.ctl.put(walk))
|
|
w.settleAll()
|
|
walk = w.ctl.walk(walk.ID)
|
|
walk.State, walk.Revision = walkDone, walk.Revision+1
|
|
walk.Modules = map[string]*WalkModule{"app": {State: "built", SentAt: phases.End}}
|
|
walk.Phases = phases
|
|
w.h.WalkMoved(w.ctl.put(walk))
|
|
w.settleAll()
|
|
return IDOf(repo, head)
|
|
}
|
|
|
|
// A delivery's time runs from its own merge — ten seconds after the walk's earliest — to its walk's end, and its
|
|
// phases still add up to it.
|
|
func TestADeliveryKeepsItsTimeFromItsOwnMerge(t *testing.T) {
|
|
w := newWorld(t)
|
|
from := t0.Add(time.Minute)
|
|
id := walkedOnce(w, 7, "head7", "merge7aaaa", phasesOf("leaf", from, ph{"window", 90 * time.Second},
|
|
ph{"queued", 5 * time.Second}, ph{"build", 25 * time.Second}, ph{"judgement", 150 * time.Second},
|
|
ph{"apply", 20 * time.Second}))
|
|
d := w.delivery(id)
|
|
if d.Time == nil {
|
|
t.Fatalf("no delivery time kept: %+v", d)
|
|
}
|
|
if d.Time.TookMS != (280*time.Second).Milliseconds() || d.Time.Class != "leaf" || !d.Time.Over {
|
|
t.Fatalf("time %dms (want 280000, from its own merge, over a leaf's three minutes), class %s, over %v", d.Time.TookMS, d.Time.Class, d.Time.Over)
|
|
}
|
|
var sum int64
|
|
for _, p := range d.Time.Phases {
|
|
if p.State == phaseMeasured {
|
|
sum += p.TookMS
|
|
}
|
|
}
|
|
if sum+d.Time.UnknownMS != d.Time.TookMS {
|
|
t.Fatalf("the phases add up to %dms + %dms unknown, its time is %dms", sum, d.Time.UnknownMS, d.Time.TookMS)
|
|
}
|
|
if d.Time.Phases[0].TookMS != 80000 || !strings.HasPrefix(d.Time.Longest, "judgement") {
|
|
t.Fatalf("its window starts at its own merge (80s), longest judgement: %+v %s", d.Time.Phases[0], d.Time.Longest)
|
|
}
|
|
// Its own merge after a first phase whose start is unknown: the unknown time moves, the sum holds.
|
|
p := phasesOf("leaf", from, ph{"window", 90 * time.Second}, ph{"build", 30 * time.Second})
|
|
p.Phases[0] = WalkPhase{Name: "window", Tier: -1, State: phaseUnknown, End: p.Phases[0].End}
|
|
p.UnknownMS = 90000
|
|
dt := timeOf(&Delivery{MergedAt: from.Add(10 * time.Second)}, Walk{ID: "w", Phases: p})
|
|
if dt.UnknownMS != 80000 || dt.TookMS != 110000 {
|
|
t.Fatalf("unknown first phase: %+v", dt)
|
|
}
|
|
// Merged after the walk's first phase ended (a later merge carried by the walk, its window already running): that
|
|
// phase is before its merge, the next starts at its merge, and nothing is negative.
|
|
p = phasesOf("leaf", from, ph{"window", 30 * time.Second}, ph{"queued", 60 * time.Second}, ph{"build", 30 * time.Second})
|
|
p.Phases[0].State, p.Phases[0].Start, p.Phases[0].TookMS = phaseUnknown, nil, 0
|
|
dt = timeOf(&Delivery{MergedAt: from.Add(45 * time.Second)}, Walk{ID: "w", Phases: p})
|
|
if dt.Unreliable != "" || dt.UnknownMS != 0 || dt.TookMS != 75000 || dt.Phases[0].State != "none" ||
|
|
dt.Phases[1].TookMS != 45000 || dt.Phases[2].TookMS != 30000 {
|
|
t.Fatalf("merged inside the second phase: %+v", dt)
|
|
}
|
|
assertSums(t, dt)
|
|
// Merged before the walk's earliest merge: the wait is unknown time, and the sum holds.
|
|
dt = timeOf(&Delivery{MergedAt: from.Add(-20 * time.Second)}, Walk{ID: "w", Phases: p})
|
|
if dt.UnknownMS != 50000 || dt.TookMS != 140000 {
|
|
t.Fatalf("merged before the walk's first merge: %+v", dt)
|
|
}
|
|
assertSums(t, dt)
|
|
// Moments out of order: unreliable, and no number.
|
|
bad := phasesOf("leaf", from, ph{"window", 30 * time.Second}, ph{"build", 30 * time.Second})
|
|
early := from.Add(10 * time.Second)
|
|
bad.Phases[1].End = &early
|
|
bad.End = &early
|
|
dt = timeOf(&Delivery{MergedAt: from}, Walk{ID: "w", Phases: bad})
|
|
if dt.Unreliable == "" || dt.TookMS != 0 {
|
|
t.Fatalf("out of order is unreliable, with no time: %+v", dt)
|
|
}
|
|
for _, ph := range dt.Phases {
|
|
if ph.TookMS != 0 || ph.Start != nil || ph.State != phaseUnknown {
|
|
t.Fatalf("an unreliable time says no phase's time: %+v", ph)
|
|
}
|
|
}
|
|
// The walk's phases not reaching its end: unreliable.
|
|
short := phasesOf("leaf", from, ph{"window", 30 * time.Second})
|
|
later := from.Add(time.Minute)
|
|
short.End = &later
|
|
if dt := timeOf(&Delivery{MergedAt: from}, Walk{ID: "w", Phases: short}); dt.Unreliable == "" || dt.TookMS != 0 {
|
|
t.Fatalf("phases short of the walk's end: %+v", dt)
|
|
}
|
|
// Merged after the walk's end: unreliable.
|
|
if dt := timeOf(&Delivery{MergedAt: from.Add(time.Hour)}, Walk{ID: "w", Phases: p}); dt.Unreliable == "" || dt.TookMS != 0 {
|
|
t.Fatalf("merged after its walk's end: %+v", dt)
|
|
}
|
|
// Exactly its budget is within it.
|
|
p = phasesOf("leaf", from, ph{"build", 3*time.Minute + 10*time.Second})
|
|
if dt := timeOf(&Delivery{MergedAt: from.Add(10 * time.Second)}, Walk{ID: "w", Phases: p}); dt.Over || dt.TookMS != 180000 {
|
|
t.Fatalf("three minutes is within a leaf's budget: %+v", dt)
|
|
}
|
|
p = phasesOf("leaf", from, ph{"build", 3*time.Minute + 11*time.Second})
|
|
if dt := timeOf(&Delivery{MergedAt: from.Add(10 * time.Second)}, Walk{ID: "w", Phases: p}); !dt.Over {
|
|
t.Fatalf("a second past three minutes is over a leaf's budget: %+v", dt)
|
|
}
|
|
// Seen again, unchanged: not written again (issue 326).
|
|
before := w.store.puts
|
|
w.h.Reconcile()
|
|
w.settleAll()
|
|
if w.store.puts != before {
|
|
t.Fatalf("a delivery whose time did not change was written again")
|
|
}
|
|
}
|
|
|
|
// A walk whose end is not known gives no time; a phase unknown in the walk stays unknown, never a zero.
|
|
func TestNoEndNoTime(t *testing.T) {
|
|
w := newWorld(t)
|
|
p := phasesOf("core", t0, ph{"window", time.Minute}, ph{"build", time.Minute})
|
|
p.End, p.TotalMS = nil, 0
|
|
p.Phases = append(p.Phases, WalkPhase{Name: "apply", Tier: -1, State: phaseUnknown, Said: "waiting for ace"})
|
|
p.Said = "its end is unknown: apply (waiting for ace)"
|
|
id := walkedOnce(w, 8, "head8", "merge8bbbb", p)
|
|
if d := w.delivery(id); d.Time != nil {
|
|
t.Fatalf("a time without an end: %+v", d.Time)
|
|
}
|
|
got, err := w.h.Times(0, id)
|
|
if err != nil || !strings.Contains(mustString(got), "waiting for ace") {
|
|
t.Fatalf("the delivery's time says why it is not known: %v %v", got, err)
|
|
}
|
|
a := w.h.times(7)
|
|
if len(a.Unknown) != 1 || !strings.Contains(a.Unknown[0], "waiting for ace") {
|
|
t.Fatalf("a delivered delivery with no known time is said: %+v", a.Unknown)
|
|
}
|
|
}
|
|
|
|
// `times`: each class's median, worst, within and over its budget, its newest delivery, and every delivery over.
|
|
func TestTimesSaysEachClassAgainstItsBudget(t *testing.T) {
|
|
w := newWorld(t)
|
|
leaf := func(n int, d time.Duration, at time.Duration) string {
|
|
return walkedOnce(w, n, "head"+string(rune('a'+n)), "merge"+string(rune('a'+n))+"zzzz",
|
|
phasesOf("leaf", t0.Add(at), ph{"window", 10 * time.Second}, ph{"judgement", d}))
|
|
}
|
|
leaf(1, 1*time.Minute, 0)
|
|
leaf(2, 2*time.Minute, time.Hour)
|
|
over := leaf(3, 6*time.Minute, 2*time.Hour)
|
|
walkedOnce(w, 4, "headcore", "mergekore1", phasesOf("core", t0.Add(3*time.Hour), ph{"judgement", 9 * time.Minute}))
|
|
w.later(4 * time.Hour)
|
|
a := w.h.times(7)
|
|
if len(a.Classes) != 2 || a.Classes[0].Class != "leaf" {
|
|
t.Fatalf("classes: %+v", a.Classes)
|
|
}
|
|
l := a.Classes[0]
|
|
// Each delivery's time is from its own merge, ten seconds after the walk's: 1m, 2m, 6m.
|
|
if l.Count != 3 || l.Within != 2 || l.Over != 1 || l.MedianMS != (2*time.Minute).Milliseconds() ||
|
|
l.WorstMS != (6*time.Minute).Milliseconds() || l.WorstID != over {
|
|
t.Fatalf("leaf: %+v", l)
|
|
}
|
|
if l.Latest == nil || l.Latest.ID != over || !l.Latest.Over || !strings.HasPrefix(l.Latest.Longest, "judgement") {
|
|
t.Fatalf("the newest leaf delivery: %+v", l.Latest)
|
|
}
|
|
if c := a.Classes[1]; c.Count != 1 || c.Over != 0 || c.Latest == nil || c.Latest.Over {
|
|
t.Fatalf("core within ten minutes: %+v", c)
|
|
}
|
|
if len(a.Over) != 1 || a.Over[0].ID != over {
|
|
t.Fatalf("over: %+v", a.Over)
|
|
}
|
|
if !strings.Contains(a.Line, "leaf: median 2m0s, worst 6m0s, 2 of 3 within 3m0s") {
|
|
t.Fatalf("the line: %s", a.Line)
|
|
}
|
|
// Past the window, nothing.
|
|
w.later(8 * 24 * time.Hour)
|
|
if a := w.h.times(7); a.Classes[0].Count != 0 || a.Classes[0].Latest != nil {
|
|
t.Fatalf("deliveries older than the window are not counted: %+v", a.Classes[0])
|
|
}
|
|
}
|
|
|
|
func mustString(v any) string { return string(mustJSON(v)) }
|
|
|
|
// assertSums checks a delivery time's measured phases and unknown time add up to it, and none is negative.
|
|
func assertSums(t *testing.T, dt *DeliveryTime) {
|
|
t.Helper()
|
|
sum := dt.UnknownMS
|
|
if dt.UnknownMS < 0 {
|
|
t.Fatalf("negative unknown time: %+v", dt)
|
|
}
|
|
for _, p := range dt.Phases {
|
|
if p.TookMS < 0 {
|
|
t.Fatalf("negative phase %s: %+v", p.Name, p)
|
|
}
|
|
if p.State == phaseMeasured {
|
|
sum += p.TookMS
|
|
}
|
|
}
|
|
if sum != dt.TookMS {
|
|
t.Fatalf("the phases add up to %dms, the delivery time is %dms: %+v", sum, dt.TookMS, dt)
|
|
}
|
|
}
|
|
|
|
// An unreliable time is said among the unknown, never in a median, an over count or the newest of its class.
|
|
func TestAnUnreliableTimeIsNeverCounted(t *testing.T) {
|
|
w := newWorld(t)
|
|
good := walkedOnce(w, 11, "headgood", "mergegood1", phasesOf("leaf", t0, ph{"build", 2 * time.Minute}))
|
|
bad := phasesOf("leaf", t0.Add(time.Hour), ph{"window", 30 * time.Second}, ph{"build", 9 * time.Minute})
|
|
early := t0.Add(time.Hour + 10*time.Second)
|
|
bad.Phases[1].End, bad.End = &early, &early
|
|
unreliable := walkedOnce(w, 12, "headbad", "mergebad01", bad)
|
|
if d := w.delivery(unreliable); d.Time == nil || d.Time.Unreliable == "" {
|
|
t.Fatalf("the out-of-order walk gave a time: %+v", d.Time)
|
|
}
|
|
w.later(2 * time.Hour)
|
|
a := w.h.times(7)
|
|
l := a.Classes[0]
|
|
if l.Count != 1 || l.Over != 0 || l.Latest == nil || l.Latest.ID != good || l.WorstID != good {
|
|
t.Fatalf("an unreliable time was counted: %+v", l)
|
|
}
|
|
found := false
|
|
for _, u := range a.Unknown {
|
|
found = found || strings.HasPrefix(u, unreliable+": its time is unreliable")
|
|
}
|
|
if !found {
|
|
t.Fatalf("the unreliable delivery is not said among the unknown: %v", a.Unknown)
|
|
}
|
|
}
|