jschoubben
f73b0bf6f6
The check of 2026-11-02 22:35 on a loaded shanks failed two buildrun tests on wall-clock bounds of 60 ms, the second failure of this kind tonight (the first: mesh-sdk's busretry tests, f02f142). Quick fix: give the two buildrun asker tests bounds of seconds. Thorough fix (chosen, because the kind recurs across every module of the repository): every test that raced a wall clock now waits on an event, steps a clock it is given, or has a bound only a failing test reaches. - buildrun asker tests: the steps' own times stand for the clock (bound an hour, starts and phases written in the past), no goroutine paces phases with sleeps. - builder: the decline bound reads Builder.Now; the decline test steps it; the stream-wait test waits for five check reads instead of 100 ms. - checker: the lost-ask try bounds an untaken ask at 200 ms only where that is what ends it; the program says when a merge turn changes, and the integration test waits on that line instead of 300 ms. - teller: the bed makes the teller's own ends bucket (a 10 s stall at start the tests raced by 0.5 s), waits for its warrant subscription instead of 500 ms pauses, and the package-level now is restored with t.Cleanup. - watchman: the recount, run in its own goroutine, is waited for instead of 10 ms. - polls of 2-5 s become 10 s (unit) and 20 s (integration). Under a throttled cgroup (half a core shared with two busy loops) beside the node-engine's suite, the buildrun tests failed 5 of 20 runs before and passed 30 of 30 after; no test added. Claude-Session: https://claude.ai/code/session_01NcbgfJ9Gum47zkFKWRaovL
351 lines
14 KiB
Go
351 lines
14 KiB
Go
package check
|
|
|
|
import (
|
|
"context"
|
|
"encoding/json"
|
|
"strings"
|
|
"sync"
|
|
"testing"
|
|
"time"
|
|
|
|
"git.novox.be/novox/mesh-delivery/modules/mesh-delivery-builder/buildrun"
|
|
"git.novox.be/novox/mesh-sdk/go/buildstep"
|
|
"git.novox.be/novox/mesh-sdk/go/delivery"
|
|
)
|
|
|
|
// losingAsks is the build seat over a bus that gives up the first `lose` asks put (DEAD_LETTERS keeps them, as on
|
|
// 2026-10-26 during a bus reload: try-1793017340003993788) and answers the rest; with never set it neither answers nor
|
|
// gives up (an ask no node takes).
|
|
type losingAsks struct {
|
|
*buildrun.FakeAsks
|
|
answer func(delivery.StepAsk) delivery.Step
|
|
dead *buildrun.DeadLetters
|
|
never bool
|
|
|
|
mu sync.Mutex
|
|
lose int
|
|
}
|
|
|
|
func (l *losingAsks) PublishAsk(ctx context.Context, subject, id string, data []byte) error {
|
|
if err := l.FakeAsks.PublishAsk(ctx, subject, id, data); err != nil {
|
|
return err
|
|
}
|
|
l.mu.Lock()
|
|
lost := l.lose > 0
|
|
if lost {
|
|
l.lose--
|
|
}
|
|
l.mu.Unlock()
|
|
switch {
|
|
case l.never:
|
|
case lost:
|
|
h := map[string][]string{buildrun.DeadHeaderMsgID: {id}, buildrun.DeadHeaderDeliveries: {"5"}, buildrun.DeadHeaderStream: {"SEAT_NODE_BUILD_GO"},
|
|
buildrun.DeadHeaderGaveUp: {"2026-10-26T12:26:40Z"}}
|
|
g, ok := buildrun.GivenUpOf(h)
|
|
if !ok {
|
|
return nil
|
|
}
|
|
go l.dead.Heard(g)
|
|
default:
|
|
a, err := delivery.DecodeStepAsk(data)
|
|
if err != nil {
|
|
return err
|
|
}
|
|
l.Write(l.answer(a))
|
|
}
|
|
return nil
|
|
}
|
|
|
|
func losing(b *bench, lose int) *losingAsks {
|
|
l := &losingAsks{FakeAsks: &buildrun.FakeAsks{}, answer: b.answer, dead: &buildrun.DeadLetters{}, lose: lose}
|
|
b.ex.Asks = buildrun.Asker{Publisher: l, Waiter: buildrun.LostAskWaiter{Inner: l.FakeAsks, Dead: l.dead}, Bound: 5 * time.Second}
|
|
return l
|
|
}
|
|
|
|
// endable is the tries state as the end tool sees it.
|
|
type endable struct{ kv *memKV }
|
|
|
|
func (e endable) Entry(key string) (json.RawMessage, uint64, error) {
|
|
v, rev, _, err := e.kv.Get(context.Background(), key)
|
|
return v, rev, err
|
|
}
|
|
func (e endable) Update(key string, value []byte, revision uint64) error {
|
|
_, err := e.kv.Update(context.Background(), key, value, revision)
|
|
return err
|
|
}
|
|
|
|
// Issue 734: a try whose ask the build seat gave up on ends as error saying so, and the next ask of its head is a new try;
|
|
// one no node takes ends at the step bound; one ended by hand frees its place and stops being waited for.
|
|
func TestAnAskGivenUpOrNeverTakenEndsItsTryAsErrorAndItsHeadIsAskedAnew(t *testing.T) {
|
|
ctx := context.Background()
|
|
for _, row := range []struct {
|
|
name string
|
|
lose int
|
|
never bool
|
|
// notTaken is the try's bound on an ask no node takes: short only where it is what ends the try, an hour where the
|
|
// dead letter must (a loaded machine let 200 ms pass before the dead letter was heard).
|
|
notTaken time.Duration
|
|
want string
|
|
}{
|
|
{"given up by the build seat", 1, false, time.Hour, buildrun.LostWords + " after 5 deliveries at 2026-10-26T12:26:40Z"},
|
|
{"taken by no build node within the bound", 0, true, 200 * time.Millisecond, buildrun.NotTakenWords + " within 200ms"},
|
|
} {
|
|
t.Run(row.name, func(t *testing.T) {
|
|
kv := newMemKV()
|
|
at := time.Date(2026, 10, 26, 12, 22, 20, 0, time.UTC)
|
|
id, err := AskTry(memTries{kv}, tryTrunks, TryAsk{Repository: repoA, Head: head1}, at)
|
|
if err != nil {
|
|
t.Fatal(err)
|
|
}
|
|
b := newBench(t)
|
|
l := losing(b, row.lose)
|
|
l.never = row.never
|
|
tr := &Tryer{Tries: kv, Judge: b.ex, NotTaken: row.notTaken}
|
|
raw, _, _, _ := kv.Get(ctx, id)
|
|
tr.Put(ctx, id, raw)
|
|
tr.Wait()
|
|
got := readTry(t, kv, id)
|
|
if got.State != TryError || len(got.Failed) != 1 || !strings.Contains(got.Failed[0], row.want) || !strings.Contains(got.Said, row.want) {
|
|
t.Fatalf("try = %+v, want error saying %q", got, row.want)
|
|
}
|
|
again, err := AskTry(memTries{kv}, tryTrunks, TryAsk{Repository: repoA, Head: head1}, at.Add(time.Minute))
|
|
if err != nil || again == id {
|
|
t.Errorf("the head asked again answered %q, %v, want a new try", again, err)
|
|
}
|
|
})
|
|
}
|
|
t.Run("ended by hand", func(t *testing.T) {
|
|
kv := newMemKV()
|
|
id, _ := AskTry(memTries{kv}, tryTrunks, TryAsk{Repository: repoA, Head: head1}, time.Now())
|
|
b := newBench(t)
|
|
losing(b, 0).never = true
|
|
tr := &Tryer{Tries: kv, Judge: b.ex} // no bound: only the hand ends it
|
|
raw, _, _, _ := kv.Get(ctx, id)
|
|
tr.Put(ctx, id, raw)
|
|
deadline := time.Now().Add(10 * time.Second)
|
|
for readTry(t, kv, id).State != TryRunning && time.Now().Before(deadline) {
|
|
time.Sleep(5 * time.Millisecond)
|
|
}
|
|
if _, err := EndTry(endable{kv}, id, "", time.Now()); err == nil {
|
|
t.Error("an end without a why was taken")
|
|
}
|
|
ended, err := EndTry(endable{kv}, id, "its ask was lost in the bus reload", time.Now())
|
|
if err != nil || ended.State != TryError || !strings.HasPrefix(ended.Said, "ended by hand ("+TryEndTool+"): its ask was lost") {
|
|
t.Fatalf("ended = %+v, %v", ended, err)
|
|
}
|
|
raw, _, _, _ = kv.Get(ctx, id)
|
|
tr.Put(ctx, id, raw) // the watch of the tries hands the end over
|
|
tr.Wait() // returns: the try's judging stopped
|
|
if got := readTry(t, kv, id); got.State != TryError || got.Said != ended.Said {
|
|
t.Errorf("try = %+v, want the hand's end kept", got)
|
|
}
|
|
if _, err := EndTry(endable{kv}, id, "again", time.Now()); err == nil || !strings.Contains(err.Error(), "ended already") {
|
|
t.Errorf("a second end answered %v", err)
|
|
}
|
|
})
|
|
}
|
|
|
|
// troubled is the build seat as a check meets it when its step's end does not reach its wait: the first `restarts` asks'
|
|
// steps are ended by the build module's next process (buildstep.RestartReason), and the first `deaf` asks' watches hear
|
|
// nothing though their steps end (the lost check of 2026-10-28). Its steps state is read through AskSteps and Steps.
|
|
type troubled struct {
|
|
*buildrun.FakeAsks
|
|
answer func(delivery.StepAsk) delivery.Step
|
|
|
|
mu sync.Mutex
|
|
restarts, deaf int
|
|
deafIDs map[string]bool
|
|
steps map[string]delivery.Step
|
|
}
|
|
|
|
func (tr *troubled) PublishAsk(ctx context.Context, subject, id string, data []byte) error {
|
|
if err := tr.FakeAsks.PublishAsk(ctx, subject, id, data); err != nil {
|
|
return err
|
|
}
|
|
a, err := delivery.DecodeStepAsk(data)
|
|
if err != nil {
|
|
return err
|
|
}
|
|
step := tr.answer(a)
|
|
step.What = buildstep.AskWhat(a)
|
|
tr.mu.Lock()
|
|
if tr.restarts > 0 {
|
|
tr.restarts--
|
|
step.State, step.Reason, step.Result = delivery.StepFailed, buildstep.RestartReason, nil
|
|
}
|
|
deaf := tr.deaf > 0
|
|
if deaf {
|
|
tr.deaf--
|
|
tr.deafIDs[id] = true
|
|
}
|
|
tr.steps[id] = step
|
|
tr.mu.Unlock()
|
|
if !deaf {
|
|
tr.Write(step)
|
|
}
|
|
return nil
|
|
}
|
|
|
|
func (tr *troubled) WatchAsk(ctx context.Context, module, askID string) (<-chan delivery.Step, error) {
|
|
tr.mu.Lock()
|
|
deaf := tr.deafIDs[askID]
|
|
tr.mu.Unlock()
|
|
if deaf {
|
|
return make(chan delivery.Step), nil // open, and silent for good
|
|
}
|
|
return tr.FakeAsks.WatchAsk(ctx, module, askID)
|
|
}
|
|
|
|
func (tr *troubled) AskSteps(_ context.Context, _, askID string) ([]delivery.Step, error) {
|
|
tr.mu.Lock()
|
|
defer tr.mu.Unlock()
|
|
if s, ok := tr.steps[askID]; ok {
|
|
return []delivery.Step{s}, nil
|
|
}
|
|
return nil, nil
|
|
}
|
|
|
|
// Steps is the steps state as the read tools read it, with running in place of every step the hand has not let end.
|
|
func (tr *troubled) Steps(running bool) StateRead {
|
|
tr.mu.Lock()
|
|
defer tr.mu.Unlock()
|
|
vals := map[string]json.RawMessage{}
|
|
for id, s := range tr.steps {
|
|
if running {
|
|
s.State, s.Ended, s.Started = delivery.StepRunning, time.Time{}, time.Now()
|
|
}
|
|
raw, _ := delivery.EncodeStep(s)
|
|
vals[s.Node+"."+id] = raw
|
|
}
|
|
return StateRead{Keys: func() ([]string, error) {
|
|
var out []string
|
|
for k := range vals {
|
|
out = append(out, k)
|
|
}
|
|
return out, nil
|
|
}, Get: func(k string) (json.RawMessage, error) { return vals[k], nil }}
|
|
}
|
|
|
|
// kvRead is a bucket in memory as the read tools read it, live.
|
|
func kvRead(kv *memKV) StateRead {
|
|
return StateRead{Keys: func() ([]string, error) { return kv.Keys(context.Background()) },
|
|
Get: func(k string) (json.RawMessage, error) {
|
|
v, _, _, err := kv.Get(context.Background(), k)
|
|
return v, err
|
|
}}
|
|
}
|
|
|
|
// asVerdicts is the rig's verdicts as the ask-again tool reads and writes them.
|
|
type asVerdicts struct{ kv *memKV }
|
|
|
|
func (a asVerdicts) Entry(key string) (json.RawMessage, uint64, error) {
|
|
v, rev, _, err := a.kv.Get(context.Background(), key)
|
|
return v, rev, err
|
|
}
|
|
func (a asVerdicts) Update(key string, value []byte, revision uint64) error {
|
|
_, err := a.kv.Update(context.Background(), key, value, revision)
|
|
return err
|
|
}
|
|
|
|
// Issue 734 and the lost check of 2026-10-28: a check whose ask judged nothing is asked again, and one whose step ended
|
|
// unheard is judged. Given up by the build seat once, or its step ended by the build module's next process after a
|
|
// delivery replaced it, the check is asked again under its claim and passes; given up every time it fails loudly as not
|
|
// heard, judged again when the nodes change. A step whose watch went deaf is read at the next step end of its build module
|
|
// (a nudge) and judged with no new ask; one no event reaches is named lost by checker_status, refused by checker_ask_again
|
|
// while its step still runs, and asked again by it once its step ended.
|
|
func TestACheckWhoseAskJudgedNothingIsAskedAgainOrRead(t *testing.T) {
|
|
ctx := context.Background()
|
|
for _, row := range []struct {
|
|
name string
|
|
lose, restarts, deaf int
|
|
how string // "nudge": a step of the build module ends; "hand": checker_ask_again
|
|
state string
|
|
asks int
|
|
}{
|
|
{name: "given up once", lose: 1, state: delivery.VerdictPass, asks: 2},
|
|
{name: "given up every time", lose: LostAskTries, state: delivery.VerdictFail, asks: LostAskTries},
|
|
{name: "its build module replaced under it", restarts: 1, state: delivery.VerdictPass, asks: 2},
|
|
{name: "replaced under every ask", restarts: LostAskTries, state: delivery.VerdictFail, asks: LostAskTries},
|
|
{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},
|
|
} {
|
|
t.Run(row.name, func(t *testing.T) {
|
|
b := newBench(t)
|
|
var asked func() int
|
|
var heard *buildrun.HeardEnds
|
|
var tr *troubled
|
|
if row.lose > 0 {
|
|
l := losing(b, row.lose)
|
|
asked = func() int { return len(l.Asks()) }
|
|
} else {
|
|
tr = &troubled{FakeAsks: &buildrun.FakeAsks{}, answer: b.answer, restarts: row.restarts, deaf: row.deaf,
|
|
deafIDs: map[string]bool{}, steps: map[string]delivery.Step{}}
|
|
heard = &buildrun.HeardEnds{Inner: tr, Read: tr}
|
|
b.ex.Asks = buildrun.Asker{Publisher: tr, Waiter: heard, Bound: 5 * time.Second}
|
|
asked = func() int { return len(tr.Asks()) }
|
|
}
|
|
r := newRig(t, b.ex)
|
|
asksKept := newMemKV()
|
|
r.ch.Asks = asksKept
|
|
cand := candidateOf(t, "feat/x", pullOf(repoA, 7, head1))
|
|
key := keyOf(t, "feat/x", cand)
|
|
r.ch.Candidate(ctx, "feat%2Fx", cand)
|
|
if row.deaf > 0 {
|
|
for deadline := time.Now().Add(10 * time.Second); heard.Waiting() == 0 && time.Now().Before(deadline); {
|
|
time.Sleep(2 * time.Millisecond)
|
|
}
|
|
if v := r.verdict(t, key); v.State != delivery.VerdictRunning {
|
|
t.Fatalf("a check whose step ended unheard = %s, want running until it is read", v.State)
|
|
}
|
|
}
|
|
switch row.how {
|
|
case "nudge":
|
|
heard.Nudge(buildrun.NodeBuildModule) // another build module's step: not this one's to read
|
|
heard.Nudge(buildrun.GoBuildModule)
|
|
case "hand":
|
|
cands := newMemKV()
|
|
ckey, _ := delivery.CandidatesKey("feat/x")
|
|
_, _ = cands.Create(ctx, ckey, cand)
|
|
none := StateRead{Keys: func() ([]string, error) { return nil, nil }, Get: func(string) (json.RawMessage, error) { return nil, nil }}
|
|
rd := Reader{CandidateState: kvRead(cands), VerdictState: kvRead(r.verdicts), AskState: kvRead(asksKept),
|
|
StepStates: map[string]StateRead{buildrun.GoBuildModule: none}} // no node took its ask yet
|
|
if _, err := rd.AskAgain(asVerdicts{r.verdicts}, "feat/x", "its watch went deaf"); err == nil || !strings.Contains(err.Error(), "waits in its build seat's stream") {
|
|
t.Errorf("asked again while its ask waits in the stream (issue 1791's kind): %v", err)
|
|
}
|
|
rd.StepStates[buildrun.GoBuildModule] = tr.Steps(true)
|
|
if _, err := rd.AskAgain(asVerdicts{r.verdicts}, "feat/x", "its watch went deaf"); err == nil || !strings.Contains(err.Error(), "a step of it runs") {
|
|
t.Errorf("asked again while its step runs: %v", err)
|
|
}
|
|
rd.StepStates[buildrun.GoBuildModule] = tr.Steps(false)
|
|
if st, _ := rd.Status(); !strings.Contains(st.Lost["feat/x"], AskAgainTool) {
|
|
t.Errorf("status lost = %v, want feat/x named with %s", st.Lost, AskAgainTool)
|
|
}
|
|
got, err := rd.AskAgain(asVerdicts{r.verdicts}, "feat/x", "its watch went deaf")
|
|
if err != nil || got.Key != key || !strings.HasPrefix(got.Said, AskedAgainWords) {
|
|
t.Fatalf("asked again = %+v, %v", got, err)
|
|
}
|
|
raw, _, _, _ := r.verdicts.Get(ctx, key)
|
|
r.ch.VerdictWritten(ctx, key, raw) // the checker's watch of its verdicts hands it over
|
|
}
|
|
r.ch.Wait()
|
|
v := r.verdict(t, key)
|
|
if v.State != row.state || asked() != row.asks {
|
|
t.Errorf("verdict %s (%s) after %d asks, want %s after %d", v.State, v.Failed.Words, asked(), row.state, row.asks)
|
|
}
|
|
if _, _, kept, _ := asksKept.Get(ctx, key); kept {
|
|
t.Errorf("the asks of the ended check are still kept under %s", key)
|
|
}
|
|
if row.state == delivery.VerdictFail && (!IsLostAsk(v) || !IsNodesFailure(v)) {
|
|
t.Errorf("a check that judged nothing every time = %q, want lost and judged again when the nodes change", v.Failed.Words)
|
|
}
|
|
if row.how == "hand" {
|
|
rd := Reader{VerdictState: kvRead(r.verdicts), CandidateState: kvRead(newMemKV())}
|
|
if _, err := rd.AskAgain(asVerdicts{r.verdicts}, "feat/x", "again"); err == nil {
|
|
t.Error("a judged check was asked again")
|
|
}
|
|
}
|
|
})
|
|
}
|
|
}
|