mesh-delivery-gate: the Approve's verdict bound counts from the latest head, restarts with its check, and speaks the operator's time (issue 1733, review round 1)

A group member made ready in an event handler has no ready run when its sibling
is looked at; the bound counted from the older sibling alone, so a re-push past
60 minutes asked at once as unanswered. Such a member now counts as ready now.

The bound also counts from a check starting again at the same heads, or its
verdict being taken away, so a pass that turns back into running never asks at
once as unanswered. Times in the wait and the ask are the operator's zone
(Europe/Brussels, as the messenger says them), and a placement change whose pass
holds no composition says that no node answered its placement.

modules/mesh-delivery-gate/cmd/mesh-delivery-gate/helpers_test.go

@@ -36,8 +36,20 @@ func statusOn(w *world, repo, commit string) string {
 // checkerSays puts the checker's verdict at these heads together into its verdicts bucket, as captured on the bus
 // (mesh-delivery-checker, key `<group>.<heads hash>`).
 func checkerSays(w *world, group, state, failed string, heads ...sdk.Head) {
+	checkerSaysWith(w, group, state, failed, nil, heads...)
+}
+
+// checkerSaysWith is checkerSays with more of the verdict's fields (its composition); the state "gone" deletes the key.
+func checkerSaysWith(w *world, group, state, failed string, more map[string]any, heads ...sdk.Head) {
 	hash, _ := sdk.HeadsHash(heads)
-	value, _ := json.Marshal(map[string]any{"v": 1, "group": group, "heads": hash, "state": state,
+	if state == "gone" {
-		"failed": map[string]string{"words": failed}})
+		w.h.CheckerVerdictChanged(group+"."+hash, nil)
+		return
+	}
+	v := map[string]any{"v": 1, "group": group, "heads": hash, "state": state, "failed": map[string]string{"words": failed}}
+	for k, x := range more {
+		v[k] = x
+	}
+	value, _ := json.Marshal(v)
 	w.h.CheckerVerdictChanged(group+"."+hash, value)
 }

modules/mesh-delivery-gate/cmd/mesh-delivery-gate/holder.go

@@ -77,7 +77,10 @@ type Holder struct {
 	unchecked map[string]unchecked
 	// checker are the checker's verdicts by the hash of the heads they judged, as its verdicts bucket holds them
 	// (onestatus.go, issue 1302); runningSince when this owner first saw each running (ADR 0548 §2, turns.go).
-	checker      map[string]checkerVerdict
+	checker map[string]checkerVerdict
+	// verdictGone is when the checker's verdict at a heads hash was taken away (its key deleted): the Approve's wait for a
+	// verdict counts its bound from then, as from a check that starts again (verdictWaits).
+	verdictGone  map[string]time.Time
 	runningSince map[string]time.Time
 	// unmergeableSince is when the forge first said a group's member does not merge now, by group and member (issue 1275,
 	// group_merge.go): within forgeMergeGrace that is the forge still working out mergeability, asked again shortly.
@@ -141,7 +144,7 @@ func (h *Holder) init() {
 	h.lostRead = map[string]time.Time{}
 	h.unchecked = map[string]unchecked{}
 	h.checker = map[string]checkerVerdict{}
-	h.runningSince, h.turnsHeld = map[string]time.Time{}, map[string]sdk.Turn{}
+	h.runningSince, h.turnsHeld, h.verdictGone = map[string]time.Time{}, map[string]sdk.Turn{}, map[string]time.Time{}
 	h.reach = map[string]sdk.Reach{}
 	h.started = h.Now()
 }

modules/mesh-delivery-gate/cmd/mesh-delivery-gate/onestatus.go

@@ -8,6 +8,7 @@ import (
 	"sort"
 	"strings"
 	"time"
+	_ "time/tzdata" // the operator's zone is known whatever this machine has installed
 
 	sdk "git.novox.be/novox/mesh-sdk/go/delivery"
 )
@@ -57,6 +58,12 @@ type checkerVerdict struct {
 		Machine string `json:"machine,omitempty"`
 		Words   string `json:"words,omitempty"`
 	} `json:"failed,omitzero"`
+	// Composition is what the check of the machines' composition made of it (mesh-sdk delivery.Composition): its state
+	// not-run says the composition, and with it a placement change's answers from its nodes, was not judged.
+	Composition *struct {
+		State string `json:"state"`
+		Words string `json:"words,omitempty"`
+	} `json:"composition,omitempty"`
 }
 
 // CheckerVerdictChanged takes a key of the checker's verdicts bucket (`<group>.<heads hash>`) put or deleted (an empty
@@ -75,9 +82,13 @@ func (h *Holder) CheckerVerdictChanged(key string, value []byte) {
 	if h.runningSince == nil {
 		h.runningSince = map[string]time.Time{}
 	}
+	if h.verdictGone == nil {
+		h.verdictGone = map[string]time.Time{}
+	}
 	if len(value) == 0 || string(value) == "null" {
 		delete(h.checker, hash)
 		delete(h.runningSince, hash)
+		h.verdictGone[hash] = h.Now()
 		h.Poke()
 		return
 	}
@@ -93,6 +104,7 @@ func (h *Holder) CheckerVerdictChanged(key string, value []byte) {
 		h.runningSince[v.Heads] = h.Now() // a check starts: a merge it holds says since when (ADR 0548 §2)
 	} else if v.State != checkerRunning {
 		delete(h.runningSince, v.Heads)
+		delete(h.verdictGone, v.Heads)
 	}
 	h.checker[v.Heads] = v
 	h.Poke()
@@ -329,11 +341,11 @@ func (h *Holder) checkAt(members []*Delivery) checkSaid {
 	if ok {
 		switch v.State {
 		case checkerPass:
-			return checkSaid{Key: checkSaidPass, Words: "passed its check"}
+			return checkSaid{Key: checkSaidPass, Words: "passed its check" + notComposed(v, members)}
 		case checkerRunning:
 			words := "its check has no verdict yet: it is running"
 			if since, held := h.runningSince[hash]; held && !since.IsZero() {
-				words += " (since " + since.UTC().Format("15:04") + " UTC)"
+				words += " (since " + clockSaid(since) + ")"
 			}
 			return checkSaid{Key: checkSaidRunning, Words: words}
 		default:
@@ -371,3 +383,31 @@ func (h *Holder) checkAt(members []*Delivery) checkSaid {
 	}
 	return checkSaid{Key: checkSaidNone, Words: "its check has no verdict yet"}
 }
+
+// notComposed is what a passing verdict adds when its composition was not judged (mesh-sdk delivery.CompositionNotRun): a
+// placement change's pass then holds no node's answer to its placement (ADR 0559 §5), which the ask says. Empty otherwise.
+func notComposed(v checkerVerdict, members []*Delivery) string {
+	if v.Composition == nil || v.Composition.State != sdk.CompositionNotRun {
+		return ""
+	}
+	why := firstOf(oneLine(v.Composition.Words), "it was not run")
+	for _, m := range members {
+		for _, p := range m.Paths {
+			if strings.HasPrefix(p, "placement/") && strings.HasSuffix(p, ".json") {
+				return ", but its composition was not judged (" + why + "), so no node answered its placement"
+			}
+		}
+	}
+	return ", but its composition was not judged (" + why + ")"
+}
+
+// operatorZone is the zone the operator reads times in, as the messenger says them (its time-zone setting).
+var operatorZone = func() *time.Location {
+	if loc, err := time.LoadLocation("Europe/Brussels"); err == nil {
+		return loc
+	}
+	return time.UTC
+}()
+
+// clockSaid is a time of day as the operator reads it: in their zone, named ("00:35 CET").
+func clockSaid(t time.Time) string { return t.In(operatorZone).Format("15:04 MST") }

modules/mesh-delivery-gate/cmd/mesh-delivery-gate/ready.go

@@ -471,25 +471,38 @@ func (h *Holder) verdictWaits(d *Delivery) string {
 	if c.Key == checkSaidPass || c.Key == checkSaidFail {
 		return ""
 	}
-	until := h.readySince(d, members).Add(askCheckBound)
+	until := h.waitSince(d, members).Add(askCheckBound)
 	if !h.Now().Before(until) {
 		return ""
 	}
 	h.lookAt(until, "an Approve that waits its check, asked anyway at its bound")
-	return waitsCheckBeforeAsking + c.Words + "; asked anyway at " + until.UTC().Format("15:04") + " UTC if it has not answered"
+	return waitsCheckBeforeAsking + c.Words + "; asked anyway at " + clockSaid(until) + " if it has not answered"
 }
 
-// readySince is when the latest of the heads an ask would cover became ready: the bound of verdictWaits counts from it.
+// waitSince is when the wait for a verdict began, the moment the bound of verdictWaits counts from: the latest of the
-func (h *Holder) readySince(d *Delivery, members []*Delivery) time.Time {
+// heads becoming ready (a member with no ready run yet, such as one re-pushed or settled ready by an event this look has
-	since := h.Now()
+// not reached, became ready now), the check at those heads starting again, and its verdict being taken away. Under the lock.
-	if d.Ready != nil {
+func (h *Holder) waitSince(d *Delivery, members []*Delivery) time.Time {
-		since = d.Ready.Seen
+	now := h.Now()
-	}
+	since := time.Time{}
-	for _, m := range members {
+	later := func(t time.Time) {
-		if m.Ready != nil && m.Ready.Seen.After(since) {
+		if t.After(since) {
-			since = m.Ready.Seen
+			since = t
 		}
 	}
+	for _, m := range append([]*Delivery{d}, members...) {
+		if m.Ready == nil {
+			return now
+		}
+		later(m.Ready.Seen)
+	}
+	if hash, err := sdk.HeadsHash(headsOf(members)); err == nil {
+		later(h.runningSince[hash])
+		later(h.verdictGone[hash])
+	}
+	if since.IsZero() || since.After(now) {
+		return now
+	}
 	return since
 }
 

modules/mesh-delivery-gate/cmd/mesh-delivery-gate/ready_test.go

@@ -75,16 +75,17 @@ func TestAnApprovedPullRequestIsMergedThroughTheMergeTool(t *testing.T) {
 	// past which it is asked anyway, saying so, and asked again in new words once the check passes. The verdict is the
 	// checker's verdicts bucket value as captured on the bus (mesh-delivery-checker, `<group>.<heads hash>`).
 	for _, row := range []struct {
-		name, state, failed, then string
+		name, state, failed, then, path string
-		gated                     bool
+		gated                           bool
-		after                     time.Duration
+		notComposed                     bool
-		asks                      int
+		after                           time.Duration
-		want, not                 []string
+		asks, open                      int
+		want, not                       []string
 	}{
 		{name: "gated, passed", gated: true, state: "pass", asks: 1,
 			want: []string{"app#7 Fix it passed its check. Approve merges it into main at " + readyHead[:12] + ";"},
 			not:  []string{"before its check ends", "no verdict yet"}},
-		{name: "ungated, no verdict", asks: 0, want: []string{waitsCheckBeforeAsking + "its check has no verdict yet; asked anyway at "}},
+		{name: "ungated, no verdict", asks: 0, want: []string{waitsCheckBeforeAsking + "its check has no verdict yet; asked anyway at 15:00 CEST if"}},
 		{name: "ungated, running", state: "running", asks: 0, want: []string{waitsCheckBeforeAsking + "its check has no verdict yet: it is running"}},
 		{name: "ungated, running past its bound", state: "running", after: askCheckBound, asks: 1,
 			want: []string{"its check has no verdict yet: it is running", "has given none in 60 minutes, so the operator is asked anyway",
@@ -93,6 +94,15 @@ func TestAnApprovedPullRequestIsMergedThroughTheMergeTool(t *testing.T) {
 			want: []string{"passed its check. Approve merges it into main at " + readyHead[:12] + ";"}, not: []string{"before its check ends", "anyway"}},
 		{name: "ungated, passed", state: "pass", asks: 1,
 			want: []string{"passed its check. Approve merges it into main at " + readyHead[:12] + ";"}, not: []string{"before its check ends"}},
+		// A pass that turns back into a check with no verdict (a check started again, its verdict taken away) past the bound
+		// withdraws the ask, and the bound counts again from that moment: nothing is asked at once as unanswered.
+		{name: "ungated, passed, running again past its bound", state: "pass", after: askCheckBound, then: "running", asks: 1, open: -1,
+			want: []string{waitsCheckBeforeAsking + "its check has no verdict yet: it is running (since 15:00 CEST); asked anyway at 16:00 CEST"}},
+		{name: "ungated, passed, its verdict gone past its bound", state: "pass", after: askCheckBound, then: "gone", asks: 1, open: -1,
+			want: []string{waitsCheckBeforeAsking + "its check has no verdict yet; asked anyway at 16:00 CEST"}},
+		// A placement change's pass with its composition not judged holds no node's answer, and the ask says so (ADR 0559 §5).
+		{name: "ungated, placement passed uncomposed", state: "pass", path: "placement/node-a.json", notComposed: true, asks: 1,
+			want: []string{"passed its check, but its composition was not judged (the assigner is not running), so no node answered its placement"}},
 		{name: "ungated, failed", state: "fail", failed: "TestThing: wanted 1, got 2", asks: 1,
 			want: []string{"its check failed: TestThing: wanted 1, got 2", "although its check failed"}, not: []string{"passed", "anyway"}},
 	} {
@@ -102,7 +112,7 @@ func TestAnApprovedPullRequestIsMergedThroughTheMergeTool(t *testing.T) {
 				ungated(v)
 			}
 			v.op.auto = false
-			p := pr("novox/app", 7, readyHead, "feat/x", "src/a.go")
+			p := pr("novox/app", 7, readyHead, "feat/x", firstOf(row.path, "src/a.go"))
 			p.Title = "Fix it"
 			v.h.PullUpdated(p)
 			head := headOf("novox/app", 7, readyHead)
@@ -111,7 +121,11 @@ func TestAnApprovedPullRequestIsMergedThroughTheMergeTool(t *testing.T) {
 			}
 			v.settleAll()
 			if !row.gated && row.state != "" {
-				checkerSays(v, "g", row.state, row.failed, head)
+				var more map[string]any
+				if row.notComposed {
+					more = map[string]any{"composition": map[string]string{"state": "not-run", "words": "the assigner is not running"}}
+				}
+				checkerSaysWith(v, "g", row.state, row.failed, more, head)
 				v.settleAll()
 			}
 			if row.after > 0 {
@@ -123,10 +137,14 @@ func TestAnApprovedPullRequestIsMergedThroughTheMergeTool(t *testing.T) {
 				v.settleAll()
 			}
 			open := v.op.open()
-			if v.op.count() != row.asks || len(open) != min(row.asks, 1) {
+			wantOpen := min(row.asks, 1)
-				t.Fatalf("open asks %v, asked %d times; wanted asked %d times", open, v.op.count(), row.asks)
+			if row.open < 0 {
+				wantOpen = 0
 			}
-			if row.asks == 0 {
+			if v.op.count() != row.asks || len(open) != wantOpen {
+				t.Fatalf("open asks %v, asked %d times; wanted asked %d times, %d open", open, v.op.count(), row.asks, wantOpen)
+			}
+			if wantOpen == 0 {
 				d := v.delivery(IDOf("novox/app", readyHead))
 				for _, w := range row.want {
 					if d.Ready == nil || !strings.Contains(d.Ready.Waits, w) {
@@ -359,6 +377,26 @@ func TestAGroupMergesEveryMemberInOnePassOnlyOnceComposedAndApproved(t *testing.
 	if e := u.op.ask(u.op.open()[0]).Explanation; !strings.Contains(e, "2 pull requests, passed its check. Approve merges all of them into main in one pass, at the heads named;") {
 		t.Fatalf("ungated, the group's ask does not say its check passed:\n%s", e)
 	}
+	// A member re-pushed past the bound after its sibling became ready: the bound counts from the new head, so nothing is
+	// asked as unanswered at once (review round 1).
+	r := newWorld(t)
+	ungated(r)
+	r.op.auto = false
+	const ctlHead2 = "c3c3c3c3c3c3c3c3c3c3c3c3c3c3c3c3c3c3c3c3"
+	r.h.PullUpdated(pr("novox/mesh-controller", 1, ctlHead, "feat/x", "internal/a.go"))
+	r.h.PullUpdated(pr("novox/mesh-catalog", 2, catHead, "feat/x", "modules/app/module.json"))
+	r.settleAll()
+	r.later(askCheckBound + time.Minute)
+	r.h.PullUpdated(pr("novox/mesh-controller", 1, ctlHead2, "feat/x", "internal/a.go"))
+	// Ready in its handler, with no run yet, while the check of the group's new heads together runs.
+	r.h.Checked(judgedAt("novox/mesh-controller", 1, ctlHead2, "pass", "t1t1t1t1t1t1"))
+	checkerSays(r, "feat/x", "running", "", headOf("novox/mesh-controller", 1, ctlHead2), headOf("novox/mesh-catalog", 2, catHead))
+	r.settleAll()
+	if d := r.delivery(IDOf("novox/mesh-catalog", catHead)); r.op.count() != 0 || d.Ready == nil ||
+		!strings.Contains(d.Ready.Waits, waitsCheckBeforeAsking) {
+		t.Fatalf("a member re-pushed past the bound: asked %d times, wait %+v; wanted none asked and the wait said", r.op.count(), d.Ready)
+	}
+
 	u.op.answer(u.op.open()[0], OptionApprove)
 	u.settleAll()
 	if len(u.forge.merges) != 2 {