diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/askagain_tool.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/askagain_tool.go new file mode 100644 index 00000000..762a44b1 --- /dev/null +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/askagain_tool.go @@ -0,0 +1,100 @@ +package main + +import ( + "encoding/json" + "errors" + "fmt" + "strings" + "time" + + occ "git.novox.be/novox/mesh-contracts/operator-and-conversation/go/clients/operatorchannelclient" + + "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshhandactsclient" + "git.novox.be/novox/mesh-delivery/contracts/go/clients/meshdeliveryclient" + "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-assigner/asks" + "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-teller/tellerevents" + stdio "git.novox.be/novox/mesh-sdk/go" + + "mesh-delivery-assigner/internal/assign" + "mesh-delivery-assigner/internal/buckets" + "mesh-delivery-assigner/internal/puts" +) + +// askAgainTool asks one of the assigner's asks again by hand (issue 1966, ADR 0668 §5): the recovery of an ask that ended at +// the operator channel without an answer when the event that would have asked it again was not heard. +const askAgainTool = "assigner_ask_again" + +// asksState and answersState are the assigner's asks and the teller's answers, as the runtime names them. +const ( + asksState = "asks" + answersState = buckets.TellerModule + ".answers" +) + +// askAgainByHand writes the ask at key again under a new asking, by the rules the teller's ask-ended writes it by (assign.AskedAgain: +// a proposal's authorising ask and a put's record ask are not), so the teller asks it again; an asking the operator answered +// is refused, naming the answer. The act is recorded through the seat mesh-hand-acts. +func askAgainByHand(st store, ask func(string, any) (json.RawMessage, error), key, why, by string, now time.Time) (any, error) { + switch { + case key == "": + return nil, errors.New("name the ask's key, as assigner_read_asks lists it") + case why == "": + return nil, errors.New("a hand ask again says why") + case by == "" || by == stdio.Unproven: + return nil, errors.New("a hand ask again names who asks it, and the runtime proved no caller") + } + current, _, found, err := st.get(asksState, key) + if err != nil { + return nil, err + } + if !found { + return nil, fmt.Errorf("the assigner holds no ask under %s: assigner_read_asks lists them", key) + } + _, routerAsk, err := assign.DecodeAsk(key, current) + if err != nil { + return nil, err + } + if raw, _, found, err := st.get(answersState, key); err == nil && found { + if a, err := meshdeliveryclient.DecodeAnswer(raw); err == nil && strings.HasPrefix(a.Warrant, routerAsk.ID+"@") { + return nil, fmt.Errorf("the asking %s was answered %q (%s): it is not asked again", routerAsk.ID, a.Option, a.Words) + } + } + var put *puts.Put + if k, err := asks.ParseAnyAskKey(key); err == nil && k.Kind == asks.AskKindRecord { + if pkey, err := puts.Key(k.Node, k.Module); err == nil { + if raw, _, found, err := st.get(putsState, pkey); err == nil && found { + if p, err := puts.Decode(raw); err == nil { + put = &p + } + } + } + } + value, refused := assign.AskedAgain(tellerevents.Ended{Key: key, Ask: routerAsk.ID, Outcome: occ.OutcomeCancelled}, current, put, now) + if refused != "" { + return nil, errors.New(refused) + } + if err := st.put(asksState, key, value); err != nil { + return nil, fmt.Errorf("the ask %s is not written again: %w", key, err) + } + _, next, _ := assign.DecodeAsk(key, value) + taken, rerr := meshhandactsclient.Recorder{Ask: ask}.Record(meshhandactsclient.Request{What: askAgainTool + " " + key, Why: why + " (" + by + ")", Cause: "ask-again"}) + recorded := taken.Log + if rerr != nil { + recorded = "not recorded: " + rerr.Error() + } + return map[string]any{"key": key, "ended": routerAsk.ID, "asked": next.ID, "by": by, "hand-act": recorded}, nil +} + +// askAgainTools is the tool over the runtime's states. +func askAgainTools(st store, ask func(string, any) (json.RawMessage, error), now func() time.Time) []stdio.Tool { + return []stdio.Tool{{Name: askAgainTool, Description: "Ask one of the assigner's asks of the operator again (issue 1966): the ask " + + "under key is written again under a new asking, which the teller asks on the operator channel, as when the channel says it " + + "ended without an answer. Refused for an asking the operator answered, a proposal's authorising ask (the seat's verb again " + + "asks it) and a record ask a put asked. Recorded as a hand act.", + Input: schema(map[string]string{"key": "the ask's key, as assigner_read_asks lists it", "why": "why it is asked again"}, + []string{"key", "why"}), + Run: func(a map[string]any) (any, error) { + key, _ := a["key"].(string) + why, _ := a["why"].(string) + return askAgainByHand(st, ask, key, why, stdio.CallerOf(a), now()) + }}} +} diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/askended.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/askended.go index e121b991..7b041c7f 100644 --- a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/askended.go +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/askended.go @@ -2,6 +2,7 @@ package main import ( "context" + "encoding/json" "errors" "time" @@ -9,9 +10,15 @@ import ( "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-assigner/asks" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-teller/tellerevents" + "git.novox.be/novox/mesh-sdk/go/busretry" "git.novox.be/novox/mesh-sdk/go/process" + mcc "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" + + oc "git.novox.be/novox/mesh-contracts/operator-and-conversation/go/seats/operatorchannel" + "mesh-delivery-assigner/internal/assign" + plc "mesh-delivery-assigner/internal/assignment" "mesh-delivery-assigner/internal/buckets" "mesh-delivery-assigner/internal/puts" ) @@ -40,6 +47,126 @@ func hearAskEnded(ctx context.Context, js jetstream.JetStream, hub *process.Even }) } +// channelAsksVerb is the operator-channel seat's verb asks, read at the assigner's consumer's bind (a seat verb: no module +// named). +const channelAsksVerb = "seat:" + oc.Seat + "." + oc.VerbAsks + +// readEndedAtBind registers on the hub, before it starts, one read of the operator-channel seat's asks at each bind of the +// assigner's consumer: an ask-ended the teller said before the consumer existed is not delivered to it (issue 1966 note 155, +// ADR 0668 §4), so each held ask whose asking ended there expired or cancelled is written again as that event writes it +// (askAgain, with every rule and its compare-and-set). The read is a kept call (CallKept), made off the hub's start. +func readEndedAtBind(ctx context.Context, js jetstream.JetStream, hub *process.EventHub, asksKV jetstream.KeyValue, bus caller, wait callWait, logf func(string, ...any)) { + if asksKV == nil || bus == nil { + return + } + hub.OnBound(func(created time.Time) { + go func() { + if err := endedAtBind(ctx, js, asksKV, bus, wait, created, time.Now(), logf); err != nil { + logf("the operator channel's ended asks are not read at the bind of %s (%v): an ask that ended there before is asked again when the teller says it ended", created.Format(time.RFC3339), err) + } + }() + }) +} + +// callWait is how a kept call the assigner waits on is said (novox/hq ADR 0668 §3): heard says the callee's machine is +// heard, now is the clock, and findings the assigner's findings, where the call unanswered past +// meshconditionsclient.CallUnansweredAfter is the finding call-unanswered while heard, cleared when it is answered. +type callWait struct { + heard func() bool + now func() time.Time + findings assign.Findings +} + +// asksCallID is the finding's id for the bind's read of the operator channel's asks. +const asksCallID = "operator-channel-asks" + +// keep makes call again after every transport fault (busretry: a request that reached no one, or one whose deadline +// passed) until it is answered or ctx ends, each try itself a kept call; past the bound with the callee heard it writes +// the finding call-unanswered, and clears it when answered. No timer: each try is the wait. +func (cw callWait) keep(ctx context.Context, id, callee string, call func() (json.RawMessage, error), logf func(string, ...any)) (json.RawMessage, error) { + clock := cw.now + if clock == nil { + clock = time.Now + } + since, said := clock(), false + key := mcc.Key(mcc.ScopeCall, id, mcc.KindCallUnanswered) + for { + answer, err := call() + if err == nil || !(busretry.Undelivered(err) || busretry.TimedOut(err)) || ctx.Err() != nil { + if said && cw.findings.Delete != nil { + if derr := cw.findings.Delete(key); derr != nil { + logf("the finding %s is not cleared: %v", key, derr) + } + } + return answer, err + } + if said || clock().Sub(since) < mcc.CallUnansweredAfter || cw.heard == nil || !cw.heard() || cw.findings.Put == nil { + continue + } + o := mcc.CallUnanswered(id, callee, "", err.Error(), "assigner."+mcc.KindCallUnanswered, since) + value, eerr := mcc.EncodeFinding(o.Finding(plc.Module, "", clock().UTC())) + if eerr == nil { + eerr = cw.findings.Put(key, value) + } + if eerr != nil { + logf("the finding %s is not written: %v", key, eerr) + continue + } + said = true + logf("%s is unanswered since %s and its callee's machine is heard: the finding %s", callee, since.UTC().Format(time.RFC3339), key) + } +} + +// endedAtBind is readEndedAtBind's one read: the held asks, the seat's verb (a kept call whose wait is kept, wait), and +// each ended asking written again. +func endedAtBind(ctx context.Context, js jetstream.JetStream, asksKV jetstream.KeyValue, bus caller, wait callWait, created, now time.Time, logf func(string, ...any)) error { + keys, err := asksKV.Keys(ctx) + if errors.Is(err, jetstream.ErrNoKeysFound) { + return nil + } + if err != nil { + return err + } + held := map[string][]byte{} + for _, key := range keys { + if e, err := asksKV.Get(ctx, key); err == nil { + held[key] = e.Value() + } + } + query, ok := assign.ChannelAsksQuery(held) + if !ok { + return nil + } + answer, err := wait.keep(ctx, asksCallID, channelAsksVerb, func() (json.RawMessage, error) { return bus.CallKept(channelAsksVerb, query) }, logf) + if err != nil { + return err + } + ended, cut, err := assign.EndedAtChannel(held, answer) + if err != nil { + return err + } + if cut != "" { + logf("%s at the bind: %s", channelAsksVerb, cut) + } + var putsKV jetstream.KeyValue + if js != nil { + if kv, err := js.KeyValue(ctx, buckets.Puts); err == nil { + putsKV = kv + } + } + for _, e := range ended { + body, err := tellerevents.EncodeEnded(e) + if err == nil { + err = askAgain(ctx, asksKV, putsKV, body, now, logf) + } + if err != nil { + return err + } + } + logf("%s at the bind of %s: %d of %d held asks ended at the channel without an answer", channelAsksVerb, created.Format(time.RFC3339), len(ended), len(held)) + return nil +} + // askAgain writes the ask the teller said ended again under a new asking, by compare-and-set at the revision that holds the // asking that ended (assign.AskedAgain), and says in the journal what it wrote or why it wrote nothing. Only a bus that // could not be read or written is an error, so the event is heard again; a body that does not read is said and dropped. diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/integration_test.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/integration_test.go index b4267224..b6e8c91e 100644 --- a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/integration_test.go +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/integration_test.go @@ -1103,7 +1103,7 @@ func TestAHoldWrittenAgainAfterALiftAndARestartIsAskedAgain(t *testing.T) { time.Sleep(1100 * time.Millisecond) // the next hold is written in another second b.answerTo(t, akey, "keep", first.Ask.ID) // an answer to the first hold, which the later hold must not take b.putJSON(t, buckets.Have, "ace.web", failed) - b.start(t) + _, stop = b.startStoppable(t) again, err := decodeAsk(akey, b.get(t, buckets.Asks, akey)) if err != nil { t.Fatal(err) @@ -1111,6 +1111,34 @@ func TestAHoldWrittenAgainAfterALiftAndARestartIsAskedAgain(t *testing.T) { if again.Ask.ID == first.Ask.ID { t.Fatalf("the hold written again is asked under the first id %s", first.Ask.ID) } + // Issue 1966 note 155, ADR 0668 §4: that asking lapses at the operator channel while no assigner runs, so the teller's + // ask-ended is said before the next one's consumer binds; at its bind the next reads the operator-channel seat's asks and + // writes the hold again under a new asking. + stop() + nc, err := nats.Connect(b.srv.ClientURL()) + if err != nil { + t.Fatal(err) + } + defer nc.Close() + for _, subject := range []string{"mesh.seat.operator-channel.tool.asks", "mesh.seat.operator-channel.call.asks.*"} { + if _, err := nc.Subscribe(subject, func(m *nats.Msg) { + answer, _ := json.Marshal(map[string]any{"asks": []map[string]string{{"key": "mesh-delivery-teller." + again.Ask.ID, "state": "expired"}}, "matched": 1}) + reply, _ := json.Marshal(map[string]any{"result": json.RawMessage(answer)}) + _ = m.Respond(reply) + }); err != nil { + t.Fatal(err) + } + } + subscribed(t, nc) + b.start(t) + for deadline := time.Now().Add(15 * time.Second); ; time.Sleep(50 * time.Millisecond) { + if third, err := decodeAsk(akey, b.get(t, buckets.Asks, akey)); err == nil && third.Ask.ID != again.Ask.ID { + break + } + if time.Now().After(deadline) { + t.Fatalf("the hold whose asking %s lapsed before the assigner's bind was not asked again", again.Ask.ID) + } + } b.putJSON(t, buckets.Have, "ace.web", healthy) for deadline := time.Now().Add(15 * time.Second); b.hasKey(buckets.Wants, hkey); time.Sleep(100 * time.Millisecond) { if time.Now().After(deadline) { diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/main.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/main.go index 9e72e33e..a18d9632 100644 --- a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/main.go +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/main.go @@ -12,6 +12,7 @@ import ( "fmt" "io" "log" + "maps" "mesh-delivery-assigner/internal/assignment" "mesh-delivery-assigner/internal/buckets" "os" @@ -315,7 +316,8 @@ func follow(ctx context.Context, js jetstream.JetStream, nc process.Subscriber, // from the node's record where the engine does not answer (the fallback, said in the journal). reads := &enginereads.Keeper{Fallback: w.recordReads, Changed: wake, Logf: logger.Printf} if bus != nil { - reads.Call = bus.CallOn + reads.Call = bus.CallKeptOn // a kept call, called again through a transport fault (ADR 0668 §1) + reads.Once = bus.CallOn // its fault keeps the fallback at once while the kept call asks on (ADR 0668 §3) } if kv := kvs[engineReadsBucket]; kv != nil { reads.Put = func(node string, v []byte) error { _, err := kv.Put(ctx, node, v); return err } @@ -482,6 +484,7 @@ func follow(ctx context.Context, js jetstream.JetStream, nc process.Subscriber, if err := hearAskEnded(ctx, js, hub, kvs[buckets.Asks], logger.Printf); err != nil { logger.Printf("%s is not heard, so an ask that ends at the operator channel without an answer is not asked again until the assigner starts again: %v", askEndedSubject, err) } + readEndedAtBind(ctx, js, hub, kvs[buckets.Asks], bus, callWait{heard: func() bool { return w.seatHeard(oc.Seat) }, findings: findings}, logger.Printf) hearReadsChanged(ctx, js, hub, reads, findings, gate.eventsLive, logger.Printf) } if bus != nil && kvs[buckets.Puts] != nil { @@ -570,6 +573,9 @@ func hearReadsChanged(ctx context.Context, js jetstream.JetStream, hub *process. } } err := hub.Handle(enginereads.SubjectPrefix+"*", handle) + // At each bind every node the assigner holds a statement of is asked again: an event said before its consumer existed + // is not delivered to it (issue 1966 note 155: ace's bootstrapped statement stood; ADR 0668 §4). + hub.OnBound(reads.AtBind(func() []string { return slices.Sorted(maps.Keys(reads.Statements())) })) if err == nil { err = hub.Start(ctx, js, account) } diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/pass.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/pass.go index 4dfc33e8..31cebd7b 100644 --- a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/pass.go +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/pass.go @@ -24,6 +24,7 @@ import ( "git.novox.be/novox/mesh-sdk/go/catalogue" "git.novox.be/novox/mesh-contracts/go/clients/nodeengineclient/enginereads" + mcc "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" "mesh-delivery-assigner/internal/assign" plc "mesh-delivery-assigner/internal/assignment" @@ -42,6 +43,8 @@ type passer struct { said map[string]bool // findings is the assigner's findings bucket (its said conditions, ADR 0564 §2). findings assign.Findings + // calls is the wait of the kept manifest-reads calls (enginereads.ReadsCalls, ADR 0668 §3), made at the first pass. + calls *enginereads.ReadsCalls // failedProvisions are the failed provisions whose finding this process wrote (ADR 0570 §4). failedProvisions map[string]bool // missing are the required provisions with no key this process pulsed, and missingSaid those whose finding it wrote. @@ -116,6 +119,62 @@ func (p *passer) engineReads(n assign.Nodes) { n.Reads[node] = reads } } + p.unansweredReads(known, n.Online) +} + +// unansweredReads keeps the wait of every node whose engine has not answered manifest-reads while its machine is heard +// (online), through the node-engine seat's client (enginereads.ReadsCalls, shared with the builder and the indexer): it +// is asked again once its last ask ended, so the kept call goes on until answered; past +// meshconditionsclient.CallUnansweredAfter it is the finding call-unanswered in the assigner's findings, cleared once +// answered (novox/hq ADR 0668 §3). Each pass is the event, and the assigner's own presence says heard: no timer, no bound. +func (p *passer) unansweredReads(known []string, online map[string]bool) { + if p.reads.Call == nil { + return + } + if p.findings.Put == nil || p.findings.Delete == nil { + for _, node := range known { + if s, ok := p.reads.Statements()[node]; ok && !s.Answered && online[node] && !p.reads.Asking(node) { + p.reads.AskNode(node, "unanswered since "+s.UnansweredSince.UTC().Format(time.RFC3339)+", its machine heard") + } + } + return + } + if p.calls == nil || p.calls.Keeper != p.reads { + p.calls = &enginereads.ReadsCalls{Keeper: p.reads, Bound: mcc.CallUnansweredAfter, Now: p.clock, Logf: p.logf, + Raise: func(_ context.Context, u enginereads.UnansweredCall) error { + o := mcc.CallUnanswered(enginereads.CallID(u.Node), enginereads.Invoke, u.Node, u.Words, "assigner."+mcc.KindCallUnanswered, u.Since) + o.Needs = "assigner_engine_reads with ask_again asks the node again now and shows its statement." + value, err := mcc.EncodeFinding(o.Finding(plc.Module, "", u.At)) + if err == nil { + err = p.findings.Put(o.Key(), value) + } + return err + }, + Clear: func(_ context.Context, node string) error { + return p.findings.Delete(mcc.Key(mcc.ScopeCall, enginereads.CallID(node), mcc.KindCallUnanswered)) + }} + if p.findings.Keys != nil { + // What a pass before or another process wrote: every such finding of the assigner's is weighed to be cleared. + prefix, suffix := mcc.ScopeCall+"."+enginereads.CallID(""), "."+mcc.KindCallUnanswered + p.calls.Held = func(context.Context) ([]string, error) { + keys, err := p.findings.Keys() + var nodes []string + for _, key := range keys { + if rest, ok := strings.CutPrefix(key, prefix); ok { + if node, ok := strings.CutSuffix(rest, suffix); ok { + nodes = append(nodes, node) + } + } + } + return nodes, err + } + } else { + p.calls.Held = func(context.Context) ([]string, error) { return nil, nil } + } + } + p.calls.Nodes = func() []string { return known } + p.calls.Heard = func(_ context.Context, node string) (bool, error) { return online[node], nil } + p.calls.Step(context.Background()) } func (p *passer) clock() time.Time { diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/pass_test.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/pass_test.go index 8d116ce6..b8e5bcbd 100644 --- a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/pass_test.go +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/pass_test.go @@ -6,6 +6,8 @@ import ( "encoding/json" "errors" "fmt" + stdio "git.novox.be/novox/mesh-sdk/go" + "maps" "mesh-delivery-assigner/internal/buckets" "mesh-delivery-assigner/internal/puts" "slices" @@ -35,6 +37,7 @@ import ( "git.novox.be/novox/mesh-contracts/go/clients/nodeengineclient/enginereads" "git.novox.be/novox/mesh-contracts/go/seats/nodeengine" + mcc "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" "git.novox.be/novox/mesh-delivery/sdk/graph" "mesh-delivery-assigner/internal/assign" @@ -127,6 +130,58 @@ func TestAHoldAskedAgainAfterALiftAndARestartHasANewID(t *testing.T) { if a2.Ask.ID == a1.Ask.ID { t.Errorf("the ask written again after a lift and a restart has the id %s of the first", a1.Ask.ID) } + // Issue 1966, ADR 0668 §5: assigner_ask_again writes the hold again under a new asking and records the hand act; the + // asking the operator answered is refused, naming the answer; a proposal's authorising ask is refused by its rule. + answersKV := &memKV{values: map[string][]byte{}} + st := memStore{asksState: asksKV, answersState: answersKV} + var recorded []string + record := func(key string, body any) (json.RawMessage, error) { + raw, _ := json.Marshal(body) + recorded = append(recorded, key+" "+string(raw)) + return json.RawMessage(`{}`), nil + } + now := time.Date(2026, 10, 25, 3, 0, 0, 0, time.UTC) + out, err := askAgainByHand(st, record, key, "the channel lost it", "lead@shanks", now) + a3, derr := decodeAsk(key, asksKV.values[key]) + if err != nil || derr != nil || a3.Ask.ID == a2.Ask.ID || len(recorded) != 1 || !strings.Contains(recorded[0], askAgainTool+" "+key) { + t.Fatalf("ask again: %v, %v; asked %s (was %s), recorded %v", out, err, a3.Ask.ID, a2.Ask.ID, recorded) + } + answersKV.values[key], _ = mdc.EncodeAnswer(mdc.Answer{Option: "keep", Warrant: a3.Ask.ID + "@2026-10-25T03:01:00Z", Words: "the operator"}) + if _, err := askAgainByHand(st, record, key, "again", "lead@shanks", now); err == nil || !strings.Contains(err.Error(), "keep") { + t.Errorf("an answered asking is asked again: %v", err) + } + for _, c := range []struct{ key, by, why string }{{key, stdio.Unproven, "a caller"}, {"hold.none", "lead@shanks", "no ask"}} { + if _, err := askAgainByHand(st, record, c.key, "w", c.by, now); err == nil { + t.Errorf("%s: asked again", c.why) + } + } + // ADR 0668 §3 (review round 1): the bind's read of the operator channel's asks keeps its wait through transport faults; + // past five minutes with the channel's machine heard it is the finding call-unanswered, cleared once answered; with + // the machine away none is written. A refusal is an answer and ends the wait. + for _, heard := range []bool{false, true} { + clock, findings := now, map[string][]byte{} + cw := callWait{heard: func() bool { return heard }, now: func() time.Time { return clock }, + findings: assign.Findings{Put: func(k string, v []byte) error { findings[k] = v; return nil }, + Delete: func(k string) error { delete(findings, k); return nil }}} + tries, during := 0, 0 + answer, err := cw.keep(context.Background(), asksCallID, channelAsksVerb, func() (json.RawMessage, error) { + tries++ + clock = clock.Add(2 * time.Minute) + if tries == 5 { + during = len(findings) + return json.RawMessage(`{"asks":[]}`), nil + } + return nil, errors.New("nats: no responders available for request") + }, t.Logf) + if want := map[bool]int{false: 0, true: 1}[heard]; err != nil || string(answer) != `{"asks":[]}` || tries != 5 || during != want || len(findings) != 0 { + t.Errorf("heard %v: %s %v after %d tries; findings during %d, after %d", heard, answer, err, tries, during, len(findings)) + } + } + if _, err := (callWait{}).keep(context.Background(), asksCallID, channelAsksVerb, func() (json.RawMessage, error) { + return nil, &busretry.Answered{Words: "refused"} + }, t.Logf); err == nil { + t.Error("a refusal was asked again") + } } // 1906/H4: an answer counts only for the asking it answered: an answer to an earlier hold of the same fingerprint, or to an ask @@ -214,6 +269,45 @@ func TestAnAnswerCountsOnlyForTheAskingItAnswered(t *testing.T) { if asked["ace"] != 2 { t.Errorf("ace, back online, was asked %d times, want 2", asked["ace"]) } + // ADR 0668 §3 (review round 1): a node whose engine answers nothing while its machine is heard is asked again at each + // pass once its ask ended, and past five minutes is the finding call-unanswered, cleared once it answers; none is + // written while its machine is away. + clock := time.Date(2026, 11, 10, 3, 0, 0, 0, time.UTC) + held := map[string][]byte{} + answers := false + silent := func(node, _ string, _ any) (json.RawMessage, error) { + asked[node]++ + if answers { + return json.Marshal(nodeengine.ManifestReadsAnswer{V: 1, Node: node, ManifestReads: []string{"form:new"}, StatedAt: clock.Format(time.RFC3339Nano)}) + } + return nil, context.DeadlineExceeded + } + q := &passer{w: w, logf: t.Logf, now: func() time.Time { return clock }, findings: assign.Findings{ + Put: func(k string, v []byte) error { held[k] = v; return nil }, + Delete: func(k string) error { delete(held, k); return nil }, + Keys: func() ([]string, error) { return slices.Collect(maps.Keys(held)), nil }}, + reads: &enginereads.Keeper{Call: silent, Sync: true, Now: func() time.Time { return clock }}} + key := mcc.Key(mcc.ScopeCall, enginereads.CallID("ace"), mcc.KindCallUnanswered) + before := asked["ace"] + q.engineReads(w.nodes(nil, nil)) + clock = clock.Add(6 * time.Minute) + off, _ := presenceValue(false) + w.put(buckets.Presence, "ace", off) + q.engineReads(w.nodes(nil, nil)) + if len(held) != 0 { + t.Errorf("a finding was written while ace is away: %v", slices.Collect(maps.Keys(held))) + } + w.put(buckets.Presence, "ace", on) + q.engineReads(w.nodes(nil, nil)) + if _, ok := held[key]; !ok || asked["ace"]-before < 3 { + t.Errorf("ace unanswered six minutes, heard: findings %v, asked %d times", slices.Collect(maps.Keys(held)), asked["ace"]-before) + } + answers = true + q.engineReads(w.nodes(nil, nil)) + q.engineReads(w.nodes(nil, nil)) + if _, ok := held[key]; ok { + t.Errorf("the finding stays after ace answered") + } // The contract carries no checks, so its reader judges what the engine says (mesh-contracts seats/nodeengine): an // answer or an event that does not hold is no statement, and an event's node is its subject's last token. now := time.Now().Format(time.RFC3339Nano) @@ -316,6 +410,10 @@ func (b *fakeBus) Call(key string, body any) (json.RawMessage, error) { func (b *fakeBus) CallOn(node, key string, body any) (json.RawMessage, error) { return b.Call(node+"/"+key, body) } +func (b *fakeBus) CallKept(key string, body any) (json.RawMessage, error) { return b.Call(key, body) } +func (b *fakeBus) CallKeptOn(node, key string, body any) (json.RawMessage, error) { + return b.CallOn(node, key, body) +} func (b *fakeBus) Emit(eventType string, body any) error { b.events = append(b.events, fmt.Sprintf("%s %+v", eventType, body)) return nil diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/puts.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/puts.go index 492f4219..929ecbdb 100644 --- a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/puts.go +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/puts.go @@ -41,6 +41,10 @@ const PutEvent = "put" type caller interface { Call(key string, body any) (json.RawMessage, error) CallOn(node, key string, body any) (json.RawMessage, error) + // CallKept is Call for a kept call, safe to call again (process.Conn.CallKept; ADR 0668). + CallKept(key string, body any) (json.RawMessage, error) + // CallKeptOn is CallOn for a kept call, safe to call again (process.Conn.CallKeptOn; ADR 0668). + CallKeptOn(node, key string, body any) (json.RawMessage, error) Emit(eventType string, body any) error } diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/tools.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/tools.go index 877b6c1e..d81e9acf 100644 --- a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/tools.go +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/tools.go @@ -404,6 +404,7 @@ func serveTools() error { tools = append(tools, viewTools(os.Getenv, keptSource, time.Now)...) // What each node's engine reads, as the assigner uses it (ADR 0618 §3): its own state engine-reads, asked again through it. tools = append(tools, enginereads.Tool(engineReadsTool, "the assigner", enginereads.KeptState(stdio.State(engineReadsState)), false, time.Now)) + tools = append(tools, askAgainTools(runtimeStore{}, stdio.Ask, time.Now)...) return stdio.Serve("", tools) } diff --git a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/world.go b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/world.go index 7c60c464..cf2b67f4 100644 --- a/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/world.go +++ b/modules/mesh-delivery-assigner/cmd/mesh-delivery-assigner/world.go @@ -2,6 +2,7 @@ package main import ( "context" + "encoding/json" "errors" "maps" "mesh-delivery-assigner/internal/buckets" @@ -339,6 +340,24 @@ func presenceOf(key string, value []byte) (node string, online, ok bool) { return node, p.Online, true } +// seatHeard says a machine holding seat (a seat held once) is online as the watchman holds it: the callee of a call to +// the seat's verb is heard (novox/hq ADR 0668 §3). +func (w *world) seatHeard(seat string) bool { + online := w.online() + for _, value := range w.read(plc.SeatHoldersBucket) { + var sh mma.SeatHolders + if json.Unmarshal(value, &sh) != nil || sh.Seat != seat { + continue + } + for _, h := range sh.Holders { + if online[h.Node] { + return true + } + } + } + return false +} + // online is, by node, whether the watchman holds the node online. func (w *world) online() map[string]bool { out := map[string]bool{} diff --git a/modules/mesh-delivery-assigner/internal/assign/asks_test.go b/modules/mesh-delivery-assigner/internal/assign/asks_test.go index 8ac49816..5264609f 100644 --- a/modules/mesh-delivery-assigner/internal/assign/asks_test.go +++ b/modules/mesh-delivery-assigner/internal/assign/asks_test.go @@ -28,6 +28,7 @@ func TestTheHoldAskIsValid(t *testing.T) { t.Run("hold", theHoldAskIsValid) t.Run("restore", theRestoreAskIsValid) t.Run("ended at the channel", anAskEndedAtTheChannelIsWrittenAgain) + t.Run("ended at the channel, read at bind", anAskEndedAtTheChannelIsReadAtBind) } // Issue 1966, note 151: an ask the teller says ended at the operator channel without an answer (its event ask-ended) is @@ -122,6 +123,50 @@ func anAskEndedAtTheChannelIsWrittenAgain(t *testing.T) { } } +// Issue 1966 note 155, ADR 0668 §4: an ended ask the teller said before the assigner's consumer existed is not delivered to +// it, so at bind the assigner reads the operator-channel seat's asks: the query reaches back to the earliest held asking, +// and of the answer only the held askings that lapsed or were cancelled are taken, as the teller's event says them; an +// answered or another asker's ask, and one the key no longer holds, are not. +func anAskEndedAtTheChannelIsReadAtBind(t *testing.T) { + asked := time.Date(2026, 11, 9, 22, 0, 0, 0, time.UTC) + holdKey, _ := asks.HoldAskKey("nats", fNew) + restoreKey, _ := asks.RestoreAskKey("novox", "nats", fNew) + backupKey, _ := asks.BackupAskKey("novox", "nats", fNew) + hold := HoldAsk(holdKey, "nats", fNew, "novox", "w", AskingSeconds(asked), asked) + restore := RestoreAsk(restoreKey, "novox", "nats", fNew, "w", AskingSeconds(asked.Add(time.Hour)), asked.Add(time.Hour)) + backup := BackupAsk(backupKey, "novox", "nats", fNew, "sha256:"+strings.Repeat("e", 64), "w", 0, asked.Add(-time.Hour)) // no asking + held := map[string][]byte{} + for key, a := range map[string]asks.Ask{holdKey: hold, restoreKey: restore, backupKey: backup} { + v, err := EncodeAsk(key, a) + if err != nil { + t.Fatal(err) + } + held[key] = v + } + if _, ok := ChannelAsksQuery(nil); ok { + t.Error("with no ask held the channel is asked") + } + q, ok := ChannelAsksQuery(held) + if !ok || q.State != "ended" || q.Bound != ChannelAsksBound || q.Since != asked.Add(-time.Hour-time.Minute).Format(time.RFC3339) { + t.Errorf("the query is %v, want the ended asks since %s", q, asked.Add(-time.Hour-time.Minute).Format(time.RFC3339)) + } + at := func(key string, a asks.Ask, state string) string { + return fmt.Sprintf(`{"key":"t.%s","state":%q}`, mustAsk(t, a).ID, state) + } + answer := `{"asks":[` + strings.Join([]string{at(holdKey, hold, occ.OutcomeExpired), at(restoreKey, restore, occ.OutcomeChosen), + at(backupKey, backup, occ.OutcomeCancelled), `{"key":"t.hold-gone","state":"expired"}`, `{"key":"open","state":"open"}`}, ",") + `],"cut":"c"}` + ended, cut, err := EndedAtChannel(held, []byte(answer)) + want := []tellerevents.Ended{{Key: backupKey, Ask: mustAsk(t, backup).ID, Outcome: occ.OutcomeCancelled}, + {Key: holdKey, Ask: mustAsk(t, hold).ID, Outcome: occ.OutcomeExpired}} + slices.SortFunc(want, func(a, b tellerevents.Ended) int { return strings.Compare(a.Key, b.Key) }) + if err != nil || cut != "c" || !slices.Equal(ended, want) { + t.Errorf("EndedAtChannel = %+v, %q, %v; want %+v and the answer's cut", ended, cut, err, want) + } + if _, _, err := EndedAtChannel(held, []byte(`[1]`)); err == nil { + t.Error("an answer that does not read is taken") + } +} + func ptr(a asks.Ask) *asks.Ask { return &a } func theHoldAskIsValid(t *testing.T) { diff --git a/modules/mesh-delivery-assigner/internal/assign/ended.go b/modules/mesh-delivery-assigner/internal/assign/ended.go index 107db2b2..a59e1bbf 100644 --- a/modules/mesh-delivery-assigner/internal/assign/ended.go +++ b/modules/mesh-delivery-assigner/internal/assign/ended.go @@ -1,10 +1,14 @@ package assign import ( + "encoding/json" "fmt" + "slices" + "strings" "time" occ "git.novox.be/novox/mesh-contracts/operator-and-conversation/go/clients/operatorchannelclient" + oc "git.novox.be/novox/mesh-contracts/operator-and-conversation/go/seats/operatorchannel" "git.novox.be/novox/mesh-delivery/contracts/go/clients/meshdeliveryclient" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-assigner/asks" @@ -71,3 +75,63 @@ func AskedAgain(e tellerevents.Ended, current []byte, put *puts.Put, now time.Ti } return value, "" } + +// ChannelAsksBound is the most bytes of asks the assigner asks the operator-channel seat's verb asks for at its consumer's +// bind: every ended asking of its held asks fits. +const ChannelAsksBound = 1 << 20 + +// ChannelAsksQuery is the arguments of the operator-channel seat's verb asks that answer, at the assigner's consumer's bind, +// every asking of its held asks (key to value, as the asks state holds them) that ended at the channel: the ended asks +// opened since the earliest of them could have been opened, less a minute (issue 1966 note 155, ADR 0668 §4). ok is false +// when no held ask reads, and then nothing is asked. +func ChannelAsksQuery(held map[string][]byte) (query oc.AsksInput, ok bool) { + var since time.Time + for key, value := range held { + a, ask, err := DecodeAsk(key, value) + if err != nil { + continue + } + opened := ExpiresAt(ask).Add(-AskLasts) + if a.Asking >= 2 { + if at := time.Unix(int64(a.Asking), 0); at.Before(opened) { + opened = at + } + } + if !ok || opened.Before(since) { + since, ok = opened, true + } + } + if !ok { + return oc.AsksInput{}, false + } + return oc.AsksInput{State: "ended", Since: since.Add(-time.Minute).UTC().Format(time.RFC3339), Bound: ChannelAsksBound}, true +} + +// EndedAtChannel is, of the operator-channel seat's answer of its verb asks, each held ask whose asking ended there +// expired or cancelled, as the teller says it in its event ask-ended, so the assigner writes it again by the rules of that +// event (AskedAgain), with its compare-and-set: an ended ask said before the assigner's consumer existed is not delivered +// to it (issue 1966 note 155, ADR 0668 §4). cut is the answer's own cut, said by the caller; an answer that does not read +// is the error. +func EndedAtChannel(held map[string][]byte, answer []byte) (ended []tellerevents.Ended, cut string, err error) { + var got oc.AsksAnswer // the seat's declared answer: each ask's key and its state, and the cut + if err := json.Unmarshal(answer, &got); err != nil { + return nil, "", fmt.Errorf("assign: the operator channel's asks do not read: %w", err) + } + byID := map[string]string{} + for key, value := range held { + if _, ask, err := DecodeAsk(key, value); err == nil { + byID[ask.ID] = key + } + } + for _, v := range got.Asks { + if v.State != occ.OutcomeExpired && v.State != occ.OutcomeCancelled { + continue + } + _, id, ok := oc.ParseAsksByAskerIDKey(v.Key) + if key, held := byID[id]; ok && held { + ended = append(ended, tellerevents.Ended{Key: key, Ask: id, Outcome: v.State}) + } + } + slices.SortFunc(ended, func(a, b tellerevents.Ended) int { return strings.Compare(a.Key, b.Key) }) + return ended, got.Cut, nil +} diff --git a/modules/mesh-delivery-assigner/manifest_test.go b/modules/mesh-delivery-assigner/manifest_test.go index 4438804c..c1ceeaea 100644 --- a/modules/mesh-delivery-assigner/manifest_test.go +++ b/modules/mesh-delivery-assigner/manifest_test.go @@ -96,8 +96,8 @@ func TestManifest(t *testing.T) { // which lists and asks again what each node's engine reads. if !slices.Equal(m.Tools, []string{"assigner_put", "assigner_release", "assigner_puts", "assignments", "seat-holders", "wants", "assigner_read_assignments", "assigner_read_seat_holders", "assigner_read_wants", "assigner_read_findings", "assigner_read_asks", "assigner_read_differences", "assigner_read_copies", - "assigner_first_views", "assigner_first_view_again", "assigner_engine_reads", "assigner_seat_list", "assigner_seat_list_again"}) { - t.Errorf("the assigner serves tools %v, want its three put tools, three first views, six read tools, assigner_engine_reads and the seat list's two (ADR 0636 §7)", m.Tools) + "assigner_first_views", "assigner_first_view_again", "assigner_engine_reads", "assigner_seat_list", "assigner_seat_list_again", "assigner_ask_again"}) { + t.Errorf("the assigner serves tools %v, want its three put tools, three first views, six read tools, assigner_engine_reads, the seat list's two (ADR 0636 §7) and assigner_ask_again (ADR 0668 §5)", m.Tools) } if m.RunsAs != m.Module || m.SecretsOwner != m.RunsAs { t.Errorf("runs-as = %q: the bundle runs on the assigner's own account (ADR 0621 §1)", m.RunsAs) @@ -130,7 +130,8 @@ func TestManifest(t *testing.T) { "seat:mesh-catalog.seat-definitions", // ADR 0636 §4: the seat list "seat:mesh-hand-acts.hand-act", "seat:mesh-hand-acts.hand-acts", "seat:mesh-hand-acts.warranted", // ADR 0565 §9, §11: the seat alone "seat:node-backup.backed-up", "seat:node-backup.now", - "seat:node-engine.manifest-reads"}; !slices.Equal(slices.Sorted(slices.Values(m.Invokes)), want) { // ADR 0618 §3 + "seat:node-engine.manifest-reads", // ADR 0618 §3 + "seat:operator-channel.asks"}; !slices.Equal(slices.Sorted(slices.Values(m.Invokes)), want) { // ADR 0668 §4: the ended asks at bind t.Errorf("invokes = %v, want %v", m.Invokes, want) } if want := []string{"assignments-copied", "put", "views.asks", "views.copies", "views.differences", "views.findings", "views.assignments", "views.seat-holders", "views.wants"}; !slices.Equal(m.Emits, want) { diff --git a/modules/mesh-delivery-assigner/module.json b/modules/mesh-delivery-assigner/module.json index 63ae125a..e594b25c 100644 --- a/modules/mesh-delivery-assigner/module.json +++ b/modules/mesh-delivery-assigner/module.json @@ -57,7 +57,8 @@ "seat:mesh-hand-acts.warranted", "seat:node-backup.backed-up", "seat:node-backup.now", - "seat:node-engine.manifest-reads" + "seat:node-engine.manifest-reads", + "seat:operator-channel.asks" ], "emits": [ "assignments-copied", @@ -88,7 +89,8 @@ "assigner_first_view_again", "assigner_engine_reads", "assigner_seat_list", - "assigner_seat_list_again" + "assigner_seat_list_again", + "assigner_ask_again" ], "state": [ { "name": "assignments", "history": 64 }, diff --git a/modules/mesh-delivery-builder/buildrun/asks.go b/modules/mesh-delivery-builder/buildrun/asks.go index 5e88371c..d9a0c35b 100644 --- a/modules/mesh-delivery-builder/buildrun/asks.go +++ b/modules/mesh-delivery-builder/buildrun/asks.go @@ -14,6 +14,7 @@ import ( "github.com/nats-io/nats.go/jetstream" "git.novox.be/novox/mesh-delivery/sdk/buildstep" + "git.novox.be/novox/mesh-sdk/go/busretry" ) // **An asker puts an ask on its build seat's stream and waits for its step** (novox/hq ADR 0525 §1, §6; issue 1887 A4, @@ -98,7 +99,14 @@ func (k Asker) dropped(a buildstep.StepAsk, why string) { } } -// Put puts a on its stream: the seat's accept subject of its language and kind. +// PutTry is how long one publish of an ask waits for its stream's answer before it is made again (Put). +var PutTry = 10 * time.Second + +// Put puts a on its stream: the seat's accept subject of its language and kind. The put is a kept call (novox/hq ADR 0668 +// §1, §2; issue 1966, issue 1748 note 27): it carries the ask's id as its message id, so the stream takes it once, and it +// is made again through every transport fault (a deadline, no responders) within busretry.Bound, each try bounded by +// PutTry, until ctx ends. A put that still meets one is an error opening with buildstep.TransportFaultWords, so the key it +// fails is one the builder does not take again by itself (ADR 0664 §3) and builder_build_again does. func (k Asker) Put(ctx context.Context, a buildstep.StepAsk) error { raw, err := buildstep.EncodeStepAsk(a) if err != nil { @@ -108,10 +116,25 @@ func (k Asker) Put(ctx context.Context, a buildstep.StepAsk) error { if err != nil { return err } - if err := k.Publisher.PublishAsk(ctx, subject, a.ID, raw); err != nil { - return fmt.Errorf("putting the %s ask %s: %w", a.Kind, a.ID, err) + _, err = busretry.DoRepeatable("putting the "+a.Kind+" ask "+a.ID, func() (struct{}, error) { + if err := ctx.Err(); err != nil { + return struct{}{}, fmt.Errorf("the put was given up: %v", err) // not a fault to wait out: the build ended + } + try, cancel := context.WithTimeout(ctx, PutTry) + defer cancel() + err := k.Publisher.PublishAsk(try, subject, a.ID, raw) + if err != nil && ctx.Err() != nil { + return struct{}{}, fmt.Errorf("the put was given up: %v", err) + } + return struct{}{}, err + }, nil) + switch { + case err == nil: + return nil + case busretry.TimedOut(err) || busretry.Undelivered(err): + return fmt.Errorf("%sthe put of the %s ask %s: %w", buildstep.TransportFaultWords, a.Kind, a.ID, err) } - return nil + return fmt.Errorf("putting the %s ask %s: %w", a.Kind, a.ID, err) } // Wait waits for the step of an ask already put (a builder that started again takes over its own asks with it, never diff --git a/modules/mesh-delivery-builder/buildrun/asks_test.go b/modules/mesh-delivery-builder/buildrun/asks_test.go index 29406198..a460f924 100644 --- a/modules/mesh-delivery-builder/buildrun/asks_test.go +++ b/modules/mesh-delivery-builder/buildrun/asks_test.go @@ -5,12 +5,16 @@ import ( "encoding/json" "errors" "fmt" + "slices" "strings" "sync" "testing" "time" + "github.com/nats-io/nats.go" + "git.novox.be/novox/mesh-delivery/sdk/buildstep" + "git.novox.be/novox/mesh-sdk/go/busretry" "git.novox.be/novox/mesh-sdk/go/health" ) @@ -41,6 +45,39 @@ func TestAnAskerPutsOnceAndReadsTheStep(t *testing.T) { if _, err := k.Ask(context.Background(), goAsk("mvl0frv18d1958")); err == nil || !strings.Contains(err.Error(), "shanks refused: go 1.27 installed") { t.Fatalf("a refused step: %v", err) } + // Issue 1966 (ADR 0668 §1, §2; 1748 note 27): the put is a kept call under the ask's id, made again through a deadline and + // no responders until the stream takes it; a refusal of the stream is not made again; a put that meets a transport fault + // past the bound says it in buildstep.TransportFaultWords, so the key it fails is the hand tool's to build again. + t.Cleanup(busretry.Waits(time.Second, time.Millisecond, time.Millisecond)) + for name, c := range map[string]struct { + faults []error + tries int + transport bool + }{ + "a deadline, then no responders, then taken": {faults: []error{context.DeadlineExceeded, nats.ErrNoResponders}, tries: 3}, + "refused by the stream": {faults: []error{errors.New("maximum messages exceeded")}, tries: 1}, + "a deadline past the bound": {faults: slices.Repeat([]error{nats.ErrTimeout}, 10000), transport: true}, + } { + p := &faultyPuts{faults: c.faults, inner: &FakeAsks{}} + restore := func() {} + if c.transport { + restore = busretry.Waits(20*time.Millisecond, time.Millisecond, time.Millisecond) // a bound this row passes + } + err := (Asker{Publisher: p, Waiter: p.inner}).Put(context.Background(), goAsk("mvl0frv18d1960")) + restore() + switch { + case c.transport: + if err == nil || !strings.HasPrefix(err.Error(), buildstep.TransportFaultWords) { + t.Errorf("%s: %v, want it opens with the transport fault's words", name, err) + } + case c.tries == 1: + if err == nil || p.tries != 1 || strings.Contains(err.Error(), buildstep.TransportFaultWords) { + t.Errorf("%s: %v after %d tries, want one try and no transport fault", name, err, p.tries) + } + case err != nil || p.tries != c.tries || len(p.inner.Asks()) != 1 || len(p.ids) != c.tries || p.ids[0] != p.ids[len(p.ids)-1]: + t.Errorf("%s: %v after %d tries under %v, %d asks taken, want %d tries under one id, one ask", name, err, p.tries, p.ids, len(p.inner.Asks()), c.tries) + } + } // Issue 1748 (ADR 0664 §3): a run that ended on a transport fault is no end; the next run's end is the answer, in either // arrival order; three runs then failed say a transport fault on 3 runs with each node; a bus that never gives the ask // again ends the wait saying so. @@ -320,3 +357,27 @@ type failingDrops struct{} func (failingDrops) DropAsk(context.Context, buildstep.StepAsk, string) error { return errors.New("no holder answered") } + +// faultyPuts fails its first puts with faults, then puts through inner (issue 1966). +type faultyPuts struct { + mu sync.Mutex + faults []error + tries int + ids []string + inner *FakeAsks +} + +func (p *faultyPuts) PublishAsk(ctx context.Context, subject, id string, data []byte) error { + p.mu.Lock() + p.tries++ + p.ids = append(p.ids, id) + var err error + if len(p.faults) > 0 { + err, p.faults = p.faults[0], p.faults[1:] + } + p.mu.Unlock() + if err != nil { + return err + } + return p.inner.PublishAsk(ctx, subject, id, data) +} diff --git a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder-tools/main.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder-tools/main.go index cc24d6ec..002ecd3d 100644 --- a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder-tools/main.go +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder-tools/main.go @@ -160,10 +160,11 @@ func Tools(r build.StuckReader, askAgain func(key string, value []byte) error, q {Name: build.BuildAgainTool, Description: "Build a failed key again (rebuild a module, build a failed key again): the builder writes the key of module and " + "fingerprint building as a new revision of the same key and asks the build seats, as it does by itself when it looks at a module " + - "again (ADR 0429 clause 18). Answers the new revision and the ask id of each build module (go, node, image). Refuses a key that " + - "is not failed, and says why: done (nothing to do), or waiting (building or queued: " + build.AskAgainTool + " asks its waiting asks " + - "again); a key failed for a reason the builder never retries on the same fingerprint (a pin missing, a version taken, digests that " + - "differ) and a fingerprint its module no longer has are refused too. Use it for a key builder_stuck does not show, which failed.", + "again (ADR 0429 clause 18). Answers the new revision and the ask id of each build module (go, node, image). Also takes a key left " + + "building that no look of the builder holds (its ask never put or its end never written, ADR 0668 §5): an ask the key names and " + + "its stream holds is waited for, one never put is put under its id. Refuses a key done (nothing to do) or queued (" + + build.AskAgainTool + " asks its waiting asks again), and one the builder is looking at now; a key failed for a reason the builder never retries on the same fingerprint (a pin missing, a version taken, digests that " + + "differ) and a fingerprint its module no longer has are refused too. Use it for a failed key, or one builder_stuck shows building with no ask or no step.", Input: map[string]any{"type": "object", "required": []string{"module", "fp", "why"}, "properties": map[string]any{ "module": map[string]any{"type": "string", "description": "the module's name"}, "fp": map[string]any{"type": "string", "description": "its new-form fingerprint, src2:"}, diff --git a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/findings.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/findings.go index 10b6bac1..b730238d 100644 --- a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/findings.go +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/findings.go @@ -82,12 +82,16 @@ func (f *findings) buildEnded(ctx context.Context, e builds.BuildLogEntry) { // raise writes fd; it is written again only when its words changed, so the keeper's condition moves only then. func (f *findings) raise(ctx context.Context, fd finding) { - o := meshconditionsclient.Observation{Scope: fd.scope, ID: fd.id, Kind: fd.kind, Severity: fd.severity, + f.raiseObservation(ctx, meshconditionsclient.Observation{Scope: fd.scope, ID: fd.id, Kind: fd.kind, Severity: fd.severity, Summary: fd.summary, Headline: fd.headline, Explanation: fd.explanation, Resolved: fd.resolved, Needs: fd.needs, - Source: "builder." + fd.kind} + Source: "builder." + fd.kind}) +} + +// raiseObservation writes o, as raise does. +func (f *findings) raiseObservation(ctx context.Context, o meshconditionsclient.Observation) { kv := f.bucket() if kv == nil { - f.logf("finding %s (not written, %s is not on the bus yet): %s", o.Key(), findingsBucket, fd.summary) + f.logf("finding %s (not written, %s is not on the bus yet): %s", o.Key(), findingsBucket, o.Summary) return } if _, err := meshconditionsclient.Raise(findingBucket{ctx, kv}, builds.BuilderModule, "", o, f.now()); err != nil { diff --git a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/main.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/main.go index 224b428b..5d40a676 100644 --- a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/main.go +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/main.go @@ -19,8 +19,10 @@ import ( "syscall" "time" + "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" sdkfindings "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient/findings" + "git.novox.be/novox/mesh-contracts/go/clients/nodeengineclient/enginereads" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-builder/buildrun" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-builder/builds/forms" @@ -186,6 +188,11 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro Stored: storedVia(calls.Call), Node: cred.Node, } + // A key a look left building because its end could not be written is call-unanswered past five minutes (issue 1966, + // ADR 0668 §3): its bound is a key of the state bounds. + unput := &unputs{bounds: pubBoundsKV.KV, store: b.Claimer.Store, looking: b.Looking, findings: found, + bound: meshconditionsclient.CallUnansweredAfter, now: time.Now, logf: logger.Printf} + b.Left, b.Ended = unput.left, unput.ended tagAsksKV := process.AwaitBucket(ctx, js, conn, versions.TagAsksBucket, "builder_tag and builder_untag are not answered", logger.Printf) // A check's build of a head a kept tag ask names numbers its packages tagged (design 51 *Tagged versions*), and the ask // is marked numbered with its versions. @@ -263,7 +270,8 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro watch.put = gate.Toolchain // What each counted node's engine reads (ADR 0618 §2, ADR 0624 §1): asked through the node-engine seat's verb as the // builder's own account, for every node the assignments names, and kept in the state engine-reads once it is bound. - reads := newEngineReads(calls.CallOn, gate, logger.Printf) + reads := newEngineReads(calls.CallKeptOn, gate, logger.Printf) + reads.keeper.Once = calls.CallOn // its fault keeps the last statement at once while the kept call asks on (ADR 0668 §3) // The old reference form's window over them (DLV-B9), kept in the state old-form once it is bound; builder_old_form // reads it and drops a retired node by hand. reads.ctx = context.WithoutCancel(ctx) @@ -287,6 +295,9 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro reads.stepWindow() }) gate.OnPlaced = reads.placed + // A kept manifest-reads call unanswered past five minutes, its node's machine heard (the watchdogs seat's presence, + // asked when the bound ends), is call-unanswered in the builder's findings (issue 1966, ADR 0668 §3, ADR 0596 §2). + reads.callsOf(found, pubBoundsKV.KV, heardBy(calls.CallKept), logger.Printf) b.Forms = reads.built // Until the assignments's first view is answered the gate passes every report on, as before the assignments is settled. assignmentsErrs := make(chan error, 1) @@ -351,6 +362,7 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro if err := hub.Handle("mesh.seat.*.event.>", events); err != nil { return err } + hub.OnBound(reads.atBind) // what a node's engine said before the consumer was bound (ADR 0668 §4) if stopped != nil { return stopped } @@ -395,6 +407,16 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro }) pubBoundsKV.Ready(func(kv jetstream.KeyValue) { each := func(e jetstream.KeyValueEntry) { + if _, ok := versions.UnputBoundOf(e.Key()); ok { + unput.expired(ctx, e) + return + } + if node, ok := enginereads.BoundOf(e.Key()); ok { + if e.Operation() == jetstream.KeyValuePurge { // its five minutes ended + reads.expiredCall(node) + } + return + } if versions.IsOldFormBound(e.Key()) { if e.Operation() == jetstream.KeyValuePurge { reads.stepWindow() // a node's seven days ended: the step raises old-form-held now diff --git a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/reads.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/reads.go index 4475e766..1cc99503 100644 --- a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/reads.go +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/reads.go @@ -4,6 +4,7 @@ import ( "context" "slices" "sync" + "time" "github.com/nats-io/nats.go/jetstream" @@ -33,12 +34,17 @@ type engineReads struct { // window is the old reference form's window over these statements (DLV-B9); nil keeps none. window *oldForm ctx context.Context + // calls is the wait of the kept calls (callsOf); nil weighs none. + calls *enginereads.ReadsCalls } -// newEngineReads asks through call (process.Conn.CallOn) and keeps each answer in the state once it is bound. +// newEngineReads asks through call (process.Conn.CallKeptOn, a kept call; ADR 0668) and keeps each answer in the state once it is bound. func newEngineReads(call enginereads.Caller, gate *buildrun.ToolchainGate, logf func(string, ...any)) *engineReads { r := &engineReads{gate: gate, keeper: &enginereads.Keeper{Call: call, Logf: logf}} - r.keeper.Changed = r.stepWindow + r.keeper.Changed = func() { + r.stepWindow() + r.stepCalls() + } return r } @@ -56,6 +62,28 @@ func (r *engineReads) stepWindow() { r.window.step(ctx, r.named(), counted) } +// stepCalls weighs the kept manifest-reads calls (enginereads.ReadsCalls): after a statement changed and the assignments's +// change. +func (r *engineReads) stepCalls() { + if r.calls != nil { + r.calls.Step(r.context()) + } +} + +// expiredCall weighs node's kept manifest-reads call when its bound ended (the key's expiry in the state bounds). +func (r *engineReads) expiredCall(node string) { + if r.calls != nil { + r.calls.Expired(r.context(), node) + } +} + +func (r *engineReads) context() context.Context { + if r.ctx == nil { + return context.Background() + } + return r.ctx +} + // named are the nodes the assignments names, none dropped: what the window's step judges a read by. func (r *engineReads) named() []string { r.mu.Lock() @@ -105,6 +133,17 @@ func (r *engineReads) placed() { } } r.stepWindow() + r.stepCalls() +} + +// atBind asks every counted node again when the builder's consumer is bound (the hub's OnBound): a manifest-reads-changed +// said before the consumer existed is not delivered to it, so the statement it would have ended is ended here (novox/hq +// ADR 0668 §4; issue 1966 note 155). +func (r *engineReads) atBind(created time.Time) { + r.mu.Lock() + nodes := slices.Clone(r.counted) + r.mu.Unlock() + r.keeper.AtBind(func() []string { return nodes })(created) } // heard takes an event of the builder's consumer on EVENTS: manifest-reads-changed asks its node again, and answers true. diff --git a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/readscall.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/readscall.go new file mode 100644 index 00000000..4217ca6b --- /dev/null +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/readscall.go @@ -0,0 +1,72 @@ +package main + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "time" + + "github.com/nats-io/nats.go/jetstream" + + "git.novox.be/novox/mesh-contracts/go/clients/nodeengineclient/enginereads" + mcc "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" + "git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshwatchdogs" + + "mesh-delivery-builder/internal/versions" +) + +// presenceInvoke is the watchdogs seat's verb presence as the manifest's invokes names it: whether a node's machine is +// heard, asked of the seat, never read from its holder's state (novox/hq ADR 0596 §2). +const presenceInvoke = "seat:" + meshwatchdogs.Seat + "." + meshwatchdogs.VerbPresence + +// heardBy asks the watchdogs seat's presence of one machine through call (process.Conn.CallKept, a read) and reads its +// declared answer: whether the machine is heard now. +func heardBy(call func(key string, body any) (json.RawMessage, error)) func(context.Context, string) (bool, error) { + return func(_ context.Context, machine string) (bool, error) { + raw, err := call(presenceInvoke, meshwatchdogs.PresenceInput{Machine: machine}) + if err != nil { + return false, err + } + var a meshwatchdogs.PresenceAnswer + if err := json.Unmarshal(raw, &a); err != nil { + return false, fmt.Errorf("%s does not read: %w", presenceInvoke, err) + } + return a.Online, nil + } +} + +// callsOf is the wait of the builder's kept manifest-reads calls (enginereads.ReadsCalls): a node whose engine has not +// answered for five minutes is, when its bound ends and the watchdogs seat says its machine is heard, the finding +// call-unanswered in the builder's findings (issue 1966, ADR 0668 §3); its bound is a key of the state bounds with its +// own time to live. +func (r *engineReads) callsOf(f *findings, bounds func() jetstream.KeyValue, heard func(context.Context, string) (bool, error), logf func(string, ...any)) *enginereads.ReadsCalls { + c := &enginereads.ReadsCalls{Keeper: r.keeper, Nodes: r.named, Heard: heard, Bound: mcc.CallUnansweredAfter, Logf: logf, + Raise: func(ctx context.Context, u enginereads.UnansweredCall) error { + o := mcc.CallUnanswered(enginereads.CallID(u.Node), enginereads.Invoke, u.Node, u.Words, "builder."+mcc.KindCallUnanswered, u.Since) + o.Needs = "builder_engine_reads with ask_again asks the node again now and shows its statement." + f.raiseObservation(ctx, o) + return nil + }, + Clear: func(ctx context.Context, node string) error { + f.clear(ctx, mcc.KindCallUnanswered, mcc.ScopeCall, enginereads.CallID(node)) + return nil + }, + Arm: func(ctx context.Context, node string, ends time.Time) error { + kv := bounds() + if kv == nil { + return errors.New(versions.BoundsBucket + " is not on the bus yet") + } + left := max(time.Until(ends), time.Second) + _, err := kv.Create(ctx, enginereads.BoundPrefix+node, versions.EncodeBound("the manifest-reads call to "+node, ends), jetstream.KeyTTL(left)) + if errors.Is(err, jetstream.ErrKeyExists) { + err = nil + } + return err + }} + if f != nil && f.now != nil { + c.Now = f.now + } + r.calls = c + return c +} diff --git a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/refused_test.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/refused_test.go index f4d30f13..78fbdfb7 100644 --- a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/refused_test.go +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/refused_test.go @@ -24,6 +24,7 @@ import ( "git.novox.be/novox/mesh-contracts/go/clients/nodeengineclient/enginereads" "git.novox.be/novox/mesh-contracts/go/seats/meshmoduleassigner" "git.novox.be/novox/mesh-contracts/go/seats/nodeengine" + "git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshwatchdogs" sweep "git.novox.be/novox/mesh-delivery/contracts/go/seats/meshartifactsweep" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-builder/buildrun" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-builder/builds" @@ -137,6 +138,56 @@ func theCountedNodesEngineReads(t *testing.T) { if _, err := tool.Run(map[string]any{"node": "n1", "drop": "true", "why": "a test"}); err != nil || st.v["n1"] != nil { t.Errorf("drop: %v, the key %s", err, st.v["n1"]) } + t.Run("ADR 0668 §3: a manifest-reads call unanswered past five minutes, its machine heard, is call-unanswered", func(t *testing.T) { + // n2 answers nothing: a bound is kept at five minutes and the watchdogs seat's presence is asked only when it ends + // (ADR 0596 §2), once; away, no finding; heard, the finding call-unanswered in the builder's findings at the + // builder's clock; answered, it is cleared. + place("n1", "n2") + now := time.Unix(1000, 0) + clock := func() time.Time { return now } + down := true + r2 := newEngineReads(func(node, _ string, _ any) (json.RawMessage, error) { + if down { + return nil, nats.ErrNoResponders + } + return json.Marshal(nodeengine.ManifestReadsAnswer{V: 1, Node: node, ManifestReads: []string{"form:new"}, StatedAt: now.Format(time.RFC3339Nano)}) + }, gate, t.Logf) + r2.keeper.Sync, r2.keeper.Now = true, clock + st := &memFindings{vals: map[string][]byte{}} + armed := map[string]time.Time{} + online, asked := false, []any{} + heard := heardBy(func(key string, body any) (json.RawMessage, error) { + asked = append(asked, key, body) + return json.Marshal(meshwatchdogs.PresenceAnswer{Machine: "n2", Online: online}) + }) + calls := r2.callsOf(&findings{store: st, logf: t.Logf, now: clock}, func() jetstream.KeyValue { return nil }, heard, t.Logf) + calls.Arm = func(_ context.Context, node string, ends time.Time) error { armed[node] = ends; return nil } + key := meshconditionsclient.Key(meshconditionsclient.ScopeCall, "manifest-reads.n2", meshconditionsclient.KindCallUnanswered) + r2.placed() // n2 asked, unanswered at 1000 + if len(st.vals) != 0 || len(asked) != 0 || !armed["n2"].Equal(time.Unix(1000, 0).Add(meshconditionsclient.CallUnansweredAfter)) { + t.Fatalf("before five minutes: findings %v, presence asked %v, bounds %v", st.vals, asked, armed) + } + now = now.Add(meshconditionsclient.CallUnansweredAfter) + r2.expiredCall("n2") + if len(st.vals) != 0 || len(asked) != 2 || asked[0] != presenceInvoke || asked[1] != (meshwatchdogs.PresenceInput{Machine: "n2"}) { + t.Fatalf("its machine away: findings %v, presence asked %v", st.vals, asked) + } + online = true + r2.expiredCall("n2") + f, err := meshconditionsclient.DecodeFinding(st.vals[key]) + if err != nil || f.Observer != builds.BuilderModule || f.Kind != meshconditionsclient.KindCallUnanswered || len(asked) != 4 { + t.Fatalf("heard five minutes on: finding %+v, %v (keys %v), presence asked %v", f, err, slices.Collect(maps.Keys(st.vals)), asked) + } + r2.stepCalls() + if len(st.vals) != 1 || len(asked) != 4 { + t.Errorf("a step after it: findings %v, presence asked %v", st.vals, asked) + } + down = false + r2.keeper.AskNode("n2", "answered now, its manifest-reads-changed heard") + if len(st.vals) != 0 { + t.Errorf("answered leaves %v", st.vals) + } + }) } func mustStatement(t *testing.T, s enginereads.Statement) []byte { @@ -391,6 +442,48 @@ func aFailedTrunkBuildIsAFinding(t *testing.T) { if !h.heard(context.Background(), published) || st.vals[refusedKey] != nil || st.vals[unansweredKey] != nil || st.vals[unreadKey] != nil { t.Fatalf("a later published leaves the findings: %v", st.vals) } + // Issue 1966 (ADR 0668 §3, §5; 1748 note 27): a key a look left building because its end could not be written arms its + // bound; the bound's end while the key is still building and no look holds it is call-unanswered about the key; the key's + // next written end deletes the bound and clears it; a key a look holds, or one no longer building, raises nothing; a + // bound that cannot be written raises at once. + buildKey := "m.1111111111111111111111111111111111111111111111111111111111111111" + building, _ := builds.EncodeBuilderBuild(builds.BuilderBuild{State: builds.BuildBuilding, By: "novox.builder", Step: "claimed"}) + done, _ := builds.EncodeBuilderBuild(builds.BuilderBuild{State: builds.BuildDone, By: "novox.builder", Step: "built"}) + keys := memBuilds{memVersions{buildKey: building}} + looking := false + unputMarks := &memBounds{keys: map[string]bool{}} + u := &unputs{bounds: func() jetstream.KeyValue { return unputMarks }, store: keys, looking: func(string) bool { return looking }, + findings: f, bound: meshconditionsclient.CallUnansweredAfter, now: func() time.Time { return time.Unix(600, 0) }, logf: t.Logf} + callKey := meshconditionsclient.Key(meshconditionsclient.ScopeCall, buildKey, meshconditionsclient.KindCallUnanswered) + u.left(context.Background(), buildKey, "nats: timeout") + if !unputMarks.keys[versions.UnputBoundKey(buildKey)] || st.vals[callKey] != nil { + t.Fatalf("a key left building: bound %v, finding %v; want the bound armed, no finding yet", unputMarks.keys, st.vals[callKey] != nil) + } + for name, c := range map[string]struct { + value []byte + look bool + }{"a look holds it": {building, true}, "no longer building": {done, false}} { + keys.memVersions[buildKey], looking = c.value, c.look + u.expired(context.Background(), purged{key: versions.UnputBoundKey(buildKey)}) + if st.vals[callKey] != nil { + t.Errorf("%s: the bound's end raised call-unanswered", name) + } + } + keys.memVersions[buildKey], looking = building, false + u.expired(context.Background(), purged{key: versions.UnputBoundKey(buildKey)}) + if got, err := meshconditionsclient.DecodeFinding(st.vals[callKey]); err != nil || got.Kind != meshconditionsclient.KindCallUnanswered || !strings.Contains(got.Summary, buildKey) || !strings.Contains(got.Needs, build.BuildAgainTool) { + t.Fatalf("the bound's end of a key left building: the finding = %+v, %v", got, err) + } + u.ended(context.Background(), buildKey) + if unputMarks.keys[versions.UnputBoundKey(buildKey)] || st.vals[callKey] != nil { + t.Errorf("the key's end written: bound %v, finding left %v", unputMarks.keys, st.vals[callKey] != nil) + } + u.bounds = func() jetstream.KeyValue { return nil } + u.left(context.Background(), buildKey, "nats: timeout") + if got, err := meshconditionsclient.DecodeFinding(st.vals[callKey]); err != nil || !strings.Contains(got.Explanation, "nor its bound") { + t.Fatalf("a bound not written: the finding = %+v, %v", got, err) + } + delete(st.vals, callKey) // ADR 0615 §5 (review round 1): a consumer not there yet is family-not-heard naming its stream, cleared when it binds. notHeard := f.notHeard(context.Background()) unheardKey := heard.Key(builds.BuilderModule, "FORGE") @@ -414,6 +507,18 @@ func aFailedTrunkBuildIsAFinding(t *testing.T) { said: func(b versions.OldFormClosedBody) { closings = append(closings, b) }, log: func(e builds.BuildLogEntry) { logged = append(logged, e) }} reads := &engineReads{keeper: &enginereads.Keeper{}, window: window, counted: []string{"a", "b"}} + // Issue 1966 note 155, ADR 0668 §4: at the consumer's bind every counted node is called once again. + var boundCalls []string + reads.keeper.Sync = true + reads.keeper.Call = func(node, _ string, _ any) (json.RawMessage, error) { + boundCalls = append(boundCalls, node) + return nil, errors.New("not served") + } + reads.atBind(now) + if !slices.Equal(boundCalls, []string{"a", "b"}) { + t.Fatalf("at the bind called %v, want every counted node once", boundCalls) + } + reads.keeper = &enginereads.Keeper{} newest := []string{forms.FormNeed("oci")} counted := map[string][]string{"a": newest, "b": nil} window.step(context.Background(), []string{"a", "b"}, counted) @@ -478,6 +583,13 @@ func (m memVersions) KeysOf(context.Context, string) ([]string, error) { return slices.Collect(maps.Keys(m)), nil } +// memBuilds is the builder's builds in memory. +type memBuilds struct{ memVersions } + +func (m memBuilds) Keys(context.Context) ([]string, error) { + return slices.Collect(maps.Keys(m.memVersions)), nil +} + // memBounds is the state bounds in memory: which keys stand. type memBounds struct { jetstream.KeyValue diff --git a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/unput.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/unput.go new file mode 100644 index 00000000..55c9ccab --- /dev/null +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/unput.go @@ -0,0 +1,84 @@ +package main + +import ( + "context" + "errors" + "fmt" + "time" + + "github.com/nats-io/nats.go/jetstream" + + "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" + "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-builder/builds" + + "mesh-delivery-builder/internal/build" + "mesh-delivery-builder/internal/versions" +) + +// **A key left building unput is a finding after five minutes** (issue 1966, 1748 note 27; novox/hq ADR 0668 §3, §5). A +// look whose end could not be written leaves its key building with no look holding it: its ask put or not, nothing ends +// it but builder_build_again or the builder's next start. The look arms a key of the state bounds (UnputBoundKey) with +// its own time to live; the bus's marker of its end, heard on the watch, raises call-unanswered about the build key while +// the key is still building and no look holds it. The key's next written end deletes the bound and clears the finding. +// No timer. +type unputs struct { + bounds func() jetstream.KeyValue + store build.Store + looking func(key string) bool + findings *findings + bound time.Duration + now func() time.Time + logf func(string, ...any) +} + +// unputCallee is what the finding names as the call left unanswered: the build seats' put of the key's asks and the +// builder's write of its end. +const unputCallee = "the put of its asks on the build seats and the write of its end" + +// left arms key's bound; one that cannot be written would never end, so the finding is raised at once. +func (u *unputs) left(ctx context.Context, key, why string) { + var err error + if kv := u.bounds(); kv == nil { + err = fmt.Errorf("%s is not on the bus yet", versions.BoundsBucket) + } else if _, err = kv.Create(ctx, versions.UnputBoundKey(key), versions.EncodeBound("the build key "+key+" left building unput: "+why, u.now().Add(u.bound)), jetstream.KeyTTL(u.bound)); errors.Is(err, jetstream.ErrKeyExists) { + err = nil + } + if err == nil { + return + } + u.logf("the unput bound of %s is not written, so it is raised now: %v", key, err) + u.raise(ctx, key, fmt.Sprintf("its end could not be written (%s), nor its bound (%v)", why, err), u.now()) +} + +// ended deletes key's bound and clears its finding: its end was written. +func (u *unputs) ended(ctx context.Context, key string) { + if kv := u.bounds(); kv != nil { + if err := kv.Delete(ctx, versions.UnputBoundKey(key)); err != nil && !errors.Is(err, jetstream.ErrKeyNotFound) { + u.logf("the unput bound of %s is not deleted: %v", key, err) + } + } + u.findings.clear(ctx, meshconditionsclient.KindCallUnanswered, meshconditionsclient.ScopeCall, key) +} + +// expired is told each change of the state bounds: the end of an unput bound raises call-unanswered while its key is +// still building and no look holds it. +func (u *unputs) expired(ctx context.Context, e jetstream.KeyValueEntry) { + key, ok := versions.UnputBoundOf(e.Key()) + if !ok || e.Operation() != jetstream.KeyValuePurge || u.looking(key) { + return + } + raw, _, found, err := u.store.Get(ctx, key) + if err != nil || !found { + return + } + if v, err := builds.DecodeBuilderBuild(raw); err != nil || v.State != builds.BuildBuilding { + return + } + u.raise(ctx, key, fmt.Sprintf("its look ended without writing its end, and nothing ended it within %s", u.bound), u.now().Add(-u.bound)) +} + +func (u *unputs) raise(ctx context.Context, key, fault string, since time.Time) { + o := meshconditionsclient.CallUnanswered(key, unputCallee, "", fault, "builder."+meshconditionsclient.KindCallUnanswered, since) + o.Needs = build.BuildAgainTool + " builds the key again: an ask its stream holds is waited for, one never put is put; " + build.StuckTool + " shows it." + u.findings.raiseObservation(ctx, o) +} diff --git a/modules/mesh-delivery-builder/internal/build/buildagain.go b/modules/mesh-delivery-builder/internal/build/buildagain.go index 6f39187e..2c135769 100644 --- a/modules/mesh-delivery-builder/internal/build/buildagain.go +++ b/modules/mesh-delivery-builder/internal/build/buildagain.go @@ -84,7 +84,8 @@ func (b *Builder) handEnded(key string) { // BuildAgain builds the failed key of module at fp again, as the builder does by itself: the key is written building as a // new revision and the build module asks are put on the build seats. It answers once the asks are put, or at bound. A key -// that is not failed is refused with why: done (nothing to do) or waiting (builder_ask_again asks its waiting asks again). +// left building that no look of this builder holds is taken as it stands and its asks put if they never were (issue 1966). +// A key done or queued is refused with why: done (nothing to do) or waiting (builder_ask_again asks its waiting asks again). // ctx is the builder's own context: the build it starts lives on it. func (b *Builder) BuildAgain(ctx context.Context, module, fp, why, by string, bound time.Duration) BuildAgainResult { b.init() @@ -106,8 +107,12 @@ func (b *Builder) BuildAgain(ctx context.Context, module, fp, why, by string, bo switch { case cur.State == builds.BuildDone: return BuildAgainResult{Refused: fmt.Sprintf("%s is done: nothing to do", key)} - case cur.State == builds.BuildBuilding || cur.State == builds.BuildQueued: + case cur.State == builds.BuildQueued: return BuildAgainResult{Refused: fmt.Sprintf("%s is waiting (%s: %s): %s asks its waiting asks again", key, cur.State, cur.Step, AskAgainTool)} + case cur.State == builds.BuildBuilding: + // A key left building that no look of this builder holds (refused below when one does): its put or its end was never + // written (issue 1966, 1748 note 27: "building, claimed", no ask). It is taken as it stands, an ask it names and the + // stream holds is waited for, one never put is put under its id, one never named is asked (ADR 0668 §5). case cur.State != builds.BuildFailed: return BuildAgainResult{Refused: fmt.Sprintf("%s is %q, not failed", key, cur.State)} case builds.FailedUntilChanged(cur.Error) || strings.HasPrefix(cur.Error, buildrun.DigestsDifferPrefix): @@ -139,7 +144,11 @@ func (b *Builder) BuildAgain(ctx context.Context, module, fp, why, by string, bo } b.mu.Unlock() }() - b.logf("%s: failed (%s); built again by hand, asked by %s: %s", key, cur.Error, by, why) + if cur.State == builds.BuildBuilding { + b.logf("%s: left building (%s) with no look of this builder; built again by hand, asked by %s: %s", key, cur.Step, by, why) + } else { + b.logf("%s: failed (%s); built again by hand, asked by %s: %s", key, cur.Error, by, why) + } b.startOnce(ctx, key, module, m) wait, stop := context.WithTimeout(ctx, bound) // a context's bound for a person's answer (ADR 0437 §8) defer stop() diff --git a/modules/mesh-delivery-builder/internal/build/claim_test.go b/modules/mesh-delivery-builder/internal/build/claim_test.go index 04b68925..eeda081f 100644 --- a/modules/mesh-delivery-builder/internal/build/claim_test.go +++ b/modules/mesh-delivery-builder/internal/build/claim_test.go @@ -18,6 +18,8 @@ type memStore struct { writes int // before runs once ahead of the next write, so a test changes the key under the writer. before func() + // faults fail the next updates, one each, writing nothing (a deadline met on the bus). + faults []error } func newMem() *memStore { return &memStore{vals: map[string][]byte{}, revs: map[string]uint64{}} } @@ -67,6 +69,11 @@ func (m *memStore) Update(_ context.Context, key string, value []byte, rev uint6 m.mu.Lock() defer m.mu.Unlock() m.hook() + if len(m.faults) > 0 { + err := m.faults[0] + m.faults = m.faults[1:] + return 0, err + } if _, ok := m.vals[key]; !ok || m.revs[key] != rev { return 0, ErrConflict } diff --git a/modules/mesh-delivery-builder/internal/build/run.go b/modules/mesh-delivery-builder/internal/build/run.go index 8b74d448..a7711f09 100644 --- a/modules/mesh-delivery-builder/internal/build/run.go +++ b/modules/mesh-delivery-builder/internal/build/run.go @@ -21,6 +21,7 @@ import ( "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-builder/builds/forms" sdkstep "git.novox.be/novox/mesh-delivery/sdk/buildstep" repotrunk "git.novox.be/novox/mesh-delivery/sdk/trunk" + "git.novox.be/novox/mesh-sdk/go/busretry" "git.novox.be/novox/mesh-sdk/go/catalogue" "mesh-delivery-builder/internal/versions" @@ -52,6 +53,11 @@ type Builder struct { } Toolchains ToolchainEntries Manifests Manifests + // Left, when set, is told a key a look claimed and left building because its end could not be written (issue 1966, + // novox/hq ADR 0668 §3; 1748 note 27): no look holds it then, so nothing ends it but builder_build_again or the + // builder's next start. Ended is told each key whose end was written. + Left func(ctx context.Context, key, why string) + Ended func(ctx context.Context, key string) // Limit is how many builds the builder has asked at once; their asks wait in the build seats' streams, which are the // backlog (ADR 0525 §9), not here. 256 when 0. Limit int @@ -131,6 +137,14 @@ type planned struct { err error } +// Looking says a look of this builder holds key now, by itself or asked by hand. +func (b *Builder) Looking(key string) bool { + b.init() + b.mu.Lock() + defer b.mu.Unlock() + return b.inflight[key] || b.hands[key] != nil +} + func (b *Builder) init() { b.once.Do(func() { limit := b.Limit @@ -477,7 +491,9 @@ func (b *Builder) try(ctx context.Context, module string, m meshcatalog.ModulesB return } } - cl, err := b.Claimer.Claim(ctx, module, m.Fp2, m.Manifest, ClaimOptions{TakeOver: first, ByHand: byHand, ImageBuilder: imageSeat, Trunk: trunk, Published: b.isPublished, + // A key built again by hand is taken over as it stands too: one left building by a look that ended without its write + // (issue 1966) is the hand tool's to finish. + cl, err := b.Claimer.Claim(ctx, module, m.Fp2, m.Manifest, ClaimOptions{TakeOver: first || byHand, ByHand: byHand, ImageBuilder: imageSeat, Trunk: trunk, Published: b.isPublished, Stored: b.storedOnce(key)}) if err != nil { b.logf("%s: %v", module, err) @@ -548,8 +564,14 @@ func (b *Builder) try(ctx context.Context, module string, m meshcatalog.ModulesB } if err := b.Claimer.Finish(ctx, cl, result); err != nil { b.logf("%s: the build could not be written: %v", cl.Key, err) + if b.Left != nil && !errors.Is(err, ErrConflict) && ctx.Err() == nil { + b.Left(ctx, cl.Key, err.Error()) // left building with no look holding it (issue 1966) + } return } + if b.Ended != nil { + b.Ended(ctx, cl.Key) + } ended := LogEnded(module, m, b.refOf(module, m.Fp2), b.Node, b.now(), result) ended.OutOfStep = b.takeOutOfStep(key) // the generated files the build module's compare found out of step (design 26) b.logBuild(ended) @@ -924,7 +946,13 @@ func (b *Builder) runLane(ctx context.Context, l *lane, repository string, m mes } } else { if err := asked.note(ctx, language, ask.ID, "asked "+l.module); err != nil { - l.err = fmt.Errorf("the ask of %s could not be written to the key: %w", l.module, err) + // The note and the put are one act (novox/hq ADR 0668 §1; issue 1748 note 27): a note a transport fault kept from + // the key fails the key with that fault's words, which builder_build_again takes (ADR 0664 §3). + fault := "" + if busretry.TimedOut(err) || busretry.Undelivered(err) { + fault = sdkstep.TransportFaultWords + "the note of the ask: " + } + l.err = fmt.Errorf("%sthe ask of %s could not be written to the key: %w", fault, l.module, err) return } if err := b.Asks.Put(ctx, ask); err != nil { diff --git a/modules/mesh-delivery-builder/internal/build/run_test.go b/modules/mesh-delivery-builder/internal/build/run_test.go index b4620e5b..cfc3ad9b 100644 --- a/modules/mesh-delivery-builder/internal/build/run_test.go +++ b/modules/mesh-delivery-builder/internal/build/run_test.go @@ -981,6 +981,8 @@ func TestABuildAskWaitingInItsStreamIsNotBounded(t *testing.T) { failed string // during is a look of the builder's own at the module while the by-hand build runs: it still runs afterwards. during bool + // standing is a key taken as it stands (left building): its claim is the key's own revision, not a new one. + standing bool }{ {name: "build again: a look the builder queued during the by-hand build still runs afterwards", again: true, during: true, key: &builds.BuilderBuild{State: builds.BuildFailed, Error: "ace: no tun"}}, @@ -1002,8 +1004,16 @@ func TestABuildAskWaitingInItsStreamIsNotBounded(t *testing.T) { key: &builds.BuilderBuild{State: builds.BuildFailed, Error: "ace: the step failed: no tun"}}, {name: "build again: a done key is refused, nothing to do", again: true, refuse: "is done: nothing to do", key: &builds.BuilderBuild{State: builds.BuildDone, Step: "built"}}, - {name: "build again: a building key is refused, builder_ask_again is for it", again: true, refuse: "is waiting", - key: &builds.BuilderBuild{State: builds.BuildBuilding, By: "novox.builder", Step: "asked mesh-build-go", Asks: map[string]string{buildstep.AskGo: "mvl0frv18d1960"}}}, + {name: "build again: a queued key is refused, builder_ask_again is for it", again: true, refuse: "is waiting", + key: &builds.BuilderBuild{State: builds.BuildQueued, By: "novox.builder", Step: "waits for the package x", Waits: "x@v1.0.0"}}, + // Issue 1966 (ADR 0668 §5; 1748 note 27): a key left building with no ask, no look of the builder holding it, is taken as + // it stands, by this builder or from another, asked and done; one a look holds is refused. + {name: "build again: a key left building claimed and unasked is asked and done", again: true, standing: true, + key: &builds.BuilderBuild{State: builds.BuildBuilding, By: "novox.builder", Step: "claimed"}}, + {name: "build again: a key another builder left building unasked is taken over", again: true, standing: true, + key: &builds.BuilderBuild{State: builds.BuildBuilding, By: "ace.builder", Step: "claimed"}}, + {name: "build again: a key left building that a look holds is refused", again: true, refuse: "is being looked at", busy: 1, + key: &builds.BuilderBuild{State: builds.BuildBuilding, By: "novox.builder", Step: "claimed"}}, {name: "build again: a key failed for a pin missing is refused, it waits for another fingerprint", again: true, refuse: "does not retry", key: &builds.BuilderBuild{State: builds.BuildFailed, Error: builds.NotPinned + "web"}}, {name: "build again: a key with no build is refused", again: true, refuse: "has no build key"}, @@ -1047,6 +1057,9 @@ func TestABuildAskWaitingInItsStreamIsNotBounded(t *testing.T) { r.b.hands[r.key] = &handWatch{} } r.b.known["m"] = m // the builder has read the modules value, and looks at nothing until asked + if c.standing { + r.b.tried[r.key] = true // its look of the key ended before its write: a later look takes over nothing by itself + } log := &logged{} r.b.Logf = log.logf res := r.b.BuildAgain(context.Background(), "m", fp1, "no tun on ace", "shanks.lead", 2*time.Second) @@ -1075,7 +1088,7 @@ func TestABuildAskWaitingInItsStreamIsNotBounded(t *testing.T) { return } asks := r.asks.Asks() - if res.Refused != "" || res.Pending != "" || res.Revision <= rev || len(asks) != 1 || res.Asks[buildstep.AskGo] != asks[0].ID { + if res.Refused != "" || res.Pending != "" || res.Revision < rev || (res.Revision == rev && !c.standing) || len(asks) != 1 || res.Asks[buildstep.AskGo] != asks[0].ID { t.Fatalf("answer %+v after %d asks; want the new revision (was %d) and the ask id of the one ask", res, len(asks), rev) } if v := valueOf(t, r.st, r.key); v.State != builds.BuildDone || after <= res.Revision { @@ -1350,6 +1363,41 @@ func TestAnAskTheKeyNamesAndNobodyPutIsPutAtStart(t *testing.T) { t.Errorf("held %v: the key = %+v, want done", held, v) } } + // Issue 1966 (ADR 0668 §1, §5; 1748 note 27): the note of the ask and its put are one act. A note a deadline kept from the + // key fails the key in the transport fault's words: the builder does not take it again by itself (ADR 0664 §3), and + // builder_build_again builds it. + r := newRig(t, goBundle) + r.st.faults = []error{fmt.Errorf("the key: %w", context.DeadlineExceeded)} + if v := r.consider(t, "modules/m"); v.State != builds.BuildFailed || !builds.FailedOnTransportFault(v.Error) || len(r.asks.Asks()) != 0 { + t.Fatalf("a note the bus did not answer: the key = %+v after %d asks, want failed on a transport fault, nothing put", v, len(r.asks.Asks())) + } + if v := r.consider(t, "modules/m"); v.State != builds.BuildFailed || len(r.asks.Asks()) != 0 { + t.Fatalf("looked at again by itself: the key = %+v after %d asks, want it left failed", v, len(r.asks.Asks())) + } + if res := r.b.BuildAgain(context.Background(), "m", fp1, "the bus was back", "shanks.lead", 2*time.Second); res.Refused != "" || len(r.asks.Asks()) != 1 { + t.Fatalf("built again by hand: %+v after %d asks", res, len(r.asks.Asks())) + } + r.b.Wait() + if v := valueOf(t, r.st, r.key); v.State != builds.BuildDone { + t.Errorf("built again by hand: the key = %+v, want done", v) + } + // Its end not written either (1748 note 27's key: building, claimed, no ask): the look tells Left, and no look holds the + // key; built again by hand it is asked and done, and Ended is told. + r = newRig(t, goBundle) + r.st.faults = []error{context.DeadlineExceeded, context.DeadlineExceeded} + var left, ended []string + r.b.Left = func(_ context.Context, key, why string) { left = append(left, key+": "+why) } + r.b.Ended = func(_ context.Context, key string) { ended = append(ended, key) } + if v := r.consider(t, "modules/m"); v.State != builds.BuildBuilding || v.Step != "claimed" || len(v.Asks) != 0 || len(left) != 1 || !strings.HasPrefix(left[0], r.key) || len(ended) != 0 || r.b.Looking(r.key) { + t.Fatalf("an end not written: the key = %+v, left %q, ended %q, looking %v", v, left, ended, r.b.Looking(r.key)) + } + if res := r.b.BuildAgain(context.Background(), "m", fp1, "left building", "shanks.lead", 2*time.Second); res.Refused != "" { + t.Fatalf("built again by hand: %+v", res) + } + r.b.Wait() + if v := valueOf(t, r.st, r.key); v.State != builds.BuildDone || len(r.asks.Asks()) != 1 || len(ended) != 1 { + t.Errorf("built again by hand: the key = %+v after %d asks, ended %q", v, len(r.asks.Asks()), ended) + } } // unreadableHeld cannot tell whether an ask is held. diff --git a/modules/mesh-delivery-builder/internal/versions/publish.go b/modules/mesh-delivery-builder/internal/versions/publish.go index d185f6bf..7b401b8a 100644 --- a/modules/mesh-delivery-builder/internal/versions/publish.go +++ b/modules/mesh-delivery-builder/internal/versions/publish.go @@ -19,8 +19,8 @@ import ( // heard on the watch, is what raises publish-unanswered while the version is still numbered. No timer. const ( // BoundsState is the builder's state of its expiring keys, each with its own time to live: a publish's bound - // (PublishBoundKey) and a node's seven days holding the old form's window (OldFormBoundKey). Its end, the bus's - // marker heard on the watch, is what acts. + // (PublishBoundKey), a node's seven days holding the old form's window (OldFormBoundKey) and a build key left + // building unput (UnputBoundKey). Its end, the bus's marker heard on the watch, is what acts. BoundsState = "bounds" BoundsBucket = "mesh-delivery-builder_bounds" // PublishBound is the build module's own wait for the holder's word (design 51 *How a publish ends*: at most @@ -36,8 +36,17 @@ const ( const ( publishBoundPrefix = "publish." oldFormBoundPrefix = "old-form." + unputBoundPrefix = "unput." ) +// UnputBoundKey is the bound of a build key a look left building because its end could not be written (issue 1966, +// novox/hq ADR 0668 §3): `unput.`. Its end while the key still stands so, with no look holding it, is the +// finding call-unanswered about the key. +func UnputBoundKey(buildKey string) string { return unputBoundPrefix + buildKey } + +// UnputBoundOf is the build key an unput bound names, and whether key is one. +func UnputBoundOf(key string) (string, bool) { return strings.CutPrefix(key, unputBoundPrefix) } + // PublishBoundKey is the bound of name's version: `publish.`. func PublishBoundKey(name, version string) string { return publishBoundPrefix + Key(name, version) } @@ -58,7 +67,8 @@ const BoundsTool = "builder_bounds" // BoundsDescription is builder_bounds' description. const BoundsDescription = "The builder's expiring keys, its state " + BoundsState + " (design 51 *Health and conditions*): each key with what it " + "bounds (a version's publish, whose end unanswered is the finding " + PublishUnanswered + "; or a node's seven days holding the old " + - "form's window, whose end is the finding " + OldFormHeld + "), when it ends, and how long is left. The bus ends each key by its own time to live." + "form's window, whose end is the finding " + OldFormHeld + "; or a build key left building because its end could not be written, " + + "whose end is the finding call-unanswered), when it ends, and how long is left. The bus ends each key by its own time to live." // Bound is a key's value in BoundsState: what it bounds, in plain words, and when it ends. type Bound struct { diff --git a/modules/mesh-delivery-builder/manifest_test.go b/modules/mesh-delivery-builder/manifest_test.go index 6e883afc..dae603fa 100644 --- a/modules/mesh-delivery-builder/manifest_test.go +++ b/modules/mesh-delivery-builder/manifest_test.go @@ -101,7 +101,8 @@ func TestManifestDeclarations(t *testing.T) { // 1607/AC1 t.Errorf("state = %+v, want %+v", m.State, want) } // 1887/A4c: the builder chooses no node, so it reads neither presence nor have, invokes no build module's tool and - // holds no capacity; it puts asks on the three build seats and reads their steps (ADR 0525 §1, §4, §5). + // holds no capacity; it puts asks on the three build seats and reads their steps (ADR 0525 §1, §4, §5). Whether a + // node's machine is heard it asks the watchdogs seat's presence (issue 1966, ADR 0596 §2, ADR 0668 §3). if want := []string{"mesh-build-go.steps", "mesh-build-go.toolchains", "mesh-build-image.steps", "mesh-build-node.steps", "mesh-build-node.toolchains", "mesh-delivery-assigner.assignments", "mesh-delivery-gate.source"}; !reflect.DeepEqual(sorted(m.Reads), want) { t.Errorf("reads = %v, want %v", m.Reads, want) @@ -123,9 +124,10 @@ func TestManifestDeclarations(t *testing.T) { // 1607/AC1 } } // Design 51 *The floor*: the floor's three sources, the registry seats' versions, bridge_tags and indexer_requirements. + // The watchdogs seat's presence says a node's machine is heard (issue 1966, ADR 0596 §2, ADR 0668 §3). if want := []string{"mesh-delivery-assigner.assigner_read_assignments", "mesh-delivery-forge-bridge.bridge_tags", "mesh-delivery-indexer.indexer_read_candidates", "mesh-delivery-indexer.indexer_read_manifests", "mesh-delivery-indexer.indexer_read_modules", "mesh-delivery-indexer.indexer_read_packages", "mesh-delivery-indexer.indexer_requirements", "seat:container-image-registry.remove", "seat:container-image-registry.versions", - "seat:go-package-registry.remove", "seat:go-package-registry.versions", "seat:mesh-artifact-sweep.held", "seat:mesh-hand-acts.hand-act", "seat:node-build-go.drop", "seat:node-build-image.drop", "seat:node-build-node.drop", "seat:node-engine.manifest-reads", "seat:npm-package-registry.remove", + "seat:go-package-registry.remove", "seat:go-package-registry.versions", "seat:mesh-artifact-sweep.held", "seat:mesh-hand-acts.hand-act", "seat:mesh-watchdogs.presence", "seat:node-build-go.drop", "seat:node-build-image.drop", "seat:node-build-node.drop", "seat:node-engine.manifest-reads", "seat:npm-package-registry.remove", "seat:npm-package-registry.versions", "seat:oci-artifact-registry.remove", "seat:oci-artifact-registry.versions"}; !reflect.DeepEqual(sorted(m.Invokes), want) || len(m.Config) != 0 { t.Errorf("invokes = %v, config = %v, want %v and no config", m.Invokes, m.Config, want) } diff --git a/modules/mesh-delivery-builder/module.json b/modules/mesh-delivery-builder/module.json index 2f4140d0..9ab32e47 100644 --- a/modules/mesh-delivery-builder/module.json +++ b/modules/mesh-delivery-builder/module.json @@ -67,6 +67,7 @@ "seat:go-package-registry.versions", "seat:mesh-artifact-sweep.held", "seat:mesh-hand-acts.hand-act", + "seat:mesh-watchdogs.presence", "seat:node-build-go.drop", "seat:node-build-image.drop", "seat:node-build-node.drop", diff --git a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/bridgemessage.go b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/bridgemessage.go index 1bf9196e..f99bb36a 100644 --- a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/bridgemessage.go +++ b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/bridgemessage.go @@ -34,3 +34,11 @@ func messageVia(call toolCaller) func(ctx context.Context, repository, merge str return a.Message, nil } } + +// unreadAgain reads again, after a message heard on FORGE, a pending merge whose message was unread for a transport fault +// (index.Indexer.UnreadAgain; issue 1966 note 153): the forge is heard again, so the bridge is asked again. A failure is said. +func unreadAgain(ctx context.Context, ix *index.Indexer, logger interface{ Printf(string, ...any) }) { + if err := ix.UnreadAgain(ctx); err != nil { + logger.Printf("take-in: a merge unread for a transport fault is not read again after this message: %v", err) + } +} diff --git a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/integration_test.go b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/integration_test.go index a9e3c7c8..ce7132fd 100644 --- a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/integration_test.go +++ b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/integration_test.go @@ -87,7 +87,7 @@ func TestIndexerWhole(t *testing.T) { // 1238/AC2, AC10; 1585/T14, T15 // The states and the stream the controller makes from the indexer's manifest (old sections, ADR 0595 §11). for bucket, history := range map[string]uint8{index.PendingBucket: 1, index.VerdictsBucket: index.VerdictsHistory, index.GraphBucket: 1, index.TakenBucket: 1, index.PackagesBucket: 1, - index.SeatDefinitionsBucket: 1, index.RequirementsBucket: 1, findingsBucket: 1, index.HoldsBucket: 1} { + index.SeatDefinitionsBucket: 1, index.RequirementsBucket: 1, findingsBucket: 1, index.HoldsBucket: 1, index.UnjudgedBucket: 1} { if _, err := js.CreateKeyValue(ctx, jetstream.KeyValueConfig{Bucket: bucket, History: history}); err != nil { t.Fatal(err) } @@ -662,8 +662,9 @@ func TestIndexerKeepsManifestsAtAMerge(t *testing.T) { // 1444/AC4, 1449/AC4, 15 js, ctx, _, modules := startIndexer(t, func(ctx context.Context, builds buildLog) { builds.end(t, "novox/mesh-catalog", "avahi", "modules/avahi") }, func(ctx context.Context, js jetstream.JetStream) { - // The verdicts state and the stream of the indexer's events, as the controller makes them from its manifest. - if _, err := js.CreateKeyValue(ctx, jetstream.KeyValueConfig{Bucket: index.VerdictsBucket, History: index.VerdictsHistory}); err != nil { + // The indexer's state unjudged, as the controller makes it from its manifest; the verdicts state is made only once + // the merge is taken in (issue 1966 note 154: a take-in at the start, before the verdicts state's bind). + if _, err := js.CreateKeyValue(ctx, jetstream.KeyValueConfig{Bucket: index.UnjudgedBucket, History: 1}); err != nil { t.Fatal(err) } }) @@ -707,7 +708,20 @@ func TestIndexerKeepsManifestsAtAMerge(t *testing.T) { // 1444/AC4, 1449/AC4, 15 t.Errorf("manifest = %+v err %v, want avahi and the file's bytes", got, err) } - verdicts, err := js.KeyValue(ctx, index.VerdictsBucket) + // 1966 (ADR 0668 §4, note 154): the take-in wrote its four manifests with no verdicts state on the bus, so it keeps + // them in its state unjudged; when the verdicts state binds, each is judged as new (bad refused in full, never as a + // warning), every accepted one is said as manifest-accepted, and the state is left empty. + unjudged, err := js.KeyValue(ctx, index.UnjudgedBucket) + if err != nil { + t.Fatal(err) + } + kept, _ := unjudged.Keys(ctx) + for _, raw := range []string{string(manifest), judged["good"], judged["bad"], judged["later"]} { + if !slices.Contains(kept, meshcatalogclient.ManifestDigest([]byte(raw))) { + t.Errorf("the take-in's new manifest %s is not kept unjudged: the state holds %v", meshcatalogclient.ManifestDigest([]byte(raw)), kept) + } + } + verdicts, err := js.CreateKeyValue(ctx, jetstream.KeyValueConfig{Bucket: index.VerdictsBucket, History: index.VerdictsHistory}) if err != nil { t.Fatal(err) } @@ -732,12 +746,20 @@ func TestIndexerKeepsManifestsAtAMerge(t *testing.T) { // 1444/AC4, 1449/AC4, 15 if !strings.Contains(strings.Join(got["bad"].Problems, " "), `provides "amqp"`) || strings.Join(got["later"].Unknown, " ") != "a-field-from-later" { t.Errorf("the refusal names no problem or the wait no field: %+v", got) } + // The pass ends the state's keys after it wrote and said every verdict. + left, _ := unjudged.Keys(ctx) + for deadline := time.Now().Add(10 * time.Second); len(left) != 0 && time.Now().Before(deadline); time.Sleep(50 * time.Millisecond) { + left, _ = unjudged.Keys(ctx) + } + if len(left) != 0 { + t.Errorf("the state unjudged still holds %v within 10 s, once every manifest has its verdict", left) + } // manifest-refused, said once for each refusal (a wait is no refusal). events, err := js.Stream(ctx, "EVENTS") if err != nil { t.Fatal(err) } - said := map[string]bool{} + said, acceptedSaid := map[string]bool{}, map[string]bool{} for seq := uint64(1); ; seq++ { msg, err := events.GetMsg(ctx, seq) if err != nil { @@ -747,10 +769,17 @@ func TestIndexerKeepsManifestsAtAMerge(t *testing.T) { // 1444/AC4, 1449/AC4, 15 if msg.Subject == "mesh.seat.mesh-catalog.event."+meshcatalog.EventManifestRefused && json.Unmarshal(msg.Data, &r) == nil { said[r.Module] = true } + var a meshcatalog.ManifestAcceptedEvent + if msg.Subject == "mesh.seat.mesh-catalog.event."+meshcatalog.EventManifestAccepted && json.Unmarshal(msg.Data, &a) == nil { + acceptedSaid[a.Module] = true + } } if !said["bad"] || said["later"] || said["good"] { t.Errorf("manifest-refused said for %v, want bad only", said) } + if !acceptedSaid["good"] || acceptedSaid["bad"] || acceptedSaid["later"] { + t.Errorf("manifest-accepted said for %v, want good and no refused or waiting one", acceptedSaid) + } // How a composer holds a refused module by these verdicts is the node-engine's to test (ADR 0593 §7: the composer // and its bus reader are its own). } diff --git a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/main.go b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/main.go index 00ef9a3d..abd61bd5 100644 --- a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/main.go +++ b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/main.go @@ -415,6 +415,9 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro // The module graph (ADR 0603 §2): a state this delivery brings, bound when it appears; until then no graph is written. graph := process.AwaitBucket(ctx, js, conn, index.GraphBucket, "no module graph is written", logger.Printf) ownBuildState := process.AwaitBucket(ctx, js, conn, index.OwnBuildBucket, "which build this indexer runs is not kept", logger.Printf) + // The manifests a take-in wrote and no judge pass judged yet (issue 1966): a state this delivery brings, bound when it + // appears; until then a take-in's new manifests are kept for their judging in its memory alone. + unjudged := process.AwaitBucket(ctx, js, conn, index.UnjudgedBucket, "a take-in's new manifests are kept for their judging in its memory alone", logger.Printf) tryRecovery := process.AwaitBucket(ctx, js, conn, index.TryRecoveryBucket, "how the recovery of the open tries went is not kept", logger.Printf) findings := process.AwaitBucket(ctx, js, conn, findingsBucket, "no finding of the indexer is written", logger.Printf) // The seat definitions (design 26, DLV-I17): a state this delivery brings, bound when it appears; until then none is kept. @@ -423,14 +426,14 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro seatBus := &seatBus{defs: awaitedSource{ctx, seatDefs}, marks: awaitedSource{ctx, marks}} seatReader, saySeats := followSeatList(seatBus, saySeatDefinition(js, cred), logger.Printf) readWhenBound(seatReader, seatDefs, marks) - ix := &index.Indexer{Findings: awaitedStore{b: findings}, OldSections: awaitedStore{b: oldSections}, Requirements: awaitedStore{b: requirements}, Store: kvStore{candidates}, Modules: kvStore{modules}, Manifests: kvStore{manifests}, Taken: awaitedStore{b: taken}, Builds: known, + ix := &index.Indexer{Findings: awaitedStore{b: findings}, OldSections: awaitedStore{b: oldSections}, Unjudged: awaitedStore{b: unjudged}, Requirements: awaitedStore{b: requirements}, Store: kvStore{candidates}, Modules: kvStore{modules}, Manifests: kvStore{manifests}, Taken: awaitedStore{b: taken}, Builds: known, Verdicts: awaitedStore{b: verdicts}, SayRefused: sayRefused(conn, cred, logger.Printf), SayAccepted: sayAccepted(conn, cred), Predefined: awaitedStore{b: predefined}, ConfigCandidates: awaitedStore{b: configCandidates}, Logf: logger.Printf, Named: namedVia(calls.Call), Trunk: trunkVia(calls.Call), Contains: containsVia(calls.Call), Read: readVia(calls.Call), ReadOpen: openVia(calls.Call), Packages: awaitedStore{b: packages, js: js, name: index.PackagesBucket}, Files: filesVia(calls.Call), GoSum: goSumVia(calls.Call), GoMod: goModVia(calls.Call), OwnBuild: ownBuildVia(calls.Call, cred.Node), OpenTries: openTriesVia(calls.Call), OwnBuildState: awaitedStore{b: ownBuildState}, TryRecovery: awaitedStore{b: tryRecovery}, Graph: awaitedStore{b: graph}, SeatDefinitions: awaitedStore{b: seatDefs}, ReadFile: readFileVia(calls.Call), SaySeatDefinition: saySeats, - Message: messageVia(calls.Call), + Message: messageVia(calls.CallKept), // a kept call: a read, called again through a transport fault (ADR 0668 §1) // The take-in step (ADR 0633): its state pending and its stream take-in, both this delivery's, bound when they appear; // until then every merge is taken in at once, as before. Pending: awaitedStore{b: process.AwaitBucket(ctx, js, conn, index.PendingBucket, "no merge is held for the indexer its revision names: each is taken in at once", logger.Printf)}, @@ -489,7 +492,8 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro // What each counted node's engine reads (ADR 0624 §1), for the mesh-wide hold of a manifest every node reads (ADR 0632 // §2): asked through the node-engine seat's verb as the indexer's own account, for every node the assignments names, // kept in the state engine-reads once it is bound; each change weighs the holds again. - reads := newEngineReads(calls.CallOn, gate, func() { ix.KickHolds(ctx) }, logger.Printf) + reads := newEngineReads(calls.CallKeptOn, gate, func() { ix.KickHolds(ctx) }, logger.Printf) + reads.keeper.Once = calls.CallOn // its fault keeps the last statement at once while the kept call asks on (ADR 0668 §3) gate.OnPlaced = reads.placed ix.Counted, ix.AskEngines = reads.counted, reads.ask // The holds, new with ADR 0632 (issue 1790's kind), bound when they appear: until then a merge that would hold a @@ -502,8 +506,17 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro // weighing only, said. holdBounds := process.AwaitBucket(ctx, js, conn, index.HoldBoundsBucket, "a hold standing past its bound is raised at its next weighing only", logger.Printf) ix.HoldBounds = expiringKeys{holdBounds} + // A kept manifest-reads call unanswered past five minutes, its node's machine heard (the watchdogs seat's presence, + // asked when the bound ends), is call-unanswered in the indexer's findings (issue 1966, ADR 0668 §3, ADR 0596 §2). + reads.callsOf(ctx, findings.KV, ix.HoldBounds, heardBy(calls.CallKept), logger.Printf) holdBounds.Ready(func(kv jetstream.KeyValue) { each := func(e jetstream.KeyValueEntry) { + if node, ok := enginereads.BoundOf(e.Key()); ok { + if e.Operation() == jetstream.KeyValuePurge { // a manifest-reads call's five minutes ended + reads.expiredCall(node) + } + return + } if e.Operation() == jetstream.KeyValuePurge { // its time to live ended ix.HoldBoundEnded(ctx, e.Key()) } @@ -591,6 +604,13 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro // Every manifest judged at the start, so a judge that changed with this program judges every one again (ADR 0578 // §1), once the verdicts state is there; each merge judges them again (index.ApplyMessage). verdicts.Ready(func(jetstream.KeyValue) { + // A take-in held because the verdicts state was not on the bus yet is evaluated again once the start's pass ended, + // whatever it answered (issue 1966 note 154). + defer func() { + if err := ix.PendingAgain(ctx); err != nil { + logger.Printf("take-in: pending is not evaluated again at the verdicts state's bind: %v", err) + } + }() // A pass that fails (a read the bus did not answer) is judged again at the next message or source revision the // indexer hears (index.kickJudge): no timer. j, err := ix.JudgeAtStart(ctx) @@ -648,6 +668,7 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro }); err != nil { return err } + hub.OnBound(reads.atBind) // what a node's engine said before the consumer was bound (ADR 0668 §4) versions := func(m jetstream.Msg) { if !heardVersion(ctx, ix, m, logger.Printf) { _ = m.Ack() // nothing else the indexer consumes rides the shared stream @@ -718,7 +739,11 @@ func run(ctx context.Context, getenv func(string) string, logOut io.Writer) erro index.ConfigCandidatesState: awaited(configCandidates), index.PackagesState: awaited(packages), graphState: awaited(graph), index.HeardState: awaited(heard.b), "taken": awaited(taken), "findings": awaited(findings), index.SeatDefinitionsState: awaited(seatDefs)}, errs, logger.Printf) - cc, err := process.HearEvents(cons, func(m jetstream.Msg) { handle(ctx, m, ix, heard, logger); ix.KickFill(ctx) }, logger.Printf) + cc, err := process.HearEvents(cons, func(m jetstream.Msg) { + handle(ctx, m, ix, heard, logger) + ix.KickFill(ctx) + unreadAgain(ctx, ix, logger) + }, logger.Printf) if err != nil { return err } diff --git a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/main_test.go b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/main_test.go index 40e32bfe..e64afeeb 100644 --- a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/main_test.go +++ b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/main_test.go @@ -12,6 +12,10 @@ import ( "github.com/nats-io/nats.go/jetstream" + "git.novox.be/novox/mesh-contracts/go/clients/nodeengineclient/enginereads" + "git.novox.be/novox/mesh-contracts/go/seats/nodeengine" + mcc "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" + "git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshwatchdogs" "git.novox.be/novox/mesh-delivery/contracts/go/clients/meshdeliveryclient" "git.novox.be/novox/mesh-delivery/contracts/go/seats/meshdelivery" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-forge-bridge/forgemsg" @@ -79,6 +83,65 @@ func TestAMessageIsIndexedAndAcked(t *testing.T) { // 1238/AC2 (unit part) if em := viewsEmitter(context.Background(), nil, process.Account{}, nil, &process.AwaitedBucket{}, nil, t.Logf); em.Findings == nil { t.Error("the indexer's views emitter writes no view-unsaid finding") } + t.Run("the consumer bound: every counted node's manifest-reads called once", func(t *testing.T) { // 1966 note 155, ADR 0668 §4 + // A manifest-reads-changed said before the indexer's consumer existed is never delivered: the hub's OnBound + // (reads.atBind) calls every node the assignments counts, so a stale statement ends at the bind. + var called []string + reads := &engineReads{known: true, nodes: []string{"ace", "g14"}, keeper: &enginereads.Keeper{Sync: true, + Call: func(node, _ string, _ any) (json.RawMessage, error) { + called = append(called, node) + return nil, errors.New("no responders") + }}} + reads.atBind(time.Unix(0, 0)) + if strings.Join(called, ",") != "ace,g14" { + t.Errorf("at the bind called %v, want ace and g14 once each", called) + } + }) + t.Run("a manifest-reads call unanswered past five minutes, its machine heard, is call-unanswered (ADR 0668 §3)", func(t *testing.T) { + // A bound is kept at five minutes; when it ends the watchdogs seat's presence is asked, once (ADR 0596 §2): away, + // no finding; heard, the finding in the indexer's findings, stamped with the wait's clock; answered, it is cleared. + now := time.Unix(1000, 0) + clock := func() time.Time { return now } + down := true + held := &findingsKV{vals: map[string][]byte{}} + reads := &engineReads{known: true, nodes: []string{"ace"}} + reads.keeper = &enginereads.Keeper{Sync: true, Now: clock, Call: func(node, _ string, _ any) (json.RawMessage, error) { + if down { + return nil, errors.New("no responders") + } + return json.Marshal(nodeengine.ManifestReadsAnswer{V: 1, Node: node, ManifestReads: []string{"form:new"}, StatedAt: now.Format(time.RFC3339Nano)}) + }} + reads.keeper.Changed = reads.stepCalls + armed := map[string]time.Time{} + online, asked := false, []any{} + heard := heardBy(func(key string, body any) (json.RawMessage, error) { + asked = append(asked, key, body) + return json.Marshal(meshwatchdogs.PresenceAnswer{Machine: "ace", Online: online}) + }) + calls := reads.callsOf(context.Background(), func() jetstream.KeyValue { return held }, nil, heard, t.Logf) + calls.Now = clock + calls.Arm = func(_ context.Context, node string, ends time.Time) error { armed[node] = ends; return nil } + key := mcc.Key(mcc.ScopeCall, "manifest-reads.ace", mcc.KindCallUnanswered) + reads.keeper.AskNode("ace", "counted") // unanswered at 1000 + if len(held.vals) != 0 || len(asked) != 0 || !armed["ace"].Equal(time.Unix(1000, 0).Add(mcc.CallUnansweredAfter)) { + t.Fatalf("before five minutes: findings %v, presence asked %v, bounds %v", held.vals, asked, armed) + } + now = time.Unix(1000, 0).Add(mcc.CallUnansweredAfter + time.Second) + reads.expiredCall("ace") + if len(held.vals) != 0 || len(asked) != 2 || asked[0] != presenceInvoke || asked[1] != (meshwatchdogs.PresenceInput{Machine: "ace"}) { + t.Fatalf("its machine away: findings %v, presence asked %v", held.vals, asked) + } + online = true + reads.expiredCall("ace") + if f, err := mcc.DecodeFinding(held.vals[key]); err != nil || f.Observer != "mesh-delivery-indexer" || f.Kind != mcc.KindCallUnanswered || !f.At.Equal(now) { + t.Fatalf("heard five minutes on: finding %+v, %v; want it at the wait's clock %v", f, err, now) + } + down = false + reads.keeper.AskNode("ace", "answered") + if len(held.vals) != 0 || !reads.keeper.Statements()["ace"].Answered || len(asked) != 4 { + t.Errorf("answered leaves %v, presence asked %v", held.vals, asked) + } + }) t.Run("not a forge message: terminated and logged", func(t *testing.T) { // 1238 (never redelivered) var logs bytes.Buffer st := &memStore{vals: map[string][]byte{}} @@ -196,3 +259,26 @@ func TestTheSourceMainKeyIsTakenAtItsRevision(t *testing.T) { // 1344/AC1 (the w } func ptr[T any](v T) *T { return &v } + +// findingsKV is a findings bucket of the two calls the indexer's call finding makes. +type findingsKV struct { + jetstream.KeyValue + vals map[string][]byte +} + +func (f *findingsKV) Put(_ context.Context, key string, value []byte) (uint64, error) { + f.vals[key] = value + return uint64(len(f.vals)), nil +} + +func (f *findingsKV) Get(_ context.Context, key string) (jetstream.KeyValueEntry, error) { + if _, ok := f.vals[key]; !ok { + return nil, jetstream.ErrKeyNotFound + } + return nil, nil +} + +func (f *findingsKV) Delete(_ context.Context, key string, _ ...jetstream.KVDeleteOpt) error { + delete(f.vals, key) + return nil +} diff --git a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/reads.go b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/reads.go index 29a7c890..ede70275 100644 --- a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/reads.go +++ b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/reads.go @@ -4,6 +4,7 @@ import ( "context" "slices" "sync" + "time" "github.com/nats-io/nats.go/jetstream" @@ -27,11 +28,36 @@ type engineReads struct { mu sync.Mutex known bool // the assignments is read nodes []string + // calls is the wait of the kept calls (callsOf); nil weighs none. ctx is the indexer's. + calls *enginereads.ReadsCalls + ctx context.Context } -// newEngineReads asks through call (process.Conn.CallOn) and tells changed after each statement changed. +// newEngineReads asks through call (process.Conn.CallKeptOn, a kept call; ADR 0668) and tells changed after each statement changed. func newEngineReads(call enginereads.Caller, gate *buildrun.ToolchainGate, changed func(), logf func(string, ...any)) *engineReads { - return &engineReads{gate: gate, keeper: &enginereads.Keeper{Call: call, Logf: logf, Changed: changed}} + r := &engineReads{gate: gate, ctx: context.Background()} + r.keeper = &enginereads.Keeper{Call: call, Logf: logf, Changed: func() { + if changed != nil { + changed() + } + r.stepCalls() + }} + return r +} + +// stepCalls weighs the kept manifest-reads calls (enginereads.ReadsCalls): after a statement changed and the assignments's +// change. +func (r *engineReads) stepCalls() { + if r.calls != nil { + r.calls.Step(r.ctx) + } +} + +// expiredCall weighs node's kept manifest-reads call when its bound ended (the key's expiry in the state hold-bounds). +func (r *engineReads) expiredCall(node string) { + if r.calls != nil { + r.calls.Expired(r.ctx, node) + } } // bind keeps the statements in kv and hears it: every node's last statement at the start, a person's ask again and drop @@ -75,6 +101,16 @@ func (r *engineReads) placed() { if r.keeper.Changed != nil { r.keeper.Changed() } + r.stepCalls() +} + +// atBind asks every counted node again when the indexer's consumer is bound (the hub's OnBound): a manifest-reads-changed +// said before the consumer existed is not delivered to it (novox/hq ADR 0668 §4; issue 1966 note 155). +func (r *engineReads) atBind(created time.Time) { + r.mu.Lock() + nodes := slices.Clone(r.nodes) + r.mu.Unlock() + r.keeper.AtBind(func() []string { return nodes })(created) } // heard takes an event of the indexer's consumer on EVENTS: manifest-reads-changed asks its node again, and answers true. diff --git a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/readscall.go b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/readscall.go new file mode 100644 index 00000000..aec566ce --- /dev/null +++ b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/readscall.go @@ -0,0 +1,82 @@ +package main + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "slices" + "time" + + "github.com/nats-io/nats.go/jetstream" + + "git.novox.be/novox/mesh-contracts/go/clients/nodeengineclient/enginereads" + mcc "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" + "git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshwatchdogs" + "git.novox.be/novox/mesh-sdk/go/process" + + "mesh-delivery-indexer/internal/index" +) + +// presenceInvoke is the watchdogs seat's verb presence as the manifest's invokes names it: whether a node's machine is +// heard, asked of the seat, never read from its holder's state (novox/hq ADR 0596 §2). +const presenceInvoke = "seat:" + meshwatchdogs.Seat + "." + meshwatchdogs.VerbPresence + +// heardBy asks the watchdogs seat's presence of one machine through call (process.Conn.CallKept, a read) and reads its +// declared answer: whether the machine is heard now. +func heardBy(call func(key string, body any) (json.RawMessage, error)) func(context.Context, string) (bool, error) { + return func(_ context.Context, machine string) (bool, error) { + raw, err := call(presenceInvoke, meshwatchdogs.PresenceInput{Machine: machine}) + if err != nil { + return false, err + } + var a meshwatchdogs.PresenceAnswer + if err := json.Unmarshal(raw, &a); err != nil { + return false, fmt.Errorf("%s does not read: %w", presenceInvoke, err) + } + return a.Online, nil + } +} + +// callsOf is the wait of the indexer's kept manifest-reads calls (enginereads.ReadsCalls): a node whose engine has not +// answered for five minutes is, when its bound ends and the watchdogs seat says its machine is heard, the finding +// call-unanswered in the indexer's findings, stamped with the wait's clock (issue 1966, ADR 0668 §3); its bound is a key +// of the state hold-bounds, which expires at its end. +func (r *engineReads) callsOf(ctx context.Context, findings func() jetstream.KeyValue, bounds index.Bounds, heard func(context.Context, string) (bool, error), logf func(string, ...any)) *enginereads.ReadsCalls { + c := &enginereads.ReadsCalls{Keeper: r.keeper, Heard: heard, Bound: mcc.CallUnansweredAfter, Logf: logf, + Nodes: func() []string { r.mu.Lock(); defer r.mu.Unlock(); return slices.Clone(r.nodes) }, + Raise: func(ctx context.Context, u enginereads.UnansweredCall) error { + kv := findings() + if kv == nil { + return process.ErrNotYet + } + o := mcc.CallUnanswered(enginereads.CallID(u.Node), enginereads.Invoke, u.Node, u.Words, "indexer."+mcc.KindCallUnanswered, u.Since) + o.Needs = index.EngineReadsTool + " with ask_again asks the node again now and shows its statement." + value, err := mcc.EncodeFinding(o.Finding(index.Module, "", u.At)) + if err == nil { + _, err = kv.Put(ctx, o.Key(), value) + } + return err + }, + Clear: func(ctx context.Context, node string) error { + kv := findings() + if kv == nil { + return nil + } + key := mcc.Key(mcc.ScopeCall, enginereads.CallID(node), mcc.KindCallUnanswered) + if _, err := kv.Get(ctx, key); err != nil { + if errors.Is(err, jetstream.ErrKeyNotFound) { + return nil + } + return err + } + return kv.Delete(ctx, key) + }} + if bounds != nil { + c.Arm = func(ctx context.Context, node string, ends time.Time) error { + return bounds.Arm(ctx, enginereads.BoundPrefix+node, ends) + } + } + r.ctx, r.calls = ctx, c + return c +} diff --git a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/takein.go b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/takein.go index 8585099d..af5f2e8a 100644 --- a/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/takein.go +++ b/modules/mesh-delivery-indexer/cmd/mesh-delivery-indexer/takein.go @@ -20,7 +20,7 @@ type takerIn interface { SeatDefinitionsAgain(ctx context.Context, module string, pull int, head string) index.TakenIn HoldAgain(ctx context.Context, module string, release bool, by string) index.TakenIn TakeInPendingByHand(ctx context.Context, key, by, why string) index.TakenIn - DropPending(ctx context.Context, key, by, why string) index.TakenIn + DropPending(ctx context.Context, key, by, why string, abandon bool) index.TakenIn TakeInMerge(ctx context.Context, repository, merge string, seq uint64, by, why string) index.TakenIn DropTryCandidate(ctx context.Context, id, by, why string) index.TakenIn RecoverTriesByHand(ctx context.Context, by, why string) index.TakenIn @@ -55,7 +55,7 @@ func takenIn(ctx context.Context, ix takerIn, kv jetstream.KeyValue, e jetstream asked, r = "hand take-in of a merge", ix.TakeInMerge(ctx, a.MergeRepository, a.Merge, a.Sequence, a.By, a.Why) a.Module = r.Module } else if a.Pending != "" && a.Drop { - asked, r = "drop of a pending merge", ix.DropPending(ctx, a.Pending, a.By, a.Why) + asked, r = "drop of a pending merge", ix.DropPending(ctx, a.Pending, a.By, a.Why, a.Abandon) a.Module = a.Pending } else if a.Pending != "" { asked, r = "hand take-in of what waits", ix.TakeInPendingByHand(ctx, a.Pending, a.By, a.Why) diff --git a/modules/mesh-delivery-indexer/go.mod b/modules/mesh-delivery-indexer/go.mod index 84dc549a..3302bf36 100644 --- a/modules/mesh-delivery-indexer/go.mod +++ b/modules/mesh-delivery-indexer/go.mod @@ -68,7 +68,7 @@ require ( require ( git.novox.be/novox/mesh-contracts/go/seats/nodeengine v0.0.0-00010101000000-000000000000 // indirect git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshhandacts v0.0.0-00010101000000-000000000000 // indirect - git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshwatchdogs v0.0.0-00010101000000-000000000000 // indirect + git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshwatchdogs v0.0.0-00010101000000-000000000000 git.novox.be/novox/mesh-delivery/contracts/go/clients/containerimageregistryclient v0.0.0-00010101000000-000000000000 // indirect git.novox.be/novox/mesh-delivery/contracts/go/seats/containerimageregistry v0.0.0-00010101000000-000000000000 // indirect git.novox.be/novox/mesh-delivery/contracts/go/seats/ociartifactregistry v0.0.0-00010101000000-000000000000 // indirect diff --git a/modules/mesh-delivery-indexer/internal/index/candidates.go b/modules/mesh-delivery-indexer/internal/index/candidates.go index 0849ba47..54463a6b 100644 --- a/modules/mesh-delivery-indexer/internal/index/candidates.go +++ b/modules/mesh-delivery-indexer/internal/index/candidates.go @@ -68,6 +68,9 @@ type Indexer struct { // OldSections is the state of how many accepted modules use each old section (oldsections.go, issue 1966 D4); nil keeps no // count and the judge refuses no use of an old section. OldSections Store + // Unjudged is the state of the manifest digests a take-in wrote and no judge pass judged yet (unjudged.go, issue 1966); + // nil keeps them only in the take-in's memory. + Unjudged Store // Requirements is the requirements state (requirements.go, DLV-I7): what each consumer's go.sum requires of each mesh // Go module, kept at each merge; nil keeps none. Requirements Store @@ -245,7 +248,9 @@ func (ix *Indexer) ApplyMessage(ctx context.Context, f forgemsg.Forge) (Applied, // Every manifest judged again: a rule between manifests can turn on the one this merge moved (ADR 0578 §1). // What this take-in newly wrote is fresh: judged in full (ADR 0579 §1). if _, err := ix.JudgeAll(ctx, w.fresh); err != nil { - ix.logf("judge: the manifests are not judged after %s#%d: %v", f.Repository, f.Number, err) + // Judged again at the next message or source revision heard (kickJudge), as a failed start pass is. + ix.judgePending.Store(true) + ix.logf("judge: the manifests are not judged after %s#%d: %v; judged again at the next message heard", f.Repository, f.Number, err) } } ix.kickRetry(ctx) // a registered module the forge could not read is read again on a merge, in the background (issue 1945) diff --git a/modules/mesh-delivery-indexer/internal/index/pending.go b/modules/mesh-delivery-indexer/internal/index/pending.go index d92c6956..238fa5e1 100644 --- a/modules/mesh-delivery-indexer/internal/index/pending.go +++ b/modules/mesh-delivery-indexer/internal/index/pending.go @@ -17,6 +17,7 @@ import ( "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-forge-bridge/forgemsg" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-indexer/takein" "git.novox.be/novox/mesh-delivery/sdk/trunk" + "git.novox.be/novox/mesh-sdk/go/busretry" "git.novox.be/novox/mesh-sdk/go/keys" "git.novox.be/novox/mesh-sdk/go/process" @@ -87,6 +88,13 @@ type Pending struct { SaidKind string `json:"said-kind,omitempty"` SaidAt time.Time `json:"said-at,omitzero"` Taking string `json:"taking,omitempty"` + // Unread is why the merged message could not be read for a transport fault (the forge bridge restarting, a deadline; + // ADR 0664's classes): not lost, it is read again on the next message heard on the forge, at the start and by + // indexer_take_in_pending (issue 1966 note 153, ADR 0668 §1). + Unread string `json:"unread,omitempty"` + // UnreadSince is when the message was first found unread: past meshconditionsclient.CallUnansweredAfter, with the forge + // heard since, it is the finding call-unanswered (unreadcall.go, ADR 0668 §3). + UnreadSince time.Time `json:"unread-since,omitzero"` } // PendingEntry is one key of the pending state as read: its key, revision, value and the merged message decoded. For a @@ -244,9 +252,9 @@ func (ix *Indexer) load(ctx context.Context, e PendingEntry) (PendingEntry, erro // loadNewest prepares the ready merges of one revision, in merge order. Of the merges of one repository only the newest is // loaded: applying it writes every module whose manifest differs from what is held, so it covers the older ones, which are // marked Covered and never read. A newest merge the forge bridge cannot give is answered in lost with its reason, by key, and its revision is held (holdLost). -func (ix *Indexer) loadNewest(ctx context.Context, entries []PendingEntry) (out, lost []PendingEntry, reasons map[string]string) { +func (ix *Indexer) loadNewest(ctx context.Context, entries []PendingEntry) (out, lost []PendingEntry, reasons map[string]string, unread map[string]bool) { out = slices.Clone(entries) - reasons = map[string]string{} + reasons, unread = map[string]string{}, map[string]bool{} newest := map[string]bool{} for i := len(out) - 1; i >= 0; i-- { repo := strings.ToLower(out[i].Forge.Repository) @@ -267,12 +275,14 @@ func (ix *Indexer) loadNewest(ctx context.Context, entries []PendingEntry) (out, if err != nil { lost = append(lost, out[i]) reasons[out[i].Key] = err.Error() + // A transport fault is not the bridge's answer: the message is unread, never lost (ADR 0668 §1). + unread[out[i].Key] = busretry.Undelivered(err) || busretry.TimedOut(err) continue } out[i] = full } slices.Reverse(lost) - return out, lost, reasons + return out, lost, reasons, unread } // Waits is the pending state read as what waits (ADR 0633 §3, §4): Ready are the merges no group still being gathered @@ -348,6 +358,15 @@ func revisionWait(kind string, ready []PendingEntry, waitsFor string) takein.Tak // pendingOnBus says whether the pending state is on the bus: a state this delivery brings is bound when it appears // (issue 1790), and until then every merge is taken in at once, so the build this program runs is not needed. A read // that fails otherwise counts as on the bus: the step that follows answers the error. +// errVerdictsNotYet is a take-in held because the verdicts state is not on the bus yet (takeInWholeBy). +var errVerdictsNotYet = errors.New("the verdicts state is not on the bus yet: nothing is taken in until it is") + +// verdictsOnBus says the verdicts state is on the bus (a take-in judges what it writes there). +func (ix *Indexer) verdictsOnBus(ctx context.Context) bool { + _, _, _, err := ix.Verdicts.Get(ctx, "on-the-bus") + return !errors.Is(err, process.ErrNotYet) +} + func (ix *Indexer) pendingOnBus(ctx context.Context) bool { _, _, _, err := ix.Pending.Get(ctx, takein.PendingKey(0)) return !errors.Is(err, process.ErrNotYet) @@ -670,8 +689,33 @@ func (ix *Indexer) TakeInAtStart(ctx context.Context) (Applied, string, error) { return a, words, err } +// UnreadAgain evaluates pending again when a merge in it is unread for a transport fault (Pending.Unread): told after +// every message heard on the forge, of any kind, so a merge whose message the forge bridge could not give while it +// restarted is read again once the forge is heard again, with no timer (issue 1966 note 153, ADR 0668 §4). It reads +// pending once and does nothing when no merge is unread. +func (ix *Indexer) UnreadAgain(ctx context.Context) error { + if ix.Pending == nil || !ix.pendingOnBus(ctx) { + return nil + } + entries, err := ReadPending(ctx, ix.Pending, ix.logf) + if err != nil { + return err + } + if slices.ContainsFunc(entries, func(e PendingEntry) bool { return e.Value.Unread != "" }) { + if err := ix.PendingAgain(ctx); err != nil { + return err + } + if entries, err = ReadPending(ctx, ix.Pending, ix.logf); err != nil { + return err + } + } + // The forge was heard, so the bridge that says it is: a read still failing past the bound is a finding (ADR 0668 §3). + ix.unreadFindings(ctx, entries) + return nil +} + // PendingAgain evaluates pending again after something a fingerprint is computed from changed, a toolchain report -// (ADR 0633 §1, §3): a revision that now names the running build is taken in, and one that names another build is held +// (ADR 0633 §1, §3), or the verdicts state bound (issue 1966): a revision that now names the running build is taken in, and one that names another build is held // for that one. It does nothing while the pending state is not on the bus or the build this program runs is not known. func (ix *Indexer) PendingAgain(ctx context.Context) error { if ix.Pending == nil || !ix.pendingOnBus(ctx) { @@ -688,7 +732,7 @@ func (ix *Indexer) PendingAgain(ctx context.Context) error { return nil } if err == nil && words != "" { - ix.logf("take-in: evaluated again after a toolchain report: %s", words) + ix.logf("take-in: evaluated again: %s", words) } return err } @@ -722,9 +766,9 @@ func (ix *Indexer) evaluate(ctx context.Context, own string, start bool) (Applie // Of each repository's merges only the newest is read (from memory, else asked of the forge bridge: a pending value // keeps a reference); the older ones are covered by it. A newest merge that cannot be read is said and // holds its revision: nothing of it is taken in silently. - ready, lost, reasons := ix.loadNewest(ctx, w.Ready) + ready, lost, reasons, unread := ix.loadNewest(ctx, w.Ready) if len(lost) > 0 { - return Applied{}, ix.waitingLine(w), ix.holdLost(ctx, w.Ready, lost, reasons) + return Applied{}, ix.waitingLine(w), ix.holdLost(ctx, w.Ready, lost, reasons, unread) } names, dry, err := ix.computeOver(ctx, ready) if err != nil { @@ -735,6 +779,9 @@ func (ix *Indexer) evaluate(ctx context.Context, own string, start bool) (Applie if errors.Is(err, errClaimLost) { return a, "claimed by another take-in", nil } + if errors.Is(err, errVerdictsNotYet) { + return a, "the verdicts state is not on the bus yet: the revision waits for it, taken in when it binds", nil + } return a, ix.waitingLine(w), err } return Applied{}, ix.waitingLine(w), ix.holdFor(ctx, ready, names, own, dry) @@ -743,8 +790,9 @@ func (ix *Indexer) evaluate(ctx context.Context, own string, start bool) (Applie // holdLost holds a revision whose newest merge of a repository cannot be read (the forge bridge's stream no longer holds // it, or the bus refuses the read): said once on take-in.pending with the lost keys (TakeIn.Lost), and on each lost entry // (Pending.Lost, the reason, which indexer_pending shows), until a newer merge of its repository covers it or -// indexer_drop_pending drops it. Nothing of the revision is taken in meanwhile. -func (ix *Indexer) holdLost(ctx context.Context, ready, lost []PendingEntry, reasons map[string]string) error { +// indexer_drop_pending drops it. A merge unread for a transport fault (unread) is kept as Pending.Unread, not Lost, and read +// again on the next message heard on the forge (UnreadAgain). Nothing of the revision is taken in meanwhile. +func (ix *Indexer) holdLost(ctx context.Context, ready, lost []PendingEntry, reasons map[string]string, unread map[string]bool) error { t := revisionWait(takein.TakeInPending, ready, "") for _, g := range lost { t.Lost = append(t.Lost, g.Key) @@ -752,7 +800,7 @@ func (ix *Indexer) holdLost(ctx context.Context, ready, lost []PendingEntry, rea said := true for _, e := range ready { isLost := slices.Contains(t.Lost, e.Key) - if e.Value.Said != t.Key || e.Value.SaidKind != takein.TakeInPending || (isLost && e.Value.Lost == "") { + if e.Value.Said != t.Key || e.Value.SaidKind != takein.TakeInPending || (isLost && (unread[e.Key] && e.Value.Unread == "" || !unread[e.Key] && e.Value.Lost == "")) { said = false } } @@ -760,8 +808,13 @@ func (ix *Indexer) holdLost(ctx context.Context, ready, lost []PendingEntry, rea return nil } for _, g := range lost { - ix.logf("take-in: %s (%s#%d) is not taken in and holds its revision, the forge bridge could not give its message: %s; a newer merge of %s covers it, indexer_drop_pending drops it", - g.Key, g.Forge.Repository, g.Forge.Number, reasons[g.Key], g.Forge.Repository) + if unread[g.Key] { + ix.logf("take-in: %s (%s#%d) is not taken in and holds its revision, its message is unread for a transport fault: %s; it is read again on the next message heard on the forge, at the start, and by %s", + g.Key, g.Forge.Repository, g.Forge.Number, reasons[g.Key], TakeInPendingTool) + continue + } + ix.logf("take-in: %s (%s#%d) is not taken in and holds its revision, the forge bridge could not give its message: %s; %s reads it again; indexer_drop_pending drops it once a later merge of %s covers it", + g.Key, g.Forge.Repository, g.Forge.Number, reasons[g.Key], TakeInPendingTool, g.Forge.Repository) } if !ix.sayTakeIn(ctx, t) { return nil @@ -773,8 +826,19 @@ func (ix *Indexer) holdLost(ctx context.Context, ready, lost []PendingEntry, rea } } for _, g := range lost { - reason := reasons[g.Key] - ix.markSaid(ctx, []PendingEntry{g}, &t, func(p *Pending) { p.Lost = reason }) + reason, isUnread := reasons[g.Key], unread[g.Key] + now := ix.now().UTC() + ix.markSaid(ctx, []PendingEntry{g}, &t, func(p *Pending) { + p.Lost, p.Unread = reason, "" + if !isUnread { + p.UnreadSince = time.Time{} + return + } + p.Lost, p.Unread = "", reason + if p.UnreadSince.IsZero() { + p.UnreadSince = now + } + }) } ix.markSaid(ctx, kept, &t, nil) return nil @@ -830,6 +894,8 @@ func (ix *Indexer) dry() *dryRun { x.Predefined, d.predefined = over(ix.Predefined) x.ConfigCandidates, d.configs = over(ix.ConfigCandidates) x.OldSections, d.oldSections = over(ix.OldSections) + // What the trunk holds unjudged is read through, as fresh; what the dry run would keep stays in its overlay (issue 1966). + x.Unjudged, _ = over(ix.Unjudged) ix.mu.Lock() x.source = sourceNow{rev: ix.source.rev, heads: maps.Clone(ix.source.heads)} x.previews = maps.Clone(ix.previews) @@ -967,6 +1033,13 @@ func (ix *Indexer) takeInWhole(ctx context.Context, entries []PendingEntry, own, // takeInWholeBy is takeInWhole; who and why, of a hand act, are carried on the take-in.taken events. func (ix *Indexer) takeInWholeBy(ctx context.Context, entries []PendingEntry, own, by, who, why string) (Applied, error) { + if ix.Verdicts != nil && !ix.verdictsOnBus(ctx) && len(entries) > 0 { + // Every manifest a take-in writes is judged in it and its verdict said before take-in.taken (issue 1966 note 154, + // ADR 0668 §4): with the verdicts state not on the bus yet, nothing is taken in; its bind evaluates pending again. + ix.logf("take-in: %d merges wait, oldest %s: the state %s is not on the bus yet, so nothing is taken in until it is, and no manifest is written without its verdict", + len(entries), entries[0].Key, VerdictsBucket) + return Applied{}, errVerdictsNotYet + } claimed, ok := ix.claim(ctx, entries, own, by) if !ok { return Applied{}, errClaimLost @@ -1179,6 +1252,9 @@ func waitOf(entries []PendingEntry, what, behind string) takein.PendingWait { if e.Value.Lost != "" { pw.Lost = append(pw.Lost, e.Key) } + if e.Value.Unread != "" { + pw.Unread = append(pw.Unread, e.Key) + } if e.Value.Refused != "" { pw.Refused = e.Value.Refused } @@ -1224,9 +1300,9 @@ func (ix *Indexer) TakeInPendingByHand(ctx context.Context, key, by, why string) r.Answer = fmt.Sprintf("nothing waits under %s: indexer_pending names the waits", key) return r } - take, lost, reasons := ix.loadNewest(ctx, take) + take, lost, reasons, _ := ix.loadNewest(ctx, take) if len(lost) > 0 { - r.Answer = fmt.Sprintf("nothing is taken in: the message of %s is not read (%s); a newer merge of its repository covers it, indexer_drop_pending drops it", lost[0].Key, reasons[lost[0].Key]) + r.Answer = fmt.Sprintf("nothing is taken in: the message of %s is not read (%s); asked again, it is read again; indexer_drop_pending drops it once a later merge of its repository covers it", lost[0].Key, reasons[lost[0].Key]) return r } ix.logf("take-in: a hand take-in of %s (%d merges) asked by %s: %s", key, len(take), by, why) @@ -1245,8 +1321,10 @@ func (ix *Indexer) TakeInPendingByHand(ctx context.Context, key, by, why string) // DropPending is the hand drop (indexer_drop_pending, ADR 0633 §5): the one pending merge under key, abandoned // because a later merge replaced it, is removed and nothing of it is taken in. Its wait is said taken, naming the drop; -// the merges left under that wait are said pending again by the evaluation that follows. -func (ix *Indexer) DropPending(ctx context.Context, key, by, why string) TakenIn { +// the merges left under that wait are said pending again by the evaluation that follows. A merge that no later pending +// merge and no taken merge of its repository covers is refused unless abandon (issue 1966: #650, its repository's head, +// was dropped on the advice of a line that named a drop where nothing covered it; ADR 0668 §5). +func (ix *Indexer) DropPending(ctx context.Context, key, by, why string, abandon bool) TakenIn { r := TakenIn{Module: key} if ix.Pending == nil { r.Answer = "the pending state is not on the bus: nothing waits" @@ -1266,6 +1344,39 @@ func (ix *Indexer) DropPending(ctx context.Context, key, by, why string) TakenIn return r } e := entries[at] + if !abandon { + // Covered: a later merge of the same repository, pending or taken in, has this merge's commit as an ancestor (ADR + // 0668 §6), asked of the forge (older); a later merge whose history does not hold it covers nothing. + covered := false + for _, o := range entries[at+1:] { + if o.Forge.Repository != e.Forge.Repository { + continue + } + in, err := ix.older(ctx, e.Forge.Repository, e.Forge.Merge, o.Forge.Merge) + if err != nil { + r.Answer = fmt.Sprintf("%s is not dropped: whether the later pending merge %s covers it is not read: %v", key, o.Key, err) + return r + } + if in { + covered = true + break + } + } + if !covered { + taken, err := ix.takenAlready(ctx, forgemsg.GroupMerge{Repository: e.Forge.Repository, Number: e.Forge.Number, Merge: e.Forge.Merge}) + if err != nil { + r.Answer = fmt.Sprintf("%s is not dropped: whether a taken merge of %s covers it is not read: %v", key, e.Forge.Repository, err) + return r + } + covered = taken + } + if !covered { + r.Answer = fmt.Sprintf("%s is not dropped: no later merge of %s, pending or taken in, has %s as an ancestor, so its "+ + "changes would never be taken in (ADR 0633 §5); %s reads its message again, or abandon: true drops it all the same", + key, e.Forge.Repository, e.Forge.Merge, TakeInPendingTool) + return r + } + } if err := ix.Pending.Delete(ctx, e.Key, e.Revision); err != nil { r.Answer = fmt.Sprintf("%s.%s is not removed: %v", PendingState, key, err) return r diff --git a/modules/mesh-delivery-indexer/internal/index/pending_test.go b/modules/mesh-delivery-indexer/internal/index/pending_test.go index 0ecaef44..066f9450 100644 --- a/modules/mesh-delivery-indexer/internal/index/pending_test.go +++ b/modules/mesh-delivery-indexer/internal/index/pending_test.go @@ -11,14 +11,18 @@ import ( "testing" "time" + mcc "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" + "git.novox.be/novox/mesh-delivery/contracts/go/clients/meshdeliveryclient" "git.novox.be/novox/mesh-delivery/contracts/go/seats/meshcatalog" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-forge-bridge/forgemsg" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-indexer/takein" "git.novox.be/novox/mesh-delivery/sdk/trunk" "git.novox.be/novox/mesh-sdk/go/buscompose" + "git.novox.be/novox/mesh-sdk/go/busretry" "git.novox.be/novox/mesh-sdk/go/catalogue" "git.novox.be/novox/mesh-sdk/go/process" + "github.com/nats-io/nats.go" ) // takeInBed is an indexer holding the catalogue's avahi and the indexer's own module, both with a fingerprint, its @@ -204,8 +208,23 @@ func TestTakeIn(t *testing.T) { // 1585/T3-T13 (ADR 0633) t.Run("T7 and T3 a merge alone, an indexer change, a merge behind it and a revert", func(t *testing.T) { b := newTakeInBed(t) own, avahi0 := b.fp(t, Module), b.fp(t, "avahi") - // A merge with no change to the indexer and nothing pending is taken in alone, as before. + // Issue 1966 note 154 (ADR 0668 §4): with the verdicts state not on the bus yet, nothing is taken in and no manifest + // is written without its verdict; its bind evaluates pending again, which takes the merge in with its verdicts. + verdictsBound := b.ix.Verdicts + b.ix.Verdicts = &memStore{unbound: process.ErrNotYet} b.arrive(t, 1, b.merge(20, sha('b'), "tree-avahi-2", "")) + if b.fp(t, "avahi") != avahi0 || !reflect.DeepEqual(b.keys(), []string{takein.PendingKey(1)}) { + t.Fatalf("verdicts not on the bus: avahi %s (was %s), pending %v: want the merge waiting, nothing written", b.fp(t, "avahi"), avahi0, b.keys()) + } + b.ix.Verdicts = verdictsBound + judgedBefore := len(verdictsBound.(*memStore).vals) + if err := b.ix.PendingAgain(ctx); err != nil { + t.Fatal(err) + } + if n := len(verdictsBound.(*memStore).vals); n <= judgedBefore { + t.Fatalf("taken in at the bind: %d verdicts (were %d), want the new manifest's", n, judgedBefore) + } + // A merge with no change to the indexer and nothing pending is taken in alone, as before. if avahi1 := b.fp(t, "avahi"); avahi1 == avahi0 || len(b.keys()) != 0 || len(b.said) != 0 { t.Fatalf("alone: avahi %s (was %s), pending %v, said %v: want taken in", avahi1, avahi0, b.keys(), b.events()) } @@ -554,6 +573,73 @@ func TestTakeIn(t *testing.T) { // 1585/T3-T13 (ADR 0633) if len(b.keys()) != 0 || b.commit(t, "avahi") != sha('e') { t.Errorf("after a lost start: pending %v, avahi at %s: want all taken in by the next merged message", b.keys(), b.commit(t, "avahi")) } + // Issue 1966 note 153, ADR 0668 §1, §4: a transport fault (the bridge restarting past the call's bound) leaves the + // newest merge unread, not lost, and indexer_pending says so; the next message heard on the forge, of any kind, reads + // it again. The bridge's own answer (it holds no such merge) is lost, as before, and a heard message does not ask it. + for _, c := range []struct { + name string + fault error + unread bool + }{ + {"a deadline", fmt.Errorf("the bridge: %w", nats.ErrTimeout), true}, + {"no responders", fmt.Errorf("the bridge: %w", nats.ErrNoResponders), true}, + {"the bridge's answer", &busretry.Answered{Words: "no merge at that commit"}, false}, + } { + b = held() + clock := time.Date(2026, 11, 10, 1, 0, 0, 0, time.UTC) + b.ix.Now, b.ix.Findings = func() time.Time { return clock }, newMem() + answers := b.ix.Message + b.ix.held = nil + b.ix.Message = func(context.Context, string, string, int) ([]byte, error) { return nil, c.fault } + if _, _, err := b.ix.TakeInAtStart(ctx); err != nil || len(b.keys()) != 2 { + t.Fatalf("%s at the start: err %v, pending %v", c.name, err, b.keys()) + } + waits := PendingWaits(mustReadPending(t, b)) + if len(waits) != 1 || (len(waits[0].Unread) == 1) != c.unread || (len(waits[0].Lost) == 1) == c.unread { + t.Fatalf("%s: indexer_pending %+v: want unread %v, lost %v", c.name, waits, c.unread, !c.unread) + } + // ADR 0668 §3: unread within five minutes is no finding; past them, with nothing heard on the forge (the bridge's + // machine away, only a toolchain report heard), none either; the next message heard on the forge, the read still + // failing, writes call-unanswered naming the bridge's call; the merge read and taken in clears it. + finding := func() (string, bool) { + keys, _ := b.ix.Findings.Keys(ctx) + for _, k := range keys { + if strings.HasSuffix(k, "."+mcc.KindCallUnanswered) { + v, _, _, _ := b.ix.Findings.Get(ctx, k) + return string(v), true + } + } + return "", false + } + if c.unread { + for _, step := range []struct { + after time.Duration + heard bool + finding bool + }{{time.Minute, true, false}, {5 * time.Minute, false, false}, {0, true, true}} { + clock = clock.Add(step.after) + var err error + if step.heard { + err = b.ix.UnreadAgain(ctx) + } else { + err = b.ix.PendingAgain(ctx) + } + if v, found := finding(); err != nil || found != step.finding || found && !strings.Contains(v, UnreadCallee) { + t.Fatalf("%s, %s later, forge heard %v: finding %v %s (%v), want %v", c.name, step.after, step.heard, found, v, err, step.finding) + } + } + } + b.ix.Message = answers + if err := b.ix.UnreadAgain(ctx); err != nil { + t.Fatal(err) + } + if taken := len(b.keys()) == 0 && b.commit(t, "avahi") == sha('d'); taken != c.unread { + t.Errorf("%s, a message heard after: pending %v, avahi at %s: want taken in %v", c.name, b.keys(), b.commit(t, "avahi"), c.unread) + } + if v, found := finding(); found { + t.Errorf("%s: the finding stands after the merge was taken in: %s", c.name, v) + } + } }) t.Run("T5 two take-ins of one pending revision: the one that loses the claim writes nothing", func(t *testing.T) { b := newTakeInBed(t) @@ -643,7 +729,7 @@ func TestTakeIn(t *testing.T) { // 1585/T3-T13 (ADR 0633) key, _ := ToolchainKey(node, "go") x.PutToolchain("mesh-build-go", key, toolchainValue(t, "go", "go1.27.2", "1"), false) } - ready, _, _ := b.ix.loadNewest(ctx, WaitsOf(entries).Ready) + ready, _, _, _ := b.ix.loadNewest(ctx, WaitsOf(entries).Ready) next, _, err := x.computeOver(ctx, ready) if err != nil || next == "" || next == b.said[0].WaitsFor { t.Fatalf("the build under the next toolchain: %q %v (the revision names %s)", next, err, b.said[0].WaitsFor) @@ -678,13 +764,30 @@ func TestTakeIn(t *testing.T) { // 1585/T3-T13 (ADR 0633) answer.Waits[0].Said != takein.TakeInPendingEvent || len(answer.Waits[0].Keys) != 2 { t.Fatalf("indexer_pending = %+v", answer) } + // ADR 0668 §6: a later merge covers a pending one only when its commit has the pending merge's as an ancestor. + history := "cd" + b.ix.Contains = func(_ context.Context, _, commit, in string) (bool, error) { + i, j := strings.IndexByte(history, commit[0]), strings.IndexByte(history, in[0]) + return i >= 0 && j >= 0 && i <= j, nil + } + history = "dc" // m.3's commit is not in m.2's later history (a history rewritten) + if r := b.ix.DropPending(ctx, takein.PendingKey(2), "lead@shanks", "replaced by m.3", false); r.Stored || !strings.Contains(r.Answer, "as an ancestor") { + t.Fatalf("a drop a later merge not holding it would cover: %+v", r) + } + history = "cd" b.said = nil - if r := b.ix.DropPending(ctx, takein.PendingKey(2), "lead@shanks", "replaced by m.3"); !r.Stored { + if r := b.ix.DropPending(ctx, takein.PendingKey(2), "lead@shanks", "replaced by m.3", false); !r.Stored { t.Fatalf("drop: %+v", r) } if len(b.said) < 2 || !b.said[0].Dropped || b.said[0].Key != takein.PendingKey(2) || b.said[0].By != "lead@shanks" || b.said[1].Key != takein.PendingKey(3) { t.Fatalf("drop said %+v: want m.2 taken (dropped, by) and m.3 pending", b.said) } + // Issue 1966 (#650), ADR 0633 §5: the newest pending merge of its repository, which no taken merge covers, is not + // dropped; the answer names the read again. abandon drops it all the same (below). + if r := b.ix.DropPending(ctx, takein.PendingKey(3), "lead@shanks", "lost message", false); r.Stored || + !strings.Contains(r.Answer, TakeInPendingTool) || len(b.keys()) != 1 { + t.Fatalf("a drop nothing covers: %+v, pending %v", r, b.keys()) + } b.said = nil if r := b.ix.TakeInPendingByHand(ctx, takein.PendingKey(3), "lead@shanks", "the named indexer can never run"); !r.Stored { t.Fatalf("hand take-in: %+v", r) @@ -692,6 +795,13 @@ func TestTakeIn(t *testing.T) { // 1585/T3-T13 (ADR 0633) if len(b.keys()) != 0 || b.commit(t, "avahi") != sha('d') || len(b.said) != 1 || b.said[0].Kind != takein.TakeInTaken || b.said[0].By != "lead@shanks" { t.Errorf("hand take-in: pending %v, avahi at %s, said %+v", b.keys(), b.commit(t, "avahi"), b.said) } + b.arrive(t, 4, b.merge(23, sha('e'), "tree-avahi-5", "tree-indexer-2")) + if r := b.ix.DropPending(ctx, takein.PendingKey(4), "lead@shanks", "abandoned on the operator's word", true); !r.Stored || len(b.keys()) != 0 { + t.Errorf("an abandoned drop: %+v, pending %v", r, b.keys()) + } + if _, _, err := NewPendingAsk(takein.PendingKey(4), "x", "lead@shanks", false, true, time.Unix(0, 0)); err == nil { + t.Errorf("abandon on a take-in was asked") + } }) t.Run("1585 a merge over the value cap is held by reference, a new indexer with an empty memory takes it in through the forge bridge, and a covered pull request leaves its candidate", func(t *testing.T) { big := func(f forgemsg.Forge) forgemsg.Forge { @@ -829,7 +939,7 @@ func TestTakeIn(t *testing.T) { // 1585/T3-T13 (ADR 0633) t.Run("the dry run names every field of the indexer", func(t *testing.T) { // dry (pending.go) builds an indexer field by field: a field added to Indexer is named there, or this fails. named := map[string]bool{} - for _, f := range []string{"Store", "Modules", "Manifests", "Predefined", "ConfigCandidates", "Taken", "Verdicts", "OldSections", + for _, f := range []string{"Store", "Modules", "Manifests", "Predefined", "ConfigCandidates", "Taken", "Verdicts", "OldSections", "Unjudged", "JudgeID", "SayRefused", "SayAccepted", "Packages", "Graph", "Files", "GoSum", "GoMod", "Now", "Builds", "Named", "Trunk", "Read", "Contains", "Logf", "ReadOpen", "OwnBuild", "Message", "Pending", "SayTakeIn", "Requirements", "Findings", "SeatDefinitions", "ReadFile", "SaySeatDefinition", "Holds", "Counted", "AskEngines", "HoldBounds", "OpenTries", "TryRecovery", "OwnBuildState"} { diff --git a/modules/mesh-delivery-indexer/internal/index/pending_tools.go b/modules/mesh-delivery-indexer/internal/index/pending_tools.go index 189cff8a..4ab76300 100644 --- a/modules/mesh-delivery-indexer/internal/index/pending_tools.go +++ b/modules/mesh-delivery-indexer/internal/index/pending_tools.go @@ -21,7 +21,7 @@ func PendingTools(pending, ownBuild Store, ask func(key string, value []byte) (T str := func(args map[string]any, k string) string { s, _ := args[k].(string); return s } hand := func(drop bool) func(map[string]any) (any, error) { return func(args map[string]any) (any, error) { - key, value, err := NewPendingAsk(str(args, "key"), str(args, "why"), stdio.CallerOf(args), drop, now()) + key, value, err := NewPendingAsk(str(args, "key"), str(args, "why"), stdio.CallerOf(args), drop, args["abandon"] == true, now()) if err != nil { return nil, err } @@ -93,11 +93,13 @@ func PendingTools(pending, ownBuild Store, ask func(key string, value []byte) (T Run: hand(false)}, {Name: DropPendingTool, Description: "Drop one pending merge by hand, abandoned because a later merge replaced it (ADR 0633 §5): it is removed from " + - "the pending state and nothing of it is taken in; what waited with it is worked out again. A hand act: who and why are " + - "said in the journal and on the take-in.taken event (dropped).", + "the pending state and nothing of it is taken in; what waited with it is worked out again. A merge no later pending merge " + + "and no taken merge of its repository covers is refused, naming indexer_take_in_pending, which reads its message again; " + + "abandon: true drops it all the same. A hand act: who and why are said in the journal and on the take-in.taken event (dropped).", Input: map[string]any{"type": "object", "required": []string{"key", "why"}, "properties": map[string]any{ - "key": map[string]any{"type": "string", "description": "the pending merge's key, m., as indexer_pending names its merges' wait"}, - "why": map[string]any{"type": "string", "description": "why it is dropped, in plain words"}}}, + "key": map[string]any{"type": "string", "description": "the pending merge's key, m., as indexer_pending names its merges' wait"}, + "why": map[string]any{"type": "string", "description": "why it is dropped, in plain words"}, + "abandon": map[string]any{"type": "boolean", "description": "drop it though no later merge covers it; its changes are then never taken in"}}}, Run: hand(true)}, {Name: TakeInMergeTool, Description: "Take one merge in by hand (ADR 0633 §5, issue 1585): the indexer asks the forge bridge for the merge's merged message " + diff --git a/modules/mesh-delivery-indexer/internal/index/takein.go b/modules/mesh-delivery-indexer/internal/index/takein.go index b20c7006..89505157 100644 --- a/modules/mesh-delivery-indexer/internal/index/takein.go +++ b/modules/mesh-delivery-indexer/internal/index/takein.go @@ -49,6 +49,9 @@ type TakeInAsk struct { // Pending asks the wait under this take-in key to be taken in by hand (indexer_take_in_pending), or with Drop the // one pending merge under it to be dropped (indexer_drop_pending), instead of a module (pending.go, ADR 0633 §5). Pending string `json:"pending,omitempty"` + // Abandon, with Drop, drops a pending merge no later merge covers (ADR 0633 §5 asks a later merge; issue 1966, ADR + // 0668 §5): the hand act says why it is abandoned all the same. + Abandon bool `json:"abandon,omitempty"` // Merge asks the merge of MergeRepository at this commit to be taken in by hand (indexer_take_in_merge): its merged message // is asked of the forge bridge and run through the take-in as a delivered one, under its stream sequence Sequence. Merge string `json:"merge,omitempty"` @@ -137,8 +140,8 @@ func NewMergeAsk(repository, merge string, sequence uint64, why, by string, at t // NewPendingAsk is the value indexer_take_in_pending (drop false) or indexer_drop_pending (drop true) writes: its key // in takeins, `pending..`, and the value. key is a wait's key as indexer_pending names it, for a -// drop one pending merge's. -func NewPendingAsk(key, why, by string, drop bool, at time.Time) (string, []byte, error) { +// drop one pending merge's; abandon drops one no later merge covers. +func NewPendingAsk(key, why, by string, drop, abandon bool, at time.Time) (string, []byte, error) { key = strings.TrimSpace(key) if !strings.HasPrefix(key, "m.") && !(strings.HasPrefix(key, "g.") && !drop) { if drop { @@ -153,6 +156,9 @@ func NewPendingAsk(key, why, by string, drop bool, at time.Time) (string, []byte if drop { act = "drop" } - data, err := json.Marshal(TakeInAsk{V: 1, Pending: key, Drop: drop, Why: strings.TrimSpace(why), By: by, At: at.UTC()}) + if abandon && !drop { + return "", nil, errors.New("abandon is a drop's: indexer_take_in_pending takes a wait in") + } + data, err := json.Marshal(TakeInAsk{V: 1, Pending: key, Drop: drop, Abandon: abandon, Why: strings.TrimSpace(why), By: by, At: at.UTC()}) return "pending." + act + "." + key, data, err } diff --git a/modules/mesh-delivery-indexer/internal/index/toolchains.go b/modules/mesh-delivery-indexer/internal/index/toolchains.go index 71044311..2ffb0617 100644 --- a/modules/mesh-delivery-indexer/internal/index/toolchains.go +++ b/modules/mesh-delivery-indexer/internal/index/toolchains.go @@ -415,6 +415,10 @@ func (ix *Indexer) writeOverlay(ctx context.Context, overlay, finals map[string] } if next.Manifest != "" && (!held || cur.Manifest != next.Manifest) { w.taken(next.Manifest) // a new module, or a changed manifest: fresh, judged in full (ADR 0579 §1) + // Kept on the bus before the module names it, so a judge pass that fails does not lose it (issue 1966). + if err := ix.keepUnjudged(ctx, next.Manifest, key, w); err != nil { + return nil, false, err + } } data, err := meshcatalogclient.EncodeModule(next) wrote = err == nil && !unchanged(data, false, value, found) diff --git a/modules/mesh-delivery-indexer/internal/index/unjudged.go b/modules/mesh-delivery-indexer/internal/index/unjudged.go new file mode 100644 index 00000000..772551b8 --- /dev/null +++ b/modules/mesh-delivery-indexer/internal/index/unjudged.go @@ -0,0 +1,111 @@ +package index + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "maps" + "slices" + + "git.novox.be/novox/mesh-sdk/go/process" +) + +// What a take-in newly wrote is kept until judged (issue 1966, ADR 0668 §4; ADR 0579 §1). A manifest a take-in writes new +// is fresh: judged in full, never taken as accepted before. A judge pass that fails (the verdicts state not on the bus, a +// restart between the write and the pass) used to lose that set, which lived only in the take-in's memory: the next pass +// found no verdict, took the manifest as held before any verdict, and wrote a refusal as a warning. So the take-in writes +// each digest into the indexer's own state unjudged before it writes the module naming it, every judge pass judges those +// digests as fresh, and a pass deletes a digest's key once its verdict is written or no module holds it any more. The +// tool indexer_read_unjudged reads the state; indexer_judge judges again by hand, which ends what it holds. +const ( + // UnjudgedState is the indexer's state of the digests a take-in wrote and no judge pass judged yet: the bucket + // mesh-delivery-indexer_unjudged, one key per manifest digest. + UnjudgedState = "unjudged" + UnjudgedBucket = Module + "_" + UnjudgedState +) + +// UnjudgedValue is one key of the unjudged state: the module whose new manifest the digest is, and the merge that wrote it. +type UnjudgedValue struct { + V int `json:"v"` + Module string `json:"module"` + Repository string `json:"repository,omitempty"` + Merge string `json:"merge,omitempty"` +} + +// keepUnjudged writes the digest into the unjudged state before the module naming it is written. A state not on the bus +// yet (an indexer whose delivery brings it) is said and the take-in goes on, judged from its memory alone as before; +// any other failure fails the write, so the module is not written with its digest unkept. +func (ix *Indexer) keepUnjudged(ctx context.Context, digest, module string, w *mergeWrite) error { + if ix.Unjudged == nil { + return nil + } + v := UnjudgedValue{V: 1, Module: module} + if w != nil { + v.Repository, v.Merge = w.repository, w.merge + } + data, err := json.Marshal(v) + if err != nil { + return err + } + err = write(ctx, ix.Unjudged, digest, func(value []byte, found bool) ([]byte, bool, error) { + if found { + return nil, false, nil // kept already: the first take-in that wrote it stands + } + return data, false, nil + }) + if errors.Is(err, process.ErrNotYet) { + ix.logf("judge: the state %s is not on the bus yet, so the new manifest %s of %s is kept for its judging only in this take-in", UnjudgedBucket, digest, module) + return nil + } + if err != nil { + return fmt.Errorf("%s.%s: %w", UnjudgedState, digest, err) + } + return nil +} + +// withUnjudged is fresh with every digest the unjudged state holds; a state that cannot be listed is said and fresh +// alone is judged. +func (ix *Indexer) withUnjudged(ctx context.Context, fresh map[string]bool) map[string]bool { + if ix.Unjudged == nil { + return fresh + } + keys, err := ix.Unjudged.Keys(ctx) + if err != nil { + if !errors.Is(err, process.ErrNotYet) { + ix.logf("judge: the state %s cannot be listed (%v), so only this take-in's new manifests are judged as new", UnjudgedBucket, err) + } + return fresh + } + if len(keys) == 0 { + return fresh + } + out := maps.Clone(fresh) + if out == nil { + out = map[string]bool{} + } + for _, k := range keys { + out[k] = true + } + return out +} + +// endUnjudged deletes each key of the unjudged state whose digest the pass judged with its verdict written, or which no +// module holds any more (a later merge replaced it): what is left waits for the next pass. +func (ix *Indexer) endUnjudged(ctx context.Context, judged, held map[string]bool) { + if ix.Unjudged == nil { + return + } + keys, err := ix.Unjudged.Keys(ctx) + if err != nil { + return + } + for _, k := range slices.Sorted(slices.Values(keys)) { + if held[k] && !judged[k] { + continue + } + if err := write(ctx, ix.Unjudged, k, func(_ []byte, found bool) ([]byte, bool, error) { return nil, found, nil }); err != nil { + ix.logf("judge: %s.%s is not ended: %v; judged again as new by the next pass", UnjudgedState, k, err) + } + } +} diff --git a/modules/mesh-delivery-indexer/internal/index/unreadcall.go b/modules/mesh-delivery-indexer/internal/index/unreadcall.go new file mode 100644 index 00000000..e8d2f1da --- /dev/null +++ b/modules/mesh-delivery-indexer/internal/index/unreadcall.go @@ -0,0 +1,69 @@ +package index + +import ( + "context" + "strings" + + mcc "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshconditionsclient" +) + +// **A merged message unread past five minutes, the forge heard, is a finding** (issue 1966 note 153; novox/hq ADR 0668 §3). +// The indexer's call for a merged message is a kept call: a transport fault leaves the merge unread (Pending.Unread) and +// it is read again after every message heard on the forge (UnreadAgain). A message heard on the forge is the forge bridge +// heard, the callee of that call: so after each one, a merge still unread since meshconditionsclient.CallUnansweredAfter +// or longer is the finding call-unanswered in the indexer's findings, which the condition keeper raises, and a merge no +// longer unread (read, taken in, covered or dropped) clears its finding. While nothing is heard on the forge (the bridge's +// machine away) no finding is written: the merge stays unread and is read again when the forge is heard. No timer. + +// UnreadCallee is the call the finding names: the forge bridge's tool for one merged message. +const UnreadCallee = ForgeBridgeModule + ".bridge_merged_message" + +// unreadCallID is the finding's id for the pending key: the merge it waits on. +func unreadCallID(key string) string { return "merged-message." + key } + +// unreadFindings raises the finding of every merge of entries unread past the bound and clears the finding of every other. +func (ix *Indexer) unreadFindings(ctx context.Context, entries []PendingEntry) { + if ix.Findings == nil { + return + } + unread := map[string]bool{} + for _, e := range entries { + if e.Value.Unread == "" { + continue + } + unread[mcc.Key(mcc.ScopeCall, unreadCallID(e.Key), mcc.KindCallUnanswered)] = true + since := e.Value.UnreadSince + if since.IsZero() || ix.now().Sub(since) < mcc.CallUnansweredAfter { + continue + } + o := mcc.CallUnanswered(unreadCallID(e.Key), UnreadCallee, "", e.Value.Unread, "indexer."+mcc.KindCallUnanswered, since) + o.Needs = TakeInPendingTool + " reads the merge again now; " + PendingTool + " shows it unread." + key := o.Key() + if err := write(ctx, ix.Findings, key, func(value []byte, found bool) ([]byte, bool, error) { + if found { + if f, err := mcc.DecodeFinding(value); err == nil && f.Summary == o.Summary { + return nil, false, nil + } + } + data, err := mcc.EncodeFinding(o.Finding(Module, "", ix.now().UTC())) + return data, false, err + }); err != nil { + ix.logf("take-in: the finding %s is not written: %v", key, err) + } else { + ix.logf("take-in: %s (%s#%d) is unread since %s and the forge is heard: the finding %s", e.Key, e.Forge.Repository, e.Forge.Number, since.Format("2006-01-02T15:04:05Z07:00"), key) + } + } + keys, err := ix.Findings.Keys(ctx) + if err != nil { + return + } + prefix, suffix := mcc.ScopeCall+"."+unreadCallID(""), "."+mcc.KindCallUnanswered + for _, k := range keys { + if !strings.HasPrefix(k, prefix) || !strings.HasSuffix(k, suffix) || unread[k] { + continue + } + if err := write(ctx, ix.Findings, k, func(_ []byte, found bool) ([]byte, bool, error) { return nil, found, nil }); err != nil { + ix.logf("take-in: the finding %s is not cleared: %v", k, err) + } + } +} diff --git a/modules/mesh-delivery-indexer/internal/index/verdicts.go b/modules/mesh-delivery-indexer/internal/index/verdicts.go index 75bdf287..24ce8159 100644 --- a/modules/mesh-delivery-indexer/internal/index/verdicts.go +++ b/modules/mesh-delivery-indexer/internal/index/verdicts.go @@ -84,21 +84,32 @@ func (ix *Indexer) judgeOverHeld(ctx context.Context, fresh map[string]bool, ove } if over == nil { ix.SayUnsaid(ctx) // a manifest-accepted a pass before failed to publish is said again first (DLV-I9b) + // What a take-in wrote and no pass judged yet is fresh too, whichever pass judges it (unjudged.go, issue 1966). + fresh = ix.withUnjudged(ctx, fresh) } held, err := ix.heldModules(ctx) if err != nil { return out, err } + heldDigests, judgedDigests := map[string]bool{}, map[string]bool{} + for _, m := range held { + heldDigests[m.Manifest] = m.Manifest != "" + } trunkOf := map[string]string{} // a judged change's module to the trunk's manifest digest it changes (DLV-I15) // The known packages a manifest's `packages` may name (DLV-I14). The digest judged the trunk does not hold (a pull // request's candidate, one the trunk no longer names) is not judged on them: the checker judges a change's names, // knowing its delivery group, whose new packages this state does not know yet (the lead's ruling, issue 1966). The // trunk's own manifests are, and a merge's are again in full (namesAtMerge). known := ix.knownPackages(ctx) + // A digest judged over the trunk that is the trunk's own held one is said as the full pass says it (manifest-accepted, + // manifest-refused): indexer_judge with it, or the start pass's judgeStale, is that manifest's only judgement (review + // round 1 of issue 1966; ADR 0668 §4). A candidate's verdict is said nowhere. + onTrunk := map[string]bool{} if over != nil { fresh = map[string]bool{} for module, digest := range over { m := held[module] + onTrunk[module] = m.Manifest == digest if m.Manifest != "" && m.Manifest != digest { trunkOf[module] = m.Manifest } @@ -212,7 +223,8 @@ func (ix *Indexer) judgeOverHeld(ctx context.Context, fresh map[string]bool, ove ix.logf("judge: the verdict on %s (digest %s) is not written: %v", name, digests[name], err) continue } - if wrote && over != nil { + judgedDigests[digests[name]] = true + if wrote && over != nil && !onTrunk[name] { out.Written++ ix.logf("judge: %s judged again by %s: %s", digests[name], id, v.State) } else if wrote { @@ -243,6 +255,7 @@ func (ix *Indexer) judgeOverHeld(ctx context.Context, fresh map[string]bool, ove if over != nil { return out, nil } + ix.endUnjudged(ctx, judgedDigests, heldDigests) if err := ix.keepOldSections(ctx, judge.CountOldSections(accepted), judge.CountOwnerReads(accepted)); err != nil { ix.logf("judge: the count of the old sections is not kept: %v", err) } diff --git a/modules/mesh-delivery-indexer/internal/index/verdicts_test.go b/modules/mesh-delivery-indexer/internal/index/verdicts_test.go index 681b4cfd..09d6cf52 100644 --- a/modules/mesh-delivery-indexer/internal/index/verdicts_test.go +++ b/modules/mesh-delivery-indexer/internal/index/verdicts_test.go @@ -13,6 +13,7 @@ import ( "git.novox.be/novox/mesh-delivery/contracts/go/seats/meshcatalog" "git.novox.be/novox/mesh-delivery/modules/mesh-delivery-forge-bridge/forgemsg" "git.novox.be/novox/mesh-sdk/go/catalogue" + "git.novox.be/novox/mesh-sdk/go/process" "mesh-delivery-indexer/judge" ) @@ -137,6 +138,37 @@ func TestTheIndexerJudgesEveryManifestOnce(t *testing.T) { if err := ix.writeOverlay(ctx, map[string]meshcatalog.ModulesByModuleValue{"old": same}, nil, w); err != nil || !w.fresh[other] { t.Fatalf("a changed digest is not fresh: %v %v", w.fresh, err) } + // 1966 (ADR 0668 §4, ADR 0579 §1): what a take-in newly wrote is kept on the bus until judged. A take-in writes a + // manifest a judge refuses in full, its judge pass fails on the verdicts state, and the next pass, which knows nothing + // of that take-in (a start, a pass kicked by a message), still refuses it in full, never as a warning, and ends the key. + ix.Unjudged = newMem() + keptDigest, err := ix.keepManifest(ctx, "kept", `{"module":"kept","version":"1","requires":["amqp"]}`) + if err != nil { + t.Fatal(err) + } + kw := &mergeWrite{repository: "novox/mesh-catalog", merge: "m-kept"} + keptValue := meshcatalog.ModulesByModuleValue{Fp2: "src2:" + strings.Repeat("e", 64), Manifest: keptDigest, Repository: "novox/mesh-catalog", Commit: "c3"} + if err := ix.writeOverlay(ctx, map[string]meshcatalog.ModulesByModuleValue{"kept": keptValue}, nil, kw); err != nil || !kw.fresh[keptDigest] { + t.Fatalf("the take-in's write: %v, fresh %v", err, kw.fresh) + } + if value, _, found, _ := ix.Unjudged.Get(ctx, keptDigest); !found || !strings.Contains(string(value), `"module":"kept"`) || !strings.Contains(string(value), "m-kept") { + t.Fatalf("the new manifest is not kept as unjudged: %s", value) + } + ix.Verdicts.(*memStore).failWrite = func(string) error { return process.ErrNotYet } + if _, err := ix.JudgeAll(ctx, kw.fresh); err == nil { + t.Fatal("a pass whose verdicts state is not on the bus did not fail") + } + ix.Verdicts.(*memStore).failWrite = nil + if j, err := ix.JudgeAll(ctx, nil); err != nil || slices.Contains(j.Outgrown, "kept") { + t.Fatalf("the next pass: %+v %v", j, err) + } + if v := verdict(keptDigest); !meshcatalogclient.VerdictRefuses(v) || len(v.Warnings) != 0 { + t.Fatalf("a refusal of a manifest whose judge pass failed became %+v", v) + } + if keys, err := ix.Unjudged.Keys(ctx); err != nil || len(keys) != 0 { + t.Fatalf("the unjudged state still holds %v (%v) after its verdict is written", keys, err) + } + ix.Unjudged = nil // 1966/AC10: a newly accepted manifest asking for bus state is said once as manifest-accepted, carrying both entries // whole; a verdict already held says nothing. var accepted []meshcatalog.ManifestAcceptedEvent @@ -183,6 +215,26 @@ func TestTheIndexerJudgesEveryManifestOnce(t *testing.T) { if last := accepted[len(accepted)-1]; last.Module != "plain" || last.Digest != plain || last.BusState == nil || len(last.BusState) != 0 { t.Fatalf("a manifest asking for no bus state was said as %+v", last) } + // Review round 1 of issue 1966: a trunk's held manifest judged by its digest (indexer_judge, judgeStale) is said as the + // full pass says it, accepted or refused; a candidate's digest judged over the trunk is said nowhere. + byDigest := hold("bydigest", `{"module":"bydigest","version":"1"}`) + refusedBy := hold("refusedby", `{"module":"refusedby","version":"1","requires":["amqp"]}`) + saidBefore := len(said) + for module, digest := range map[string]string{"bydigest": byDigest, "refusedby": refusedBy} { + if _, err := ix.judgeOver(ctx, nil, module, digest); err != nil { + t.Fatal(err) + } + } + if last := accepted[len(accepted)-1]; last.Digest != byDigest || len(said) != saidBefore+1 || said[len(said)-1].Digest != refusedBy { + t.Fatalf("judged by its digest, the trunk's manifest was said as %+v, refusals %d (were %d)", last, len(said), saidBefore) + } + candidate, err := ix.keepManifest(ctx, "bydigest", `{"module":"bydigest","version":"2"}`) + if err != nil { + t.Fatal(err) + } + if _, err := ix.judgeOver(ctx, nil, "bydigest", candidate); err != nil || accepted[len(accepted)-1].Digest != byDigest { + t.Fatalf("a candidate's verdict was said: %v %+v", err, accepted[len(accepted)-1]) + } // DLV-I9b: a failed publish is published again; one failing twice writes the finding naming the module, which the next // judging pass says again and clears. ix.Findings = newMem() diff --git a/modules/mesh-delivery-indexer/internal/index/views.go b/modules/mesh-delivery-indexer/internal/index/views.go index 3bb6ac6f..7bcffe38 100644 --- a/modules/mesh-delivery-indexer/internal/index/views.go +++ b/modules/mesh-delivery-indexer/internal/index/views.go @@ -32,6 +32,7 @@ var ReadTools = []ViewedTool{ {Tool: "indexer_read_taken", State: "taken", Words: "each repository's merge the indexer took in last."}, {Tool: "indexer_read_findings", State: mcc.FindingsState, Words: "the indexer's findings, which the condition keeper raises and clears."}, {Tool: "indexer_read_seat_definitions", State: SeatDefinitionsState, Words: "the seat definitions the trunk's and each open pull request's contracts modules hold, resolved, or why one does not parse."}, + {Tool: "indexer_read_unjudged", State: UnjudgedState, Words: "the manifests a take-in newly wrote that no judge pass judged yet, by digest, each with its module and merge; indexer_judge judges them."}, } // ViewedTool is one tool over one state of the indexer's. @@ -53,4 +54,5 @@ var ViewedStates = map[string]string{ "taken": TakenBucket, mcc.FindingsState: mcc.FindingsBucket(Module), SeatDefinitionsState: SeatDefinitionsBucket, + UnjudgedState: UnjudgedBucket, } diff --git a/modules/mesh-delivery-indexer/manifest_test.go b/modules/mesh-delivery-indexer/manifest_test.go index 1519ab5f..09028dc2 100644 --- a/modules/mesh-delivery-indexer/manifest_test.go +++ b/modules/mesh-delivery-indexer/manifest_test.go @@ -116,7 +116,7 @@ func TestManifestDeclarations(t *testing.T) { // 1238/AC1, 1444 (reads the build if want := []state{{Name: "candidates", History: 10}, {Name: "heard", History: 64}, {Name: "manifests", History: 1}, {Name: "modules", History: 20}, {Name: "predefined", History: 5}, {Name: "config-candidates", History: 5}, {Name: "taken", History: 1}, {Name: "takeins", History: 1}, {Name: "verdicts", History: 5}, {Name: "oldsections", History: 1}, {Name: "try-recovery", History: 1}, {Name: "own-build", History: 1}, {Name: index.PackagesState, History: index.PackagesHistory}, {Name: graph.State, History: graph.History}, {Name: views.MarksState, History: 1}, {Name: mcc.FindingsState, History: 5}, {Name: views.StatusState, History: 1}, {Name: index.RequirementsState, History: 5}, {Name: index.SeatDefinitionsState, History: 5}, - {Name: index.HoldsState, History: 5}, {Name: index.EngineReadsState, History: 1}, {Name: index.HoldBoundsState, History: 1, KeyTTL: true}, {Name: index.PendingState, History: 1}}; !reflect.DeepEqual(m.State, want) { // DLV-I7, DLV-I17, ADR 0632 §2 + {Name: index.HoldsState, History: 5}, {Name: index.EngineReadsState, History: 1}, {Name: index.HoldBoundsState, History: 1, KeyTTL: true}, {Name: index.PendingState, History: 1}, {Name: index.UnjudgedState, History: 1}}; !reflect.DeepEqual(m.State, want) { // DLV-I7, DLV-I17, ADR 0632 §2 t.Errorf("state = %+v, want %+v", m.State, want) } // D-11 (ADR 0634 §1): the holders and buckets the indexer names (internal/index/names.go) are its manifest's: its own @@ -157,7 +157,7 @@ func TestManifestDeclarations(t *testing.T) { // 1238/AC1, 1444 (reads the build // Three invokes: the file of a registered module's manifest and lock files (registered.go), the forge's trees (the named paths' objects, since the indexer is the one reader of a manifest's paths: // ADR 0499 clauses 2 and 3, ADR 0495 clause 1; and the module directories of the trunk, issue 1900) and whether a // commit is in another (issue 1900). - if want := []string{"mesh-delivery-assigner.assignments", "gitea.gitea_commit_trees", "gitea.gitea_contains", "gitea.gitea_get_file", "gitea.gitea_open_pulls", "mesh-delivery-checker.checker_tries", "mesh-delivery-forge-bridge.bridge_merged_message", "seat:node-engine.composition", "seat:node-engine.manifest-reads", "seat:mesh-hand-acts.hand-act"}; !reflect.DeepEqual(m.Invokes, want) { + if want := []string{"mesh-delivery-assigner.assignments", "gitea.gitea_commit_trees", "gitea.gitea_contains", "gitea.gitea_get_file", "gitea.gitea_open_pulls", "mesh-delivery-checker.checker_tries", "mesh-delivery-forge-bridge.bridge_merged_message", "seat:node-engine.composition", "seat:node-engine.manifest-reads", "seat:mesh-hand-acts.hand-act", "seat:mesh-watchdogs.presence"}; !reflect.DeepEqual(m.Invokes, want) { t.Errorf("invokes = %v, want %v", m.Invokes, want) } // 1945: indexer_take_in, served by its tools bundle through the takeins state; the process serves none. The same bundle @@ -176,7 +176,7 @@ func TestManifestDeclarations(t *testing.T) { // 1238/AC1, 1444 (reads the build index.SeatDefinitionTool, index.SeatDefinitionsAgainTool, index.OutOfStepTool, // DLV-I19 index.HoldsTool, index.EngineReadsTool, // ADR 0632 §2: the mesh-wide holds and the engines' reads they weigh index.PendingTool, index.TakeInPendingTool, index.DropPendingTool, index.TryCandidatesTool, index.DropTryCandidateTool, index.RecoverTriesTool, index.TakeInMergeTool, index.FingerprintsAgainTool) // issue 1966; 1585/T12, T13 (ADR 0633 §5) - if !reflect.DeepEqual(m.Tools, want) || len(want) != 39 { + if !reflect.DeepEqual(m.Tools, want) || len(want) != 40 { t.Errorf("tools = %v, want %v", m.Tools, want) } // Every read tool of the indexer a reader of this repository invokes is one it serves (the checker's seventh first diff --git a/modules/mesh-delivery-indexer/module.json b/modules/mesh-delivery-indexer/module.json index 67f8e7a5..c820abfc 100644 --- a/modules/mesh-delivery-indexer/module.json +++ b/modules/mesh-delivery-indexer/module.json @@ -36,6 +36,7 @@ "indexer_read_taken", "indexer_read_findings", "indexer_read_seat_definitions", + "indexer_read_unjudged", "indexer_first_views", "indexer_first_view_again", "indexer_config_readers", @@ -94,7 +95,8 @@ { "name": "holds", "history": 5 }, { "name": "engine-reads", "history": 1 }, { "name": "hold-bounds", "history": 1, "key-ttl": true }, - { "name": "pending", "history": 1 } + { "name": "pending", "history": 1 }, + { "name": "unjudged", "history": 1 } ], "emits": [ "take-in.pending", @@ -129,7 +131,8 @@ "mesh-delivery-forge-bridge.bridge_merged_message", "seat:node-engine.composition", "seat:node-engine.manifest-reads", - "seat:mesh-hand-acts.hand-act" + "seat:mesh-hand-acts.hand-act", + "seat:mesh-watchdogs.presence" ], "own-secrets": { "broker": "${dir:state}/broker" diff --git a/modules/mesh-delivery-indexer/takein/takein.go b/modules/mesh-delivery-indexer/takein/takein.go index 645535c2..59141f58 100644 --- a/modules/mesh-delivery-indexer/takein/takein.go +++ b/modules/mesh-delivery-indexer/takein/takein.go @@ -243,6 +243,9 @@ type PendingWait struct { SaidAt time.Time `json:"said-at,omitzero"` // Lost are the keys of its merges whose message the forge bridge's stream no longer holds (TakeIn.Lost). Lost []string `json:"lost,omitempty"` + // Unread are the keys of its merges whose message is unread for a transport fault: read again on the next message + // heard on the forge, at the start and by indexer_take_in_pending, never dropped for it (issue 1966, ADR 0668 §1). + Unread []string `json:"unread,omitempty"` // Refused is why the manifest of the indexer it names was refused (TakeIn.Refused). Refused string `json:"refused,omitempty"` } diff --git a/modules/mesh-delivery-teller/cmd/mesh-delivery-teller/assignerasks.go b/modules/mesh-delivery-teller/cmd/mesh-delivery-teller/assignerasks.go index 7e5dd9d4..e5f7ab28 100644 --- a/modules/mesh-delivery-teller/cmd/mesh-delivery-teller/assignerasks.go +++ b/modules/mesh-delivery-teller/cmd/mesh-delivery-teller/assignerasks.go @@ -191,10 +191,11 @@ func (t *Teller) raiseAssignerAsk(key string) { return } if err := t.Asker.Ask(a.Ask); err != nil { - t.logf("%s: the ask %s was not asked: %v", key, id, err) - if kept, _, _ := t.keptOf(id); open(kept) { - _ = t.Store.Delete(keptKey(id)) // kept but not published: forgotten, so the next writing of the key asks it - } + // Kept but not published (a transport fault, the router restarting): nothing writes the key again, so the ask is not + // forgotten but waits, kept on the bus, to be asked again at the next end and at the teller's start (issue 1966, + // ADR 0668 §1). Before, the record was deleted for "the next writing of the key", which never came. + t.logf("%s: the ask %s was not asked: %v; it waits to be asked again at the next end and at the start", key, id, err) + t.unheard(id) return } t.assignerAsked(id) diff --git a/modules/mesh-delivery-teller/cmd/mesh-delivery-teller/assignerasks_test.go b/modules/mesh-delivery-teller/cmd/mesh-delivery-teller/assignerasks_test.go index 8420dcbc..1604f9df 100644 --- a/modules/mesh-delivery-teller/cmd/mesh-delivery-teller/assignerasks_test.go +++ b/modules/mesh-delivery-teller/cmd/mesh-delivery-teller/assignerasks_test.go @@ -1,6 +1,7 @@ package main import ( + "errors" "slices" "encoding/json" @@ -34,6 +35,28 @@ func TestAnAssignerAskIsRaisedOnTheOperatorChannelOnce(t *testing.T) { if got.ID != ask.ID || occ.Digest(got) != occ.Digest(ask) { t.Errorf("the router's ask %+v differs from the assigner's", got) } + // Issue 1966, ADR 0668 §1: a publish that fails (the router restarting) is not forgotten: the ask waits, kept, and is + // asked at the teller's next start (or the next end), though nothing writes the assigner's key again. + b = newBed(t) + assigner, _ = withView(b) + assigner[key] = value + publish, failed := b.client.Publish, false + b.client.Publish = func(subject string, body any, id string) error { + if subject == oc.AcceptSubjectAsk(tellerModule) && !failed { + failed = true + return errors.New("nats: no responders available for request") + } + return publish(subject, body, id) + } + b.t.Publish = b.client.Publish + b.t.OnAssignerAsk(key) + if asked := b.askedOf(oc.AcceptSubjectAsk(tellerModule)); !failed || len(asked) != 0 { + t.Fatalf("published %d asks through a failing publish", len(asked)) + } + b.t.OnCurrent() + if asked := b.askedOf(oc.AcceptSubjectAsk(tellerModule)); len(asked) != 1 { + t.Errorf("after a failed publish and a start, published %d asks, want one; log:\n%s", len(asked), b.logs.String()) + } } // 1906/H1: without the view's bucket the assigner's asks are still raised. diff --git a/modules/mesh-delivery-watchman/cmd/mesh-delivery-watchman-tools/main.go b/modules/mesh-delivery-watchman/cmd/mesh-delivery-watchman-tools/main.go index 0ce55f26..fa5a0672 100644 --- a/modules/mesh-delivery-watchman/cmd/mesh-delivery-watchman-tools/main.go +++ b/modules/mesh-delivery-watchman/cmd/mesh-delivery-watchman-tools/main.go @@ -13,6 +13,7 @@ import ( "time" "git.novox.be/novox/mesh-contracts/health-and-repair/go/clients/meshhandactsclient" + "git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshwatchdogs" stdio "git.novox.be/novox/mesh-sdk/go" "git.novox.be/novox/mesh-sdk/go/views" @@ -105,6 +106,35 @@ var keyArgs = map[string]any{"type": "object", "properties": map[string]any{ "key": map[string]any{"type": "string", "description": "one key only"}, "prefix": map[string]any{"type": "string", "description": "only the keys that begin with it"}}} +// presenceArgs are the seat's input of presence, machine, beside the watchman's own key and prefix. +var presenceArgs = map[string]any{"type": "object", "properties": map[string]any{ + "machine": map[string]any{"type": "string", "description": "one machine: whether the watchman hears it and since when"}, + "key": map[string]any{"type": "string", "description": "one key only"}, + "prefix": map[string]any{"type": "string", "description": "only the keys that begin with it"}}} + +// presenceOf answers the seat's presence of one machine (meshwatchdogs.PresenceAnswer): online and since as the state +// presence holds it under the machine's key; a machine it holds no word of is not online, with no since (novox/hq ADR +// 0596 §2: a part asks this verb, never reads the state). +func presenceOf(st state, machine string) (any, error) { + e, err := st.Get(meshwatchdogs.PresenceByNodeKey(machine)) + if err != nil { + return nil, fmt.Errorf("presence %s cannot be read: %w", machine, err) + } + answer := meshwatchdogs.PresenceAnswer{Machine: machine} + if e == nil { + return answer, nil + } + v, err := meshwatchdogs.DecodePresenceByNodeValue(e.Value) + if err != nil { + return nil, fmt.Errorf("presence %s does not read: %w", machine, err) + } + answer.Online = v.Online + if !e.At.IsZero() { + answer.Since = e.At.UTC().Format(time.RFC3339Nano) + } + return answer, nil +} + // Tools are the seat's verbs and the module's tools, over the states states gives and the program asked through ask. func Tools(states func(string) state, ask func(socket.Ask) (json.RawMessage, error)) []stdio.Tool { read := func(name string) func(map[string]any) (any, error) { @@ -141,9 +171,15 @@ func Tools(states func(string) state, ask func(socket.Ask) (json.RawMessage, err Description: "What stopped moving: every key of the watchman's stuck bucket, . with what it waited for since " + "when, and whether it moved since (never deleted). A key not moved is also the watchman's finding " + "delivery..stuck, a node's presence machine..silent. Give key for one, prefix to narrow. Read-only."}, - {Name: verb(VerbPresence), Input: keyArgs, Run: read("presence"), + {Name: verb(VerbPresence), Input: presenceArgs, Run: func(args map[string]any) (any, error) { + if machine := str(args, "machine"); machine != "" { + return presenceOf(states("presence"), machine) + } + return read("presence")(args) + }, Description: "Who is online on the bus as the watchman hears it: each node's agent () and each delivery part's instance " + - "(part..), online or not since the entry's time. Give key for one, prefix to narrow. Read-only."}, + "(part..), online or not since the entry's time. Give machine for one machine's online and since, " + + "key for one key, prefix to narrow. Read-only."}, {Name: verb(VerbDeadLetters), Run: dead, Description: "What a consumer gave up on, kept in DEAD_LETTERS (novox/hq ADR 0564 §5, ADR 0264, ADR 0376): newest first, " + "for one consumer (its name or .), at most limit; one whole by id (a restricted one's body " + diff --git a/modules/mesh-delivery-watchman/cmd/mesh-delivery-watchman-tools/main_test.go b/modules/mesh-delivery-watchman/cmd/mesh-delivery-watchman-tools/main_test.go index 97a92628..d6100784 100644 --- a/modules/mesh-delivery-watchman/cmd/mesh-delivery-watchman-tools/main_test.go +++ b/modules/mesh-delivery-watchman/cmd/mesh-delivery-watchman-tools/main_test.go @@ -4,9 +4,12 @@ import ( "encoding/json" "errors" "os" + "reflect" "slices" "testing" + "time" + "git.novox.be/novox/mesh-contracts/health-and-repair/go/seats/meshwatchdogs" stdio "git.novox.be/novox/mesh-sdk/go" "mesh-delivery-watchman/internal/socket" @@ -27,7 +30,7 @@ func (f fakeState) Get(key string) (*stdio.StateEntry, error) { if !ok { return nil, nil } - return &stdio.StateEntry{Key: key, Value: json.RawMessage(v), Revision: 3}, nil + return &stdio.StateEntry{Key: key, Value: json.RawMessage(v), Revision: 3, At: time.Date(2026, 11, 10, 3, 0, 0, 0, time.UTC)}, nil } // 1952/WM1, ADR 0564 §12: every state the manifest keeps is read by a tool, every act the program starts by hand is @@ -51,7 +54,8 @@ func TestEveryStateAndActHasATool(t *testing.T) { t.Fatal(err) } asked := []socket.Ask{} - states := map[string]fakeState{"findings": {"machine.ace.silent": `{"v":1}`, "core.doctor.self-check-silent": `{"v":1}`}} + states := map[string]fakeState{"findings": {"machine.ace.silent": `{"v":1}`, "core.doctor.self-check-silent": `{"v":1}`}, + "presence": {"ace": `{"v":1,"online":true}`, "g14": `{"v":1,"online":false}`, "part.mesh-delivery-builder.ace": `{"v":1,"online":true}`}} tools := Tools(func(name string) state { return states[name] }, func(a socket.Ask) (json.RawMessage, error) { asked = append(asked, a) if a.Act != "" { @@ -126,6 +130,31 @@ func TestEveryStateAndActHasATool(t *testing.T) { t.Fatal("a key not held is answered") } }) + // Issue 1966, ADR 0596 §2 (review round 3): presence with the seat's machine answers that machine's online and since in + // the seat's declared answer; one the watchman holds no word of is not online; without it, the keys as before. + t.Run("presence answers one machine as the seat declares", func(t *testing.T) { + for machine, want := range map[string]meshwatchdogs.PresenceAnswer{ + "ace": {Machine: "ace", Online: true, Since: "2026-11-10T03:00:00Z"}, + "g14": {Machine: "g14", Since: "2026-11-10T03:00:00Z"}, + "novox": {Machine: "novox"}, + } { + out, err := served[Seat+"."+VerbPresence].Run(map[string]any{"machine": machine}) + if err != nil { + t.Fatal(err) + } + b, _ := json.Marshal(out) + var got meshwatchdogs.PresenceAnswer + if err := json.Unmarshal(b, &got); err != nil || !reflect.DeepEqual(got, want) { + t.Errorf("presence of %s = %s (%v), want %+v", machine, b, err, want) + } + } + out, _ := served[Seat+"."+VerbPresence].Run(map[string]any{"prefix": "part."}) + b, _ := json.Marshal(out) + var whole meshwatchdogs.PresenceAnswer + if err := json.Unmarshal(b, &whole); err != nil || whole.Holds != 3 || len(whole.Keys) != 1 || whole.State != "presence" { + t.Errorf("presence whole = %s (%v)", b, err) + } + }) t.Run("dead-letters and resync ask the program", func(t *testing.T) { if _, err := served[Seat+"."+VerbDeadLetters].Run(map[string]any{"consumer": "ace_web", "limit": float64(3), "id": float64(7)}); err != nil { t.Fatal(err)