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 25d7794..0b093ad 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 @@ -85,6 +85,12 @@ func Tools(r build.StuckReader, askAgain func(key string, value []byte) error, q if r.Refused { return nil, errors.New(r.Answer) } + if r.Failed != "" { + return nil, errors.New(r.Answer) + } + if r.Revision == 0 && !r.Pending { + return nil, fmt.Errorf("the builder answered neither a new revision nor a refusal (an older builder?): %s", r.Answer) + } return map[string]any{"key": key, "revision": r.Revision, "asks": r.Asks, "answer": r.Answer, "next": build.StuckTool + " shows the key and its asks while they wait"}, nil }}, diff --git a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/reasks.go b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/reasks.go index 70d8b00..04836a7 100644 --- a/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/reasks.go +++ b/modules/mesh-delivery-builder/cmd/mesh-delivery-builder/reasks.go @@ -92,10 +92,16 @@ func builtAgain(ctx context.Context, b askAgainer, kv jetstream.KeyValue, e jets switch { case res.Refused != "": r.Answer, r.Refused = res.Refused, true + case res.Failed != "": + r.Answer, r.Revision, r.Failed = fmt.Sprintf("the key is written building as revision %d, and the build failed before any ask was put: %s", res.Revision, res.Failed), res.Revision, res.Failed default: + r.Pending = res.Revision == 0 r.Answer, r.Revision, r.Asks = "built again: the key is written building as revision "+fmt.Sprint(res.Revision)+" and its asks are put", res.Revision, res.Asks if res.Pending != "" { - r.Answer += "; " + res.Pending + r.Answer = res.Pending + if res.Revision != 0 { + r.Answer = "built again: the key is written building as revision " + fmt.Sprint(res.Revision) + "; " + res.Pending + } } } r.Answered = time.Now().UTC() diff --git a/modules/mesh-delivery-builder/internal/build/buildagain.go b/modules/mesh-delivery-builder/internal/build/buildagain.go index 0ae3f35..16e9a1c 100644 --- a/modules/mesh-delivery-builder/internal/build/buildagain.go +++ b/modules/mesh-delivery-builder/internal/build/buildagain.go @@ -26,8 +26,11 @@ type BuildAgainResult struct { // Revision is the revision the claim wrote; Asks are the ask ids put by language, as far as they were put within the bound. Revision uint64 Asks map[string]string - // Pending says the builder had not put every ask when it answered. + // Pending says the builder had not claimed the key, or not put every ask, when it answered: not a refusal. Pending string + // Failed is the error of the key when the build ended failed before its asks were put (a plan that cannot be read, a + // toolchain not agreed): the new revision was written, and nothing was asked. + Failed string } // handWatch follows one request to build a key again until its asks are put. @@ -37,6 +40,8 @@ type handWatch struct { asks map[string]string done chan struct{} shut bool + // ended is set when the look ended before the asks were all put. + ended bool } // settle closes done once the claim is written and every lane has put its ask. Call with b.mu held. @@ -71,7 +76,7 @@ func (b *Builder) handAsk(key, language, id string) { func (b *Builder) handEnded(key string) { b.hand(key, func(w *handWatch) { if !w.shut { - w.shut = true + w.shut, w.ended = true, true close(w.done) } }) @@ -108,27 +113,34 @@ func (b *Builder) BuildAgain(ctx context.Context, module, fp, why, by string, bo case delivery.FailedUntilChanged(cur.Error) || strings.HasPrefix(cur.Error, buildrun.DigestsDifferPrefix): return BuildAgainResult{Refused: fmt.Sprintf("%s failed for a reason the builder does not retry on the same fingerprint, it waits for another fingerprint: %s", key, cur.Error)} } - b.mu.Lock() - m, known := b.known[module] - busy := b.inflight[key] - b.mu.Unlock() - switch { - case !known || m.FP2 != fp: - return BuildAgainResult{Refused: fmt.Sprintf("module %s does not have the fingerprint %s now (a newer one superseded it, or its modules value is not read yet): the builder builds the module's current fingerprint", module, fp)} - case busy: - return BuildAgainResult{Refused: fmt.Sprintf("%s is being looked at by this builder now: wait for it to end", key)} - } + // One critical section: the key is refused when it is looked at or asked already, the module still has the fingerprint, + // and the watch and the look are registered before anything else can take the key. w := &handWatch{lanes: -1, asks: map[string]string{}, done: make(chan struct{})} b.mu.Lock() + m, known := b.known[module] + switch { + case !known || m.FP2 != fp: + b.mu.Unlock() + return BuildAgainResult{Refused: fmt.Sprintf("module %s does not have the fingerprint %s now (a newer one superseded it, or its modules value is not read yet): the builder builds the module's current fingerprint", module, fp)} + case m.Manifest == "": + b.mu.Unlock() + return BuildAgainResult{Refused: fmt.Sprintf("module %s names no manifest at %s yet, so the builder looks at nothing", module, fp)} + case b.inflight[key] || b.hands[key] != nil: + b.mu.Unlock() + return BuildAgainResult{Refused: fmt.Sprintf("%s is being looked at by this builder now (or asked again by hand): wait for it to end", key)} + } b.hands[key] = w + b.inflight[key] = true b.mu.Unlock() defer func() { b.mu.Lock() - delete(b.hands, key) + if b.hands[key] == w { + delete(b.hands, key) + } b.mu.Unlock() }() b.logf("%s: failed (%s); built again by hand, asked by %s: %s", key, cur.Error, by, why) - b.consider(ctx, module, m) + 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() select { @@ -136,15 +148,30 @@ func (b *Builder) BuildAgain(ctx context.Context, module, fp, why, by string, bo case <-wait.Done(): } b.mu.Lock() - defer b.mu.Unlock() res := BuildAgainResult{Revision: w.rev, Asks: maps.Clone(w.asks)} + ended, shut, lanes := w.ended, w.shut, w.lanes + b.mu.Unlock() switch { - case w.rev == 0 && w.shut: + case res.Revision == 0 && shut: res.Refused = fmt.Sprintf("the builder looked at %s and wrote nothing (a toolchain moved, the claim was lost or could not be written): its log says why", key) - case w.rev == 0: - res.Refused = fmt.Sprintf("the builder has not claimed %s within %s: it waits behind other builds; builder_stuck shows where it stands", key, bound) - case !w.shut: - res.Pending = fmt.Sprintf("the key is building at revision %d, and not every ask was put within %s; builder_stuck shows the asks", w.rev, bound) + case res.Revision == 0: + res.Pending = fmt.Sprintf("the builder has not claimed %s within %s: it waits behind other builds; builder_stuck shows where it stands", key, bound) + case ended && len(res.Asks) < max(lanes, 0)+boolInt(lanes < 0): + // The look ended before every ask was put: say how the key stands, not that it was asked. + if v, _, found, err := b.Claimer.Store.Get(ctx, key); err == nil && found { + if cur, err := delivery.DecodeBuilderBuild(v); err == nil && cur.State == delivery.BuildFailed { + res.Failed = cur.Error + } + } + case !shut: + res.Pending = fmt.Sprintf("the key is building at revision %d, and not every ask was put within %s; builder_stuck shows the asks", res.Revision, bound) } return res } + +func boolInt(b bool) int { + if b { + return 1 + } + return 0 +} diff --git a/modules/mesh-delivery-builder/internal/build/run.go b/modules/mesh-delivery-builder/internal/build/run.go index 45fa6d5..0bd1051 100644 --- a/modules/mesh-delivery-builder/internal/build/run.go +++ b/modules/mesh-delivery-builder/internal/build/run.go @@ -375,9 +375,29 @@ func (b *Builder) consider(ctx context.Context, module string, m delivery.Module }() } +// startOnce looks at the module once, for a key the caller has set inflight already (BuildAgain): it never falls into +// again, so the key is not built a second time, and clears inflight when the look ends. +func (b *Builder) startOnce(ctx context.Context, key, module string, m delivery.Module) { + b.wg.Add(1) + go func() { + defer b.wg.Done() + defer func() { + b.mu.Lock() + delete(b.again, key) + delete(b.inflight, key) + b.mu.Unlock() + }() + b.sem <- struct{}{} + defer func() { <-b.sem }() + b.try(ctx, module, m) + }() +} + // try claims the fingerprint and builds it, writing the key done or failed. A build that ends because ctx did is left // building by this builder: it takes it again when it starts (ADR 0478 clause 5). func (b *Builder) try(ctx context.Context, module string, m delivery.Module) { + key, _ := delivery.BuilderBuildKey(module, m.FP2) + defer b.handEnded(key) plan, planErr, read := b.planOf(ctx, m.Manifest) nothing := read && planErr == nil && len(plan.Tasks) == 0 if planErr == nil && !nothing { @@ -388,8 +408,6 @@ func (b *Builder) try(ctx context.Context, module string, m delivery.Module) { return } } - key, _ := delivery.BuilderBuildKey(module, m.FP2) - defer b.handEnded(key) b.mu.Lock() trunk := b.trunkFP[key] first := !b.tried[key] diff --git a/modules/mesh-delivery-builder/internal/build/run_test.go b/modules/mesh-delivery-builder/internal/build/run_test.go index e2e822d..884f892 100644 --- a/modules/mesh-delivery-builder/internal/build/run_test.go +++ b/modules/mesh-delivery-builder/internal/build/run_test.go @@ -701,7 +701,26 @@ func TestABuildAskWaitingInItsStreamIsNotBounded(t *testing.T) { key *delivery.BuilderBuild known string refuse string + // edit changes the module the builder has read, busy marks the key looked at (1) or asked by hand (2), failed is a part of + // the error the key then holds when its build ends before its asks are put. + edit func(m *delivery.Module) + busy int + failed string }{ + {name: "build again: a key looked at by the builder now is refused, not built twice", again: true, refuse: "is being looked at", busy: 1, + key: &delivery.BuilderBuild{State: delivery.BuildFailed, Error: "ace: no tun"}}, + {name: "build again: a key already asked by hand is refused, its watch kept", again: true, refuse: "is being looked at", busy: 2, + key: &delivery.BuilderBuild{State: delivery.BuildFailed, Error: "ace: no tun"}}, + {name: "build again: a module with no manifest is refused", again: true, refuse: "names no manifest", edit: func(m *delivery.Module) { m.Manifest = "" }, + key: &delivery.BuilderBuild{State: delivery.BuildFailed, Error: "ace: no tun"}}, + {name: "build again: a toolchain that moved writes nothing and is said at once", again: true, refuse: "wrote nothing", + edit: func(m *delivery.Module) { + m.Toolchains = map[string]delivery.ToolchainUsed{"go": {Version: "go1.0", Recipe: "1"}} + }, + key: &delivery.BuilderBuild{State: delivery.BuildFailed, Error: "ace: no tun"}}, + {name: "build again: a build that fails before its asks says the key failed, not that it was asked", again: true, failed: "cannot be read", + edit: func(m *delivery.Module) { m.Manifest = mdigest('b') }, + key: &delivery.BuilderBuild{State: delivery.BuildFailed, Error: "ace: no tun"}}, {name: "build again: a failed key is written building as a new revision and asks the seat", again: true, key: &delivery.BuilderBuild{State: delivery.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", @@ -734,7 +753,16 @@ func TestABuildAskWaitingInItsStreamIsNotBounded(t *testing.T) { if c.known != "" { m.FP2 = c.known } + if c.edit != nil { + c.edit(&m) + } r.b.init() + switch c.busy { + case 1: + r.b.inflight[r.key] = true + case 2: + r.b.hands[r.key] = &handWatch{} + } r.b.known["m"] = m // the builder has read the modules value, and looks at nothing until asked log := &logged{} r.b.Logf = log.logf @@ -747,6 +775,12 @@ func TestABuildAskWaitingInItsStreamIsNotBounded(t *testing.T) { } return } + if c.failed != "" { + if !strings.Contains(res.Failed, c.failed) || res.Revision <= rev || len(res.Asks) != 0 || len(r.asks.Asks()) != 0 { + t.Fatalf("answer %+v after %d asks; want a new revision (was %d), no ask and the key's failure %q", res, len(r.asks.Asks()), rev, c.failed) + } + return + } asks := r.asks.Asks() if res.Refused != "" || res.Pending != "" || res.Revision <= rev || len(asks) != 1 || res.Asks[delivery.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) diff --git a/modules/mesh-delivery-builder/internal/build/stuck.go b/modules/mesh-delivery-builder/internal/build/stuck.go index 66d4cc3..66ba529 100644 --- a/modules/mesh-delivery-builder/internal/build/stuck.go +++ b/modules/mesh-delivery-builder/internal/build/stuck.go @@ -44,7 +44,11 @@ type ReAsk struct { FP string `json:"fp,omitempty"` // Refused, Revision and Asks are the builder's answer to a ModeBuild request: why it did nothing, or the key's new // revision (building) and the ask ids it put by language. - Refused bool `json:"refused,omitempty"` + Refused bool `json:"refused,omitempty"` + // Pending says the builder answered before the key was claimed or all its asks were put: neither a refusal nor done. + // Failed is the error of a key written building that failed before its asks were put. + Pending bool `json:"pending,omitempty"` + Failed string `json:"failed,omitempty"` Revision uint64 `json:"revision,omitempty"` Asks map[string]string `json:"asks,omitempty"` }