Merge pull request 'Say a walk's phases out of order unknown, never a negative time (hq issue 382)' (#208) from fix/382-phases-out-of-order into main

This commit was merged in pull request #208.
This commit is contained in:
2026-10-10 19:36:52 +00:00
2 changed files with 50 additions and 0 deletions
+22
View File
@@ -142,6 +142,28 @@ func (p Plan) WalkPhases(now time.Time, applied AppliedLookup) *WalkPhases {
}
at := pt.at.Truncate(time.Millisecond)
ph.End = &at
if last != nil && at.Before(*last) {
// **Out of order** (issue 382): this moment was recorded before the one before it — a module's first
// send kept before its build was, two clocks, a late record. Neither phase can be measured honestly:
// the one before it is said unknown and its time joins the unknown time, and this one is said unknown
// with no time. The walk goes on from the later moment, so nothing is negative and the sum holds.
for i := len(w.Phases) - 1; i >= 0; i-- {
prev := &w.Phases[i]
if prev.End == nil {
continue // a phase that did not happen, or is unknown with no moment: the one before carries last
}
if prev.State == PhaseMeasured {
w.UnknownMS += prev.TookMS
}
prev.State, prev.Start, prev.TookMS, prev.Took = PhaseUnknown, nil, 0, ""
prev.Said = "out of order: the phase after it ended first"
break
}
ph.State, ph.Said = PhaseUnknown, "out of order: it ended before the phase before it"
w.Phases = append(w.Phases, ph)
pending = nil
continue
}
if last != nil && len(pending) == 0 {
start := *last
ph.State, ph.Start = PhaseMeasured, &start
+28
View File
@@ -300,3 +300,31 @@ func TestALateReportIsSilentNotTheEnd(t *testing.T) {
t.Fatalf("a send past the bound read as the walk's: %v %v", ok, err)
}
}
// Moments out of order — #206's own walk on 2026-10-10 kept its first send 783 ms before its build — are said
// unknown, never a negative phase: the phase before is unknown and its time joins the unknown time, the phase
// out of order has no time, and the phases still add up to the total.
func TestMomentsOutOfOrderAreUnknownNeverNegative(t *testing.T) {
p := walkOf(t, recordedWalk)
built := time.Date(2026, 10, 10, 17, 53, 8, 70000000, time.UTC) // 783 ms after its first send
p.Modules["mesh-delivery"].BuiltAt = &built
w := p.WalkPhases(time.Date(2026, 10, 10, 18, 0, 0, 0, time.UTC), nil)
sumsUp(t, w)
for _, ph := range w.Phases {
if ph.TookMS < 0 {
t.Fatalf("a negative phase: %+v", ph)
}
}
build, send := phase(w, PhaseBuild, 0), phase(w, PhaseSend, 0)
if build.State != PhaseUnknown || send.State != PhaseUnknown || send.TookMS != 0 ||
!strings.Contains(send.Said, "out of order") || !strings.Contains(build.Said, "out of order") {
t.Fatalf("build %+v, send-first %+v", build, send)
}
// The build's span (cut to its later moment) is unknown time; the judgement is measured from the later moment.
if w.UnknownMS != built.Sub(time.Date(2026, 10, 10, 17, 52, 34, 37000000, time.UTC)).Milliseconds() {
t.Fatalf("unknown %dms", w.UnknownMS)
}
if j := phase(w, PhaseJudge, 0); j.State != PhaseMeasured || j.Start == nil || !j.Start.Equal(built) {
t.Fatalf("the judgement is measured from the later moment: %+v", j)
}
}