Merge pull request 'Answer a single pull request's check with its request id on clean standard output (issue 1311)' (#403) from feat/no-terminal into main

cmd/mesh-controller/checks.go

@@ -4,6 +4,8 @@ import (
 	"context"
 	"encoding/json"
 	"fmt"
+	"io"
+	"os"
 	"path"
 	"regexp"
 	"runtime/debug"
@@ -141,18 +143,26 @@ func sourceOwner(repository string) string {
 
 // PullUpdated decides a pull request's merge check, and asks for it when there is something to run.
 func (f following) PullUpdated(ctx context.Context, p link.PullUpdated) error {
+	_, err := f.pullUpdated(ctx, p, os.Stdout)
+	return err
+}
+
+// pullUpdated is PullUpdated saying what it did to w. It returns the id of the check it asked of the build seat, or
+// "" when it said a verdict itself and asked nothing. A command that answers JSON on standard output (`delivery
+// check`) gives it standard error, so its output stays the document alone (novox/hq issue 1311).
+func (f following) pullUpdated(ctx context.Context, p link.PullUpdated, w io.Writer) (string, error) {
 	inv := f.open.inventory
 	entries, err := inv.Catalogued(ctx)
 	if err != nil {
-		return err
+		return "", err
 	}
 	read, err := readForPlanning(ctx, inv)
 	if err != nil {
-		return err
+		return "", err
 	}
 	edges, err := inv.Dependencies(ctx)
 	if err != nil {
-		return err
+		return "", err
 	}
 	scope := pullScope(p, entries, read, edges)
 	// **A cycle of edges fails the check, naming every module and edge** (novox/hq ADR 0419 clause 6), a lone pull
@@ -161,12 +171,12 @@ func (f following) PullUpdated(ctx context.Context, p link.PullUpdated) error {
 		Head: p.Commit, Number: p.Number, Paths: p.Paths, PathsTruncated: p.PathsTruncated, Removed: p.Removed, BaseSHA: p.BaseSHA}
 	if failing, cyclic, err := cycleVerdict(ctx, "", []orderMember{alone},
 		map[string]orderReach{alone.ID: {Moved: scope.Modules}}, edges, entries); err != nil {
-		return err
+		return "", err
 	} else if cyclic {
 		failing.Commit, failing.Trunk = p.Commit, twelve(p.BaseSHA)
-		fmt.Printf("%s/%s#%d (%.8s): %s\n", p.Owner, p.Repo, p.Number, p.Commit, failing.Summary)
+		fmt.Fprintf(w, "%s/%s#%d (%.8s): %s\n", p.Owner, p.Repo, p.Number, p.Commit, failing.Summary)
-		sayChecked(ctx, failing)
+		sayChecked(ctx, w, failing)
-		return nil
+		return "", nil
 	}
 	// **A member of a group whose gate is the composed check's runs its repository's check alone** (novox/hq ADR 0403
 	// clause 1): mesh-delivery is asked once, and says so on the group's line. Told nothing, the pull request is
@@ -179,7 +189,7 @@ func (f following) PullUpdated(ctx context.Context, p link.PullUpdated) error {
 		u, err := inv.UpgradeOf(ctx, module)
 		return u, err == nil
 	})
-	fmt.Print(planText(plan))
+	fmt.Fprint(w, planText(plan))
 	direct := directVerdict(p, plan)
 	if composed {
 		scope.Modules, scope.Dependents, scope.New, scope.Manifests = nil, nil, nil, nil
@@ -187,19 +197,19 @@ func (f following) PullUpdated(ctx context.Context, p link.PullUpdated) error {
 	}
 	switch {
 	case !scope.gated() && !scope.Mesh:
-		fmt.Printf("%s/%s#%d (%.8s): %s, and the repository is not the mesh's: said, nothing run\n",
+		fmt.Fprintf(w, "%s/%s#%d (%.8s): %s, and the repository is not the mesh's: said, nothing run\n",
 			p.Owner, p.Repo, p.Number, p.Commit, noModuleTouched)
-		sayChecked(ctx, direct)
+		sayChecked(ctx, w, direct)
-		return nil
+		return "", nil
 	case !scope.gated() && p.MergeCheckSaid && !p.MergeCheck:
 		direct.RepoCheck = &link.CheckLayer{Verdict: "warning", Summary: noMergeCheck}
-		fmt.Printf("%s/%s#%d (%.8s): %s; %s\n", p.Owner, p.Repo, p.Number, p.Commit, noModuleTouched, noMergeCheck)
+		fmt.Fprintf(w, "%s/%s#%d (%.8s): %s; %s\n", p.Owner, p.Repo, p.Number, p.Commit, noModuleTouched, noMergeCheck)
-		sayChecked(ctx, direct)
+		sayChecked(ctx, w, direct)
-		return nil
+		return "", nil
 	}
 	request, err := checkRequestFor(ctx, f.open, p, scope, entries)
 	if err != nil {
-		return err
+		return "", err
 	}
 	request.Check.Plan = &plan
 	request.Check.Composed = composed
@@ -208,11 +218,11 @@ func (f following) PullUpdated(ctx context.Context, p link.PullUpdated) error {
 	seat := buildSeatHeld(ctx)
 	ask, err := askOverOn(seat)
 	if err != nil {
-		return err
+		return "", err
 	}
 	defer ask.Close()
 	if err := ask.Ask(ctx, request); err != nil {
-		return err
+		return "", err
 	}
 	// **A newer request replaces the one still waiting, and a newer key stops the one running** (novox/hq ADR 0406 §3, §4,
 	// issue 974): the check queue keeps one request a pull request, and a running check watches its key. Nothing is asked
@@ -226,9 +236,9 @@ func (f following) PullUpdated(ctx context.Context, p link.PullUpdated) error {
 			strings.Join(append(append([]string{}, scope.Modules...), prefixedAll("new:", scope.New)...), ", "),
 			scope.Width, scope.Tiers)
 	}
-	fmt.Printf("%s/%s#%d (%.8s): asked %s to check it before it merges — %s — as %s\n", p.Owner, p.Repo, p.Number,
+	fmt.Fprintf(w, "%s/%s#%d (%.8s): asked %s to check it before it merges — %s — as %s\n", p.Owner, p.Repo, p.Number,
 		p.Commit, seat, what, request.ID)
-	return nil
+	return request.ID, nil
 }
 
 // composedWords is what a group member's own verdict says of its gate layer (novox/hq ADR 0403 clause 1).
@@ -528,7 +538,7 @@ func checked(ctx context.Context, result link.BuildResult) {
 		fmt.Printf("%s: stopped, its pull request's key moved on; the newer check will judge\n", result.ID)
 		return
 	}
-	sayChecked(ctx, checkedOf(result))
+	sayChecked(ctx, os.Stdout, checkedOf(result))
 }
 
 // checkedOf is what a check's outcome says: each layer, and an error — never a pass — for a check that
@@ -644,7 +654,7 @@ func prefixedAll(prefix string, items []string) []string {
 }
 
 // sayChecked says a merge check's verdict on the bus, where the forge's holder hears it.
-func sayChecked(ctx context.Context, c link.Checked) {
+func sayChecked(ctx context.Context, w io.Writer, c link.Checked) {
 	repo := "none"
 	if c.RepoCheck != nil {
 		repo = strings.ToUpper(c.RepoCheck.Verdict) + " — " + c.RepoCheck.Summary
@@ -653,7 +663,7 @@ func sayChecked(ctx context.Context, c link.Checked) {
 	if c.Trunk != "" {
 		judged = " merged into trunk " + c.Trunk
 	}
-	fmt.Printf("%s: %s/%s#%d at %.8s%s checked on %s: gate %s — %s; repository %s\n", c.ID, c.Owner, c.Repo, c.Number,
+	fmt.Fprintf(w, "%s: %s/%s#%d at %.8s%s checked on %s: gate %s — %s; repository %s\n", c.ID, c.Owner, c.Repo, c.Number,
 		c.Commit, judged, orSomewhere(c.On), strings.ToUpper(c.Verdict), c.Summary, repo)
 	if checkEvents == nil {
 		return
@@ -665,7 +675,7 @@ func sayChecked(ctx context.Context, c link.Checked) {
 	stating, stop := context.WithTimeout(context.WithoutCancel(ctx), 10*time.Second)
 	defer stop()
 	if err := checkEvents.PublishSeatEvent(stating, link.MeshControllerSeat, link.KeyChecked, body); err != nil {
-		fmt.Printf("%s: the verdict could not be said, so the pull request is not told it: %v\n", c.ID, err)
+		fmt.Fprintf(w, "%s: the verdict could not be said, so the pull request is not told it: %v\n", c.ID, err)
 	}
 }
 

cmd/mesh-controller/delivery.go

@@ -902,10 +902,14 @@ func deliveryCommand(ctx context.Context, args []string) error {
 		if *group == "" && len(members) == 1 {
 			// One head, checked again as the forge's announcement would have it (a recheck): the controller's
 			// own path for a pull request, run because the delivery's owner asked.
-			if err := sayingOnTheBus(ctx, inv, func() error { return (following{open: open, oneShot: true}).PullUpdated(ctx, members[0].pull()) }); err != nil {
+			return recheckOneHead(members[0].ID, answer, func() (string, error) {
-				return err
+				var asked string
-			}
+				err := sayingOnTheBus(ctx, inv, func() (err error) {
-			return answer(map[string]any{"rechecked": members[0].ID})
+					asked, err = (following{open: open, oneShot: true}).pullUpdated(ctx, members[0].pull(), os.Stderr)
+					return err
+				})
+				return asked, err
+			})
 		}
 		if *group == "" || len(members) < 2 {
 			return errors.New("delivery check --group <id> --members <json> (two heads or more), or --members <one head>")
@@ -1156,7 +1160,7 @@ func askGroupCheck(ctx context.Context, open *stores, group string, members []or
 	if failing, cyclic, err := cycleVerdict(ctx, group, members, reach, edges, entries); err != nil {
 		return "", err
 	} else if cyclic {
-		sayChecked(ctx, failing)
+		sayChecked(ctx, os.Stderr, failing)
 		return failing.ID, nil
 	}
 	primary := groupPrimary(members, reach)
@@ -1376,3 +1380,25 @@ func overNATS(conn *nats.Conn) (link.Bus, error) {
 	}
 	return link.OverNATS{Conn: conn, JS: js}, nil
 }
+
+// recheckAnswer is what `delivery check` answers for one head: the id of the check asked of the build seat (empty when
+// the controller said the verdict itself and asked nothing), which mesh-delivery reads, and the head rechecked.
+func recheckAnswer(asked, member string) map[string]any {
+	return map[string]any{"asked": asked, "rechecked": member}
+}
+
+// recheckOneHead runs a one-head `delivery check` and answers it as data. Standard output is the answer's JSON alone,
+// or the seat verb reads no answer from it (novox/hq issue 1311): while the check runs, whatever it prints to standard
+// output (the controller's own path prints its prose there, as do the stores it reads) goes to standard error.
+func recheckOneHead(member string, answer func(any) error, ask func() (string, error)) error {
+	real := os.Stdout
+	os.Stdout = os.Stderr
+	asked, err := func() (string, error) {
+		defer func() { os.Stdout = real }()
+		return ask()
+	}()
+	if err != nil {
+		return err
+	}
+	return answer(recheckAnswer(asked, member))
+}

cmd/mesh-controller/delivery_check_answer_test.go

@@ -0,0 +1,85 @@
+package main
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"fmt"
+	"os"
+	"strings"
+	"testing"
+
+	"github.com/novox/mesh-controller/internal/link"
+)
+
+// `delivery check` with one head answers the id of the check it asked, as data (novox/hq issue 1311): the prose
+// the check says goes to standard error, so standard output is the document alone and answerOf reads it.
+func TestDeliveryCheckOfOneHeadAnswersTheRequestID(t *testing.T) {
+	argv := []string{"delivery", "check", "--members", "[]"}
+	doc, err := json.Marshal(recheckAnswer("check-42", "novox/x@abc"))
+	if err != nil {
+		t.Fatal(err)
+	}
+	// Seen failing first: the prose the command used to print on standard output before the document.
+	polluted := append([]byte("novox/x#7 (abc): asked the build seat as check-42\n"), doc...)
+	if got := answerOf(argv, polluted, "", true); got.Answer != nil {
+		t.Fatalf("prose before the document should leave no answer; got %v", got.Answer)
+	}
+	got := answerOf(argv, doc, "novox/x#7 (abc): asked the build seat as check-42\n", true)
+	m, ok := got.Answer.(map[string]any)
+	if !ok || m["asked"] != "check-42" || m["rechecked"] != "novox/x@abc" {
+		t.Fatalf("the answer is %v; want asked check-42 and rechecked novox/x@abc", got.Answer)
+	}
+	if !strings.Contains(got.Output, "asked the build seat") {
+		t.Fatalf("the prose is still said in the text: %q", got.Output)
+	}
+}
+
+// The text of the other callers does not change: sayChecked writes the same line to the writer it is given, and
+// the controller's own path still gives PullUpdated standard output.
+func TestSayCheckedWritesTheSameLineToItsWriter(t *testing.T) {
+	var w bytes.Buffer
+	sayChecked(context.Background(), &w, link.Checked{ID: "c1", Owner: "novox", Repo: "x", Number: 7, Commit: "0123456789abcdef",
+		Verdict: "pass", Summary: "fine"})
+	want := "c1: novox/x#7 at 01234567 checked on a machine that did not say which: gate PASS — fine; repository none\n"
+	if w.String() != want {
+		t.Fatalf("sayChecked said %q; want %q", w.String(), want)
+	}
+}
+
+// Whatever the check prints to standard output while it runs (checks.go namedForTheCheck, the inventory's pointer
+// repair) must not reach the answer's standard output: it is exactly one JSON document (novox/hq issue 1311).
+func TestOneHeadRecheckLeavesStandardOutputTheAnswerAlone(t *testing.T) {
+	r, w, err := os.Pipe()
+	if err != nil {
+		t.Fatal(err)
+	}
+	e, ew, err := os.Pipe()
+	if err != nil {
+		t.Fatal(err)
+	}
+	realOut, realErr := os.Stdout, os.Stderr
+	os.Stdout, os.Stderr = w, ew
+	runErr := recheckOneHead("novox/x@abc", func(v any) error { return json.NewEncoder(os.Stdout).Encode(v) },
+		func() (string, error) {
+			fmt.Println("  the earlier checks' builds could not be read, so the check builds")
+			fmt.Fprintln(os.Stdout, "repaired a pointer")
+			return "check-42", nil
+		})
+	os.Stdout, os.Stderr = realOut, realErr
+	w.Close()
+	ew.Close()
+	if runErr != nil {
+		t.Fatal(runErr)
+	}
+	var out, errOut bytes.Buffer
+	_, _ = out.ReadFrom(r)
+	_, _ = errOut.ReadFrom(e)
+	var doc map[string]any
+	if err := json.Unmarshal(out.Bytes(), &doc); err != nil || doc["asked"] != "check-42" || doc["rechecked"] != "novox/x@abc" {
+		t.Fatalf("standard output %q is not the answer alone (%v)", out.String(), err)
+	}
+	if !strings.Contains(errOut.String(), "repaired a pointer") {
+		t.Fatalf("the prose should be on standard error: %q", errOut.String())
+	}
+}