builder_build_again: register the look in one critical section, and answer what the build did

Review round 1 (issue 1126 note 72): the inflight check, the watch and the look were three locks, so a second request or the builder's own look could build the key twice; the answer said asked when the look wrote nothing or the build failed before its asks.

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
 			}},

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()

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
+}

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]

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)

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"`
 }