From ade6a2828134a6e39c1d72706a4d0ea4b25c0b95 Mon Sep 17 00:00:00 2001 From: jochen Date: Fri, 30 Oct 2026 12:04:29 +0100 Subject: [PATCH] Checker: a check judging its step's end is judging, not lost, so checker_ask_again no longer ends a check about to pass (issue 1721) mesh-catalog #562's step passed on shanks at 10:52:16Z and its end was heard at 10:52:17Z (its own watch was deaf; HeardEnds read it at the nudge of that same step end). The checker was judging it (kept verdicts, composition) when checker_status, reading only the steps state, named it lost: no step runs and the newest one ended. checker_ask_again, called on that at 10:52:27Z, ended the judging (context canceled) and the check ran whole again, passing at 11:00:16Z. No step end was lost; the read tools could not tell judging from lost. The running check now writes, in its state asks (already its own, by verdict key), the step whose end it heard and judges, and since when; its next ask or its end clears it. checker_status names such a candidate under judging, not lost, and checker_ask_again refuses it. A judging older than the step bound counts as lost (the checker that heard it stopped). State on the bus, written on the step-end event; no timer. Quick fix: a grace time after a step's end in lostWhy. Thorough fix (chosen): the checker says on the bus what it judges, so the read side never guesses; a grace would misname any judging longer than it (a composition wait). Test: a row in TestACheckWhoseAskJudgedNothingIsAskedAgainOrRead holds the composition and reads status and ask-again while the step's end is judged; without the fix it names the check lost and the ask again fails it. --- .../cmd/mesh-delivery-checker-tools/main.go | 8 ++-- .../internal/check/askagain.go | 25 +++++++++-- .../internal/check/checker.go | 7 ++- .../internal/check/composition_test.go | 13 +++++- .../internal/check/lostask_test.go | 25 +++++++++++ .../internal/check/read.go | 45 ++++++++++++++++++- 6 files changed, 111 insertions(+), 12 deletions(-) diff --git a/modules/mesh-delivery-checker/cmd/mesh-delivery-checker-tools/main.go b/modules/mesh-delivery-checker/cmd/mesh-delivery-checker-tools/main.go index 660b6d5..afc3e1a 100644 --- a/modules/mesh-delivery-checker/cmd/mesh-delivery-checker-tools/main.go +++ b/modules/mesh-delivery-checker/cmd/mesh-delivery-checker-tools/main.go @@ -229,7 +229,8 @@ func Tools(r check.Reader) []stdio.Tool { "build seats' streams, whose backlog the delivery view shows (novox/hq ADR 0525). held_by_turn names the candidates whose check an approved " + "merge's turn holds off (novox/hq ADR 0548 ยง3), with the repository and the merge that waits; the gate's turns tool reads every turn and its " + "hand-now tool steers one. dead_letters says whether the checker hears the asks the build seats give up on (issue 734), and why not: " + - "deaf, a try or check whose ask is given up waits until its bound. Read-only.", + "deaf, a try or check whose ask is given up waits until its bound. judging names the candidates whose newest step ended and whose end " + + "the checker judges now (levels, kept verdicts, composition): their verdict follows by itself; lost names those nothing will judge. Read-only.", Input: map[string]any{"type": "object", "properties": map[string]any{}}, Run: func(map[string]any) (any, error) { return r.Status() }}, } @@ -243,8 +244,9 @@ func RecoveryTools(r check.Reader, w check.VerdictEntry) []stdio.Tool { Description: "Ask a candidate's check again by hand, whose verdict stays running while nothing runs for it (" + check.StatusReadTool + " names it " + "under lost): its verdict is ended as asked again, saying why, and the checker, which hears its verdicts, stops the wait that judged nothing " + "and asks the check anew, whole. Refused for a group with no candidate, a verdict that is not running (a pass or failure stands until a push or " + - "a trunk move), and while a step of its pull requests can still run on a build module (its end judges it). The checker reads a step that " + - "ended while its watch was deaf by itself at the next step end of its build module; this is for what that does not reach.", + "a trunk move), while a step of its pull requests can still run on a build module (its end judges it), and while the checker judges the end " + + "of its newest step (" + check.StatusReadTool + " names it under judging: its verdict follows). The checker reads a step that ended while " + + "its own watch was deaf by itself at the next step end of any step of its build module; this is for what that does not reach.", Input: map[string]any{"type": "object", "required": []string{"group", "why"}, "properties": map[string]any{ "group": map[string]any{"type": "string", "description": "the delivery group's branch name"}, "why": map[string]any{"type": "string", "description": "why it is asked again, in words; kept in the verdict it ends"}}}, diff --git a/modules/mesh-delivery-checker/internal/check/askagain.go b/modules/mesh-delivery-checker/internal/check/askagain.go index 7540bbe..0140a53 100644 --- a/modules/mesh-delivery-checker/internal/check/askagain.go +++ b/modules/mesh-delivery-checker/internal/check/askagain.go @@ -6,6 +6,7 @@ import ( "errors" "fmt" "strings" + "time" "git.novox.be/novox/mesh-sdk/go/delivery" ) @@ -29,6 +30,18 @@ const ( // CheckAsks are the asks a check put, in order, as the state asks keeps them while it runs; its end deletes the key. type CheckAsks struct { Asks []string `json:"asks"` + // Judging names the step whose end the check heard and judges now (its levels, kept verdicts, the composition), until + // its next ask or its verdict: between a step's end and its verdict no step of the check runs, and without it the read + // tools took that judging for a check nothing will judge (issue 1721: mesh-catalog #562 was named lost ten seconds + // after its step passed, and checker_ask_again ended the judging that would have passed it). Nil while an ask waits. + Judging *Judging `json:"judging,omitempty"` +} + +// Judging is the step whose end a running check heard and judges now, and since when. +type Judging struct { + Step string `json:"step"` + Node string `json:"node"` + Since time.Time `json:"since"` } // AsksKV is the state asks: a KV whose key a check's end deletes, so the state holds only the checks that run. @@ -45,13 +58,14 @@ func (ch *Checker) forgetAsks(ctx context.Context, key string) { } } -// recordAsks keeps the asks a check put under its verdict key; nil Asks keeps nothing. A record that cannot be written -// is said: checker_ask_again then refuses the check, as it cannot tell whether its ask waits in a stream. -func (ch *Checker) recordAsks(ctx context.Context, key string, asks []string) { +// recordAsks keeps the asks a check put under its verdict key, with the step whose end it judges now (nil while an ask +// waits); nil Asks keeps nothing. A record that cannot be written is said: checker_ask_again then refuses the check, as it +// cannot tell whether its ask waits in a stream. +func (ch *Checker) recordAsks(ctx context.Context, key string, asks []string, judging *Judging) { if ch.Asks == nil { return } - data, err := json.Marshal(CheckAsks{Asks: asks}) + data, err := json.Marshal(CheckAsks{Asks: asks, Judging: judging}) if err == nil { _, err = putOnce(ctx, ch.Asks, key, data, func(cur []byte) bool { return string(cur) == string(data) }) } @@ -139,6 +153,9 @@ func (r Reader) AskAgain(w VerdictEntry, group, why string) (AskedAgain, error) if err != nil || len(put.Asks) == 0 { return AskedAgain{}, fmt.Errorf("the checker names no ask of %s (%v), so whether one waits in a build seat's stream cannot be told; asking again could run it twice", key, err) } + if why := r.judgingWhy(put.Judging); why != "" { + return AskedAgain{}, fmt.Errorf("%s: asking again would end that judging and run the check twice", why) + } taken := map[string]bool{} for _, s := range steps.all { taken[s.step.ID] = true diff --git a/modules/mesh-delivery-checker/internal/check/checker.go b/modules/mesh-delivery-checker/internal/check/checker.go index 2456ab9..2723245 100644 --- a/modules/mesh-delivery-checker/internal/check/checker.go +++ b/modules/mesh-delivery-checker/internal/check/checker.go @@ -749,8 +749,11 @@ func (ch *Checker) try(ctx, run context.Context, key string, cs *Case) { began := ch.now() if cs.Watch == nil && ch.Asks != nil { cs.Watch = func(_ string, step *delivery.Step) { - if step == nil { // put: kept before its wait starts - ch.recordAsks(ctx, cs.Key, cs.Asks()) + switch { + case step == nil: // put: kept before its wait starts + ch.recordAsks(ctx, cs.Key, cs.Asks(), nil) + case step.State != delivery.StepRunning: // its end, heard: judged from now until the next ask or the verdict + ch.recordAsks(ctx, cs.Key, cs.Asks(), &Judging{Step: step.ID, Node: step.Node, Since: ch.now().UTC()}) } } defer ch.forgetAsks(ctx, cs.Key) diff --git a/modules/mesh-delivery-checker/internal/check/composition_test.go b/modules/mesh-delivery-checker/internal/check/composition_test.go index 9320456..5a32d6a 100644 --- a/modules/mesh-delivery-checker/internal/check/composition_test.go +++ b/modules/mesh-delivery-checker/internal/check/composition_test.go @@ -14,10 +14,21 @@ type fakeCompositions struct { v delivery.CompositionVerdict err error asked []string + // hold, when set, is handed a value when Await is entered and holds it until it is handed one back: a check judging + // its step's end, its verdict not written yet. + hold chan struct{} } -func (f *fakeCompositions) Await(_ context.Context, key string) (delivery.CompositionVerdict, error) { +func (f *fakeCompositions) Await(ctx context.Context, key string) (delivery.CompositionVerdict, error) { f.asked = append(f.asked, key) + if f.hold != nil { + f.hold <- struct{}{} + select { + case <-f.hold: + case <-ctx.Done(): + return delivery.CompositionVerdict{}, ctx.Err() + } + } return f.v, f.err } diff --git a/modules/mesh-delivery-checker/internal/check/lostask_test.go b/modules/mesh-delivery-checker/internal/check/lostask_test.go index ddf4d33..ccea423 100644 --- a/modules/mesh-delivery-checker/internal/check/lostask_test.go +++ b/modules/mesh-delivery-checker/internal/check/lostask_test.go @@ -266,6 +266,8 @@ func TestACheckWhoseAskJudgedNothingIsAskedAgainOrRead(t *testing.T) { {name: "its watch deaf, a step of its build module ends", deaf: 1, how: "nudge", state: delivery.VerdictPass, asks: 1}, {name: "its watch deaf, asked again by hand", deaf: 1, how: "hand", state: delivery.VerdictPass, asks: 2}, {name: "its watch deaf, asked again by hand after its build module replaced it", deaf: 1, restarts: 1, how: "hand", state: delivery.VerdictPass, asks: 2}, + // issue 1721: mesh-catalog #562 was named lost while the checker judged its step's end, and asked again by hand + {name: "its step's end heard and being judged", how: "judging", state: delivery.VerdictPass, asks: 1}, } { t.Run(row.name, func(t *testing.T) { b := newBench(t) @@ -282,6 +284,11 @@ func TestACheckWhoseAskJudgedNothingIsAskedAgainOrRead(t *testing.T) { b.ex.Asks = buildrun.Asker{Publisher: tr, Waiter: heard, Bound: 5 * time.Second} asked = func() int { return len(tr.Asks()) } } + var held *fakeCompositions + if row.how == "judging" { + held = &fakeCompositions{err: ErrAssignerNotRunning, hold: make(chan struct{})} + b.ex.Compositions = held + } r := newRig(t, b.ex) asksKept := newMemKV() r.ch.Asks = asksKept @@ -297,6 +304,24 @@ func TestACheckWhoseAskJudgedNothingIsAskedAgainOrRead(t *testing.T) { } } switch row.how { + case "judging": + select { + case <-held.hold: // its step ended and was heard: the checker judges it, its verdict not written yet + case <-time.After(5 * time.Second): + t.Fatal("the check never came to judge its step's end") + } + cands := newMemKV() + ckey, _ := delivery.CandidatesKey("feat/x") + _, _ = cands.Create(ctx, ckey, cand) + rd := Reader{CandidateState: kvRead(cands), VerdictState: kvRead(r.verdicts), AskState: kvRead(asksKept), + StepStates: map[string]StateRead{buildrun.GoBuildModule: tr.Steps(false)}} + if st, _ := rd.Status(); st.Lost["feat/x"] != "" || !strings.Contains(st.Judging["feat/x"], "judges the end of its step") { + t.Errorf("status while its step's end is judged: lost %v, judging %v; want judging, not lost", st.Lost, st.Judging) + } + if _, err := rd.AskAgain(asVerdicts{r.verdicts}, "feat/x", "named lost"); err == nil || !strings.Contains(err.Error(), "judges the end of its step") { + t.Errorf("asked again while its step's end is judged: %v", err) + } + held.hold <- struct{}{} case "nudge": heard.Nudge(buildrun.NodeBuildModule) // another build module's step: not this one's to read heard.Nudge(buildrun.GoBuildModule) diff --git a/modules/mesh-delivery-checker/internal/check/read.go b/modules/mesh-delivery-checker/internal/check/read.go index 4d22745..daa4513 100644 --- a/modules/mesh-delivery-checker/internal/check/read.go +++ b/modules/mesh-delivery-checker/internal/check/read.go @@ -338,6 +338,10 @@ type Status struct { // Lost are the candidates whose verdict is running while no step of theirs can still run and their newest step ended, by // group, with that step: nothing will judge them (the lost check of 2026-10-28); checker_ask_again asks one again. Lost map[string]string `json:"lost"` + // Judging are the candidates whose verdict is running while the checker judges the end of their newest step (its + // levels, kept verdicts, the composition), by group, with that step and since when: their verdict follows by itself, + // and checker_ask_again refuses them (issue 1721). + Judging map[string]string `json:"judging"` // DeadLetters says whether the checker hears the asks the build seats give up on (issue 734): deaf, a try or check // whose ask is given up waits until its bound. DeadLetters DeadLettersHeard `json:"dead_letters"` @@ -401,7 +405,7 @@ func heldBy(t *Turns, c delivery.Candidate, heads map[string]string) string { // Status reads the build modules' steps and the candidates against their verdicts. func (r Reader) Status() (Status, error) { - st := Status{RunningByNode: map[string]int{}, Lost: map[string]string{}} + st := Status{RunningByNode: map[string]int{}, Lost: map[string]string{}, Judging: map[string]string{}} read := r.readSteps() st.Running, st.LeftRunning, st.Notes = read.running, read.left, read.notes for _, rs := range st.Running { @@ -487,7 +491,9 @@ func (r Reader) Status() (Status, error) { switch { case err != nil: case v.State == delivery.VerdictRunning: - if why := read.lostWhy(c); why != "" { + if judging := r.judgingWhy(r.judgingOf(c)); judging != "" { + st.Judging[c.Group] = judging + } else if why := read.lostWhy(c); why != "" { st.Lost[c.Group] = why } case IsNodesFailure(v): @@ -622,6 +628,41 @@ func (s stepsRead) lostWhy(c delivery.Candidate) string { last.ID, last.Node, last.State, last.Ended.UTC().Format(time.RFC3339), AskAgainTool) } +// judgingOf is the step whose end the candidate's running check judges now, as the checker's state asks keeps it; nil +// for none, or when the state cannot be read. +func (r Reader) judgingOf(c delivery.Candidate) *Judging { + key, err := delivery.CheckerVerdictKey(c.Group, c.HeadsHash) + if err != nil || r.AskState.Get == nil { + return nil + } + raw, err := r.AskState.Get(key) + var put CheckAsks + if err != nil || len(raw) == 0 || json.Unmarshal(raw, &put) != nil { + return nil + } + return put.Judging +} + +// judgingWhy says that the checker judges a step's end now, or "" for none: a judging older than the step bound is not +// counted, as the checker that heard that end stopped before its verdict (one that starts again takes the check anew and +// writes its asks again), so the check is lost. +func (r Reader) judgingWhy(j *Judging) string { + if j == nil { + return "" + } + now, bound := time.Now(), r.StepBound + if r.Now != nil { + now = r.Now() + } + if bound <= 0 { + bound = DefaultStepBound + } + if now.Sub(j.Since) > bound { + return "" + } + return fmt.Sprintf("the checker judges the end of its step %s on %s since %s; its verdict follows", j.Step, j.Node, j.Since.UTC().Format(time.RFC3339)) +} + // DefaultStepBound is how long one check ask's step may run once a build node took it (its key written running; the fetch, // the digests and the levels), never counting its wait in the stream; past it the check fails naming the node. const DefaultStepBound = 30 * time.Minute