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 24f16218..71dd3e3d 100644 --- a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/main.go +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/main.go @@ -19,6 +19,7 @@ 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-delivery/modules/mesh-delivery-builder/buildrun" @@ -186,6 +187,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. @@ -396,6 +402,10 @@ 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 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/refused_test.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/refused_test.go index 0994e9e9..9d1b8050 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 @@ -391,6 +391,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") @@ -490,6 +532,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/run.go b/modules/mesh-delivery-builder/internal/build/run.go index 36a9b468..a7711f09 100644 --- a/modules/mesh-delivery-builder/internal/build/run.go +++ b/modules/mesh-delivery-builder/internal/build/run.go @@ -53,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 @@ -132,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 @@ -551,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) diff --git a/modules/mesh-delivery-builder/internal/build/run_test.go b/modules/mesh-delivery-builder/internal/build/run_test.go index a1429211..cfc3ad9b 100644 --- a/modules/mesh-delivery-builder/internal/build/run_test.go +++ b/modules/mesh-delivery-builder/internal/build/run_test.go @@ -1381,6 +1381,23 @@ func TestAnAskTheKeyNamesAndNobodyPutIsPutAtStart(t *testing.T) { 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 {