Merge pull request 'Say a group member refused only because main moved a warning for ten minutes, urgent after (issue 1275 AC6, ADR 0442)' (#376) from fix/1275-ac6-out-of-date-warning into main

modules/mesh-delivery/cmd/mesh-delivery/events_test.go

@@ -157,7 +157,7 @@ var errAskedAgain = &askedAgainError{}
 type askedAgainError struct{}
 
 func (*askedAgainError) Error() string {
-	return "the forge refused gitea_merge_pull_request: The check of head merged into trunk was asked"
+	return "the forge refused gitea_merge_pull_request: novox/app#7 is not merged: its verdict was judged against trunk aaaaaaaaaaaa, and main is now bbbbbbbbbbbb. The check of head cccccccccccc merged into trunk bbbbbbbbbbbb was asked; took 3s. Ask again at cccccccccccc once both statuses pass. Nothing was merged"
 }
 
 // Issue 1022 (ADR 0421 §5): the review record is read and put in the ask; it is never a gate.

modules/mesh-delivery/cmd/mesh-delivery/issue1275_test.go

@@ -248,3 +248,166 @@ func TestAMemberBothRefusedAndHeldForAStatusIsOneStalledLine(t *testing.T) {
 		t.Fatalf("%d stalled lines for one member: %+v", n, w.h.Stalled())
 	}
 }
+
+// 1275/AC6: a member refused because its verdict is out of date (the trunk moved; its fresh check runs) is a warning at
+// once, and urgent only when the group is not merged within ten minutes; the pass stops at the refusal all the same.
+func TestAnOutOfDateRefusalIsAWarningAtOnceAndUrgentAfterTenMinutes(t *testing.T) {
+	w := approvedGroup(t)
+	allGreen(w)
+	w.forge.refuse = errAskedAgain
+	w.op.answer(w.op.open()[0], OptionApprove)
+	w.settleAll()
+	if len(w.forge.merges) != 1 {
+		t.Fatalf("the pass did not stop at the refusal: %v", w.forge.merges)
+	}
+	sev := func() []string {
+		var out []string
+		for _, l := range w.h.Stalled() {
+			out = append(out, l.Severity)
+		}
+		return out
+	}
+	if got := sev(); len(got) != 1 || got[0] != "warning" {
+		t.Fatalf("an out of date refusal is %v at once; wanted one warning", got)
+	}
+	w.later(9 * time.Minute)
+	if got := sev(); len(got) != 1 || got[0] != "warning" {
+		t.Fatalf("at nine minutes it is %v; wanted still a warning", got)
+	}
+	w.later(2 * time.Minute)
+	if got := sev(); len(got) != 1 || got[0] != "urgent" {
+		t.Fatalf("after ten minutes it is %v; wanted urgent", got)
+	}
+}
+
+// 1275/AC6: every other refusal (here a missing status) is urgent at once.
+func TestAMissingStatusRefusalIsUrgentAtOnce(t *testing.T) {
+	w := approvedGroup(t)
+	allGreen(w)
+	w.forge.refuseRepo = map[string]error{gCat: refusedWords("novox/mesh-catalog#2")}
+	w.op.answer(w.op.open()[0], OptionApprove)
+	w.settleAll()
+	if lines := w.h.Stalled(); len(lines) != 1 || lines[0].Severity != "urgent" {
+		t.Fatalf("a missing status refusal is not urgent at once: %+v", lines)
+	}
+}
+
+func severities(w *world) []string {
+	var out []string
+	for _, l := range w.h.Stalled() {
+		out = append(out, l.Severity)
+	}
+	return out
+}
+
+// 1275/AC6 (b): the same out of date refusal on a LATER member, after the earlier one merged, is a warning at once and
+// urgent after ten minutes: the half merged group does not say it urgent at once.
+func TestAnOutOfDateRefusalOnALaterMemberIsAWarningThenUrgent(t *testing.T) {
+	w := approvedGroup(t)
+	allGreen(w)
+	w.forge.refuseRepo = map[string]error{gCtl: errAskedAgain}
+	w.op.answer(w.op.open()[0], OptionApprove)
+	w.settleAll()
+	w.h.PullMerged(merged(gCat, 2, gHk, gT1))
+	w.settleAll()
+	if got := severities(w); len(got) != 1 || got[0] != "warning" {
+		t.Fatalf("a later member's out of date refusal is %v at once; wanted one warning", got)
+	}
+	w.later(11 * time.Minute)
+	if got := severities(w); len(got) != 1 || got[0] != "urgent" {
+		t.Fatalf("after ten minutes it is %v; wanted urgent", got)
+	}
+}
+
+// 1275/AC6 (c): words naming an out of date check and also a missing status are urgent at once.
+func TestARefusalNamingOutOfDateAndAMissingStatusIsUrgentAtOnce(t *testing.T) {
+	w := approvedGroup(t)
+	allGreen(w)
+	w.forge.refuse = errors.New("the forge refused gitea_merge_pull_request: novox/mesh-catalog#2 is not merged: its verdict was " +
+		"judged against trunk aaaaaaaaaaaa, and main is now bbbbbbbbbbbb. The check of head cccc merged into trunk bbbb was " +
+		"asked. main requires mesh/merge-gate, mesh/repo-check; not a success: mesh/repo-check (missing)")
+	w.op.answer(w.op.open()[0], OptionApprove)
+	w.settleAll()
+	if got := severities(w); len(got) != 1 || got[0] != "urgent" {
+		t.Fatalf("a refusal with two causes is %v; wanted urgent at once", got)
+	}
+}
+
+// 1275/AC6 (d): words mesh-delivery cannot classify are urgent at once.
+func TestARefusalInUnknownWordsIsUrgentAtOnce(t *testing.T) {
+	w := approvedGroup(t)
+	allGreen(w)
+	w.forge.refuse = errors.New("the forge refused gitea_merge_pull_request: something nobody foresaw")
+	w.op.answer(w.op.open()[0], OptionApprove)
+	w.settleAll()
+	if got := severities(w); len(got) != 1 || got[0] != "urgent" {
+		t.Fatalf("an unclassified refusal is %v; wanted urgent at once", got)
+	}
+}
+
+// The merge tool's refusals, copied from gitea merge.ts with their line, `${...}` filled in.
+var mergeToolRefusals = []struct {
+	line       string
+	words      string
+	outOfDated bool
+}{
+	{"merge.ts:121", "novox/app#7 is not merged: its verdict was judged against trunk aaaaaaaaaaaa, and main is now bbbbbbbbbbbb. " +
+		"Its check is already asked and not yet answered (building), so it is not asked again; took 3s. Ask again at cccccccccccc once " +
+		"both statuses pass: this tool never merges by itself (novox/hq ADR 0323). A check that never answers is asked again with " +
+		"mesh-delivery.recheck. Nothing was merged", true},
+	{"merge.ts:147", "novox/app#7 is not merged: its verdict was judged against trunk aaaaaaaaaaaa, and main is now bbbbbbbbbbbb. " +
+		"The check of head cccccccccccc merged into trunk bbbbbbbbbbbb was asked; took 3s. Ask again at cccccccccccc once both " +
+		"statuses pass: this tool never merges by itself (novox/hq ADR 0323). In a busy repository another merge may move the trunk " +
+		"again first; this is then refused and asked once more. A check that never answers is asked again with " +
+		"mesh-delivery.recheck. Nothing was merged", true},
+	{"merge.ts:144", "novox/app#7 is not merged: its verdict was judged against trunk aaaaaaaaaaaa, and main is now bbbbbbbbbbbb, " +
+		"and its check could not be asked: the forge is away. Nothing was merged", false},
+	{"merge.ts:156", "novox/app#7 is not merged: main requires mesh/merge-gate, mesh/repo-check; not a success: mesh/repo-check " +
+		"(pending). A pull request merges once its checks succeed", false},
+	{"merge.ts:165", "novox/app#7 is not merged: its verdict read siblings, and which ones is not held here, so the group cannot " +
+		"be weighed. Ask its check again at cccccccccccc. Nothing was merged", false},
+	{"merge.ts:172", "novox/app#7 is not merged: its verdict was judged beside 1 sibling(s), and a sibling is not ready. A member " +
+		"judged beside its siblings merges once its group passed at the heads that verdict read (novox/hq ADR 0382, 0421). " +
+		"Nothing was merged", false},
+}
+
+// 1275/AC6 (e): only the merge tool's two out of date refusals (:121, :147) are warnings; the one saying its check could
+// not be asked (:144) and every other is urgent at once.
+func TestOnlyTheMergeToolsTwoOutOfDateRefusalsAreWarnings(t *testing.T) {
+	for _, c := range mergeToolRefusals {
+		if got := outOfDateRefusal(c.words); got != c.outOfDated {
+			t.Errorf("%s: outOfDateRefusal = %v, wanted %v", c.line, got, c.outOfDated)
+		}
+		w := approvedGroup(t)
+		allGreen(w)
+		w.forge.refuse = errors.New("the forge refused gitea_merge_pull_request: " + c.words)
+		w.op.answer(w.op.open()[0], OptionApprove)
+		w.settleAll()
+		want := "urgent"
+		if c.outOfDated {
+			want = "warning"
+		}
+		if got := severities(w); len(got) != 1 || got[0] != want {
+			t.Errorf("%s: severity %v at once, wanted %s", c.line, got, want)
+		}
+	}
+}
+
+// 1275/AC6 (f): the severity never steps down: a missing status refusal, then an out of date one, stays urgent.
+func TestASeverityOnceUrgentNeverStepsDownToAWarning(t *testing.T) {
+	w := approvedGroup(t)
+	allGreen(w)
+	w.forge.refuseRepo = map[string]error{gCat: refusedWords("novox/mesh-catalog#2")}
+	w.op.answer(w.op.open()[0], OptionApprove)
+	w.settleAll()
+	w.forge.refuseRepo = map[string]error{gCat: errAskedAgain}
+	w.h.mergeAgainNow(w.delivery(IDOf(gCat, gHk)))
+	w.later(time30s)
+	w.settleAll()
+	if d := w.delivery(IDOf(gCat, gHk)); !outOfDateRefusal(d.Ready.Answer) {
+		t.Fatalf("the second refusal was not the out of date one: %q", d.Ready.Answer)
+	}
+	if got := severities(w); len(got) != 1 || got[0] != "urgent" {
+		t.Fatalf("severity %v after an out of date refusal that followed an urgent one; wanted urgent", got)
+	}
+}

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

@@ -62,6 +62,9 @@ type ReadyRun struct {
 	// OwnAskedAt is when its own check was asked after the merge tool refused it for a pending status of its own (issue
 	// 1049): once for the head this run is for.
 	OwnAskedAt time.Time `json:"own_asked_at,omitempty"`
+	// Urgent is set once a refusal of this head was one that is urgent at once: its severity never steps down to a
+	// warning after (issue 1275, AC6).
+	Urgent bool `json:"urgent,omitempty"`
 	// RefusedSince is when the merge tool began refusing it without a break.
 	RefusedSince *time.Time `json:"refused_since,omitempty"`
 	// Merged is when the merge tool merged it.
@@ -376,6 +379,9 @@ func (h *Holder) mergeOne(id string, heads map[string]string) bool {
 	if r.RefusedSince == nil {
 		r.RefusedSince = &now
 	}
+	if !outOfDateRefusal(answer) {
+		r.Urgent = true // never a warning again for this head
+	}
 	if answer != r.Answer {
 		h.Logf("[mesh-delivery] %s is approved, and the merge tool did not merge it (asked again at the next verdict, Approve or composed check): %s", id,
 			answer)
@@ -432,7 +438,7 @@ func (h *Holder) readyLines(now time.Time) []StalledLine {
 			out = append(out, StalledLine{ID: d.ID, Number: d.Number, State: d.State,
 				For: now.Sub(*r.RefusedSince).Round(time.Second).String(), Bound: groupRefusedFor.String(),
 				H2:       "none: the group's composed check is asked again after each refusal, and the merge each minute — the operator's",
-				Severity: "urgent",
+				Severity: refusalSeverity(r, now),
 				Says: fmt.Sprintf("group %s is half merged: %s#%d is approved at %s and the merge tool has refused it since %s: %s. "+
 					"Needed: the refusal's cause is met (the merge is asked again at each verdict, status or Approve), or the operator decides.",
 					d.Group, d.Repository, d.Number, shortOf(r.Head, 12), r.RefusedSince.UTC().Format(time.RFC3339), r.Answer)})
@@ -443,7 +449,7 @@ func (h *Holder) readyLines(now time.Time) []StalledLine {
 					"status turning success — the operator's",
 				Says: fmt.Sprintf("%s%s#%d is approved at %s, and the merge tool has refused it since %s: %s%s", heldInGroup(d),
 					d.Repository, d.Number, shortOf(r.Head, 12), r.RefusedSince.UTC().Format(time.RFC3339), r.Answer, neededOf(d)),
-				Severity: severityOf(d)})
+				Severity: severityOf(d, now)})
 		}
 	}
 	return out
@@ -482,10 +488,41 @@ func neededOf(d *Delivery) string {
 	return ". Needed: the refusal's cause is met (the merge is asked again at each verdict, status or Approve), or the operator decides."
 }
 
-// severityOf is "urgent" for a member of a group (a refused merge is the group held), empty for a lone delivery.
-func severityOf(d *Delivery) string {
-	if d.Group == "" {
-		return ""
+// outOfDateFor is how long a refusal for an out of date verdict is a warning before it is urgent (issue 1275, AC6).
+const outOfDateFor = 10 * time.Minute
+
+// outOfDateRefusal is whether the merge tool refused because the member's verdict is judged against an earlier trunk: the
+// forge's "its verdict was judged against trunk <t>, and main is now <t>. The check of head <h> merged into trunk <t> was
+// asked" (gitea merge.ts), whose fresh check is already running.
+//
+// Words that also name another cause (a status not a success, missing or failed) are not this: the other cause is urgent
+// at once (ADR 0442, issue 1275 AC6).
+func outOfDateRefusal(answer string) bool {
+	for _, other := range []string{"not a success", "(missing)", "(failure)", "(error)", "could not be asked"} {
+		if strings.Contains(answer, other) {
+			return false
+		}
+	}
+	// gitea merge.ts: "Its check is already asked and not yet answered" (on its way), or "The check of head <h> merged into
+	// trunk <t> was asked" (asked now). Its other refusals, among them "its check could not be asked", are not this.
+	return strings.Contains(answer, "its verdict ") && strings.Contains(answer, " is now ") &&
+		(strings.Contains(answer, "Its check is already asked and not yet answered") ||
+			strings.Contains(answer, "merged into trunk") && strings.Contains(answer, "was asked"))
+}
+
+// refusalSeverity is "warning" while a member's refusal for an out of date verdict is younger than ten minutes, as its
+// fresh check runs, and "urgent" for it after that and for every other refusal at once.
+func refusalSeverity(r *ReadyRun, now time.Time) string {
+	if !r.Urgent && r.RefusedSince != nil && outOfDateRefusal(r.Answer) && now.Sub(*r.RefusedSince) < outOfDateFor {
+		return "warning"
 	}
 	return "urgent"
 }
+
+// severityOf is the severity of a refused member of a group, empty for a lone delivery.
+func severityOf(d *Delivery, now time.Time) string {
+	if d.Group == "" {
+		return ""
+	}
+	return refusalSeverity(d.Ready, now)
+}