cmd/coordinator: collapse duplicate execution headers

Following CL 371474, cmd/dist may include a "Test execution environment"
header which describes the test execution environment.

When sharding tests, we want to surface the proper execution environment
for each test, which may vary from shard to shard.

We could simply print the metadata for each shard in its output, as
shard results are printed in an atomic block. However, shards are pretty
small and that adds quite a bit of noise to logs.

Instead, treat the metadata block like the test header banners: as long
as the metadata doesn't change, we don't need to print it again.

On the other hand, if the metadata changes, we do print the test header
banner again. This isn't strictly necessary, it just serves to improve
readability by ensuring that tests are always immediately preceeded by
their banner rather than metadata (in the case that metadata changes in
the middle of a header block).

This CL should be submitted and deployed before CL 371474.

For golang/go#50146.

Change-Id: Ifca30f7f31237fd8cd0fcd801d198d9c341f695e
Reviewed-on: https://go-review.googlesource.com/c/build/+/372538
Trust: Michael Pratt <mpratt@google.com>
Run-TryBot: Michael Pratt <mpratt@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Alex Rakoczy <alex@golang.org>

cmd/coordinator/buildstatus.go

@@ -1496,6 +1496,7 @@ func (st *buildStatus) runTests(helpers <-chan buildlet.Client) (remoteErr, err
 		close(buildletsGone)
 	}()
 
+	var lastMetadata string
 	var lastHeader string
 	var serialDuration time.Duration
 	for _, ti := range set.items {
@@ -1516,9 +1517,24 @@ func (st *buildStatus) runTests(helpers <-chan buildlet.Client) (remoteErr, err
 
 		serialDuration += ti.execDuration
 		if len(ti.output) > 0 {
-			header, out := parseOutputAndHeader(ti.output)
+			metadata, header, out := parseOutputAndHeader(ti.output)
+			printHeader := false
+			if metadata != lastMetadata {
+				lastMetadata = metadata
+				fmt.Fprintf(st, "\n%s\n", metadata)
+				// Always include the test header after
+				// metadata changes. This is a readability
+				// optimization that ensures that tests are
+				// always immediately preceeded by their test
+				// banner, even if it is duplicate banner
+				// because the test metadata changed.
+				printHeader = true
+			}
 			if header != lastHeader {
 				lastHeader = header
+				printHeader = true
+			}
+			if printHeader {
 				fmt.Fprintf(st, "\n%s\n", header)
 			}
 			if pool.NewGCEConfiguration().InStaging() {
@@ -1551,31 +1567,63 @@ const (
 	banner       = "XXXBANNERXXX:" // flag passed to dist
 	bannerPrefix = "\n" + banner   // with the newline added by dist
 
+	metadataBannerPrefix = bannerPrefix + "Test execution environment."
+
 	outputBanner = "##### " // banner to display in output.
 )
 
-var bannerPrefixBytes = []byte(bannerPrefix)
+var (
+	bannerPrefixBytes         = []byte(bannerPrefix)
+	metadataBannerPrefixBytes = []byte(metadataBannerPrefix)
+)
 
-// parseOutputAndHeader parses b and returns the test display header (e.g.,
+// parseOutputAndHeader parses b and returns the test (optional) environment
-// "##### Testing packages.") and the following output.
+// metaadata, display header (e.g., "##### Testing packages.") and the
-func parseOutputAndHeader(b []byte) (header string, out []byte) {
+// following output.
+//
+// metadata is the optional execution environment metadata block. e.g.,
+//
+// ##### Test execution environment.
+// # GOARCH: amd64
+// # CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
+func parseOutputAndHeader(b []byte) (metadata, header string, out []byte) {
 	if !bytes.HasPrefix(b, bannerPrefixBytes) {
-		return "", b
+		return "", "", b
 	}
 
-	b = b[1:] // skip newline
+	if bytes.HasPrefix(b, metadataBannerPrefixBytes) {
+		// Header includes everything up to and including the next
+		// banner.
+		rem := b[len(metadataBannerPrefixBytes):]
+		i := bytes.Index(rem, bannerPrefixBytes)
+		if i == -1 {
+			// Metadata block without a following block doesn't
+			// make sense. Bail.
+			return "", "", b
+		}
+		bi := i + len(metadataBannerPrefixBytes)
+		// Metadata portion of header, skipping initial and trailing newlines.
+		metadata = strings.Trim(string(b[:bi]), "\n")
+		metadata = strings.Replace(metadata, banner, outputBanner, 1)
+		b = b[bi+1:] // skip newline at start of next banner.
+	} else {
+		b = b[1:] // skip newline
+	}
+
+	// Find end of primary test banner.
 	nl := bytes.IndexByte(b, '\n')
 	if nl == -1 {
+		// No newline, everything is header.
 		header = string(b)
 		b = nil
 	} else {
 		header = string(b[:nl])
 		b = b[nl+1:]
 	}
-	// Replace internal marker banner with the human-friendly
+
-	// version.
+	// Replace internal marker banner with the human-friendly version.
-	header = strings.ReplaceAll(header, banner, outputBanner)
+	header = strings.Replace(header, banner, outputBanner, 1)
-	return header, b
+	return metadata, header, b
 }
 
 // maxTestExecError is the number of test execution failures at which

cmd/coordinator/buildstatus_test.go

@@ -15,10 +15,11 @@ import (
 // TestParseOutputAndHeader tests header parsing by parseOutputAndHeader.
 func TestParseOutputAndHeader(t *testing.T) {
 	for _, tc := range []struct {
-		name       string
+		name         string
-		input      []byte
+		input        []byte
-		wantHeader string
+		wantMetadata string
-		wantOut    []byte
+		wantHeader   string
+		wantOut      []byte
 	}{
 		{
 			name: "standard",
@@ -28,7 +29,8 @@ ok	archive/tar	0.015s
 ok	archive/zip	0.406s
 ok	bufio	0.075s
 `),
-			wantHeader: "##### Testing packages.",
+			wantMetadata: "",
+			wantHeader:   "##### Testing packages.",
 			wantOut: []byte(`ok	archive/tar	0.015s
 ok	archive/zip	0.406s
 ok	bufio	0.075s
@@ -39,15 +41,17 @@ ok	bufio	0.075s
 			input: []byte(`
 XXXBANNERXXX:Testing packages.
 `),
-			wantHeader: "##### Testing packages.",
+			wantMetadata: "",
-			wantOut:    []byte(``),
+			wantHeader:   "##### Testing packages.",
+			wantOut:      []byte(``),
 		},
 		{
 			name: "header only missing trailing newline",
 			input: []byte(`
 XXXBANNERXXX:Testing packages.`),
-			wantHeader: "##### Testing packages.",
+			wantMetadata: "",
-			wantOut:    []byte(``),
+			wantHeader:   "##### Testing packages.",
+			wantOut:      []byte(``),
 		},
 		{
 			name: "no banner",
@@ -55,7 +59,8 @@ XXXBANNERXXX:Testing packages.`),
 ok	archive/zip	0.406s
 ok	bufio	0.075s
 `),
-			wantHeader: "",
+			wantMetadata: "",
+			wantHeader:   "",
 			wantOut: []byte(`ok	archive/tar	0.015s
 ok	archive/zip	0.406s
 ok	bufio	0.075s
@@ -68,7 +73,8 @@ ok	archive/tar	0.015s
 ok	archive/zip	0.406s
 ok	bufio	0.075s
 `),
-			wantHeader: "",
+			wantMetadata: "",
+			wantHeader:   "",
 			wantOut: []byte(`XXXBANNERXXX:Testing packages.
 ok	archive/tar	0.015s
 ok	archive/zip	0.406s
@@ -83,7 +89,8 @@ ok	archive/tar	0.015s
 ok	archive/zip	0.406s
 ok	bufio	0.075s
 `),
-			wantHeader: "",
+			wantMetadata: "",
+			wantHeader:   "",
 			wantOut: []byte(`
 ##### Testing packages.
 ok	archive/tar	0.015s
@@ -91,11 +98,99 @@ ok	archive/zip	0.406s
 ok	bufio	0.075s
 `),
 		},
+		{
+			name: "metadata",
+			input: []byte(`
+XXXBANNERXXX:Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
+
+XXXBANNERXXX:Testing packages.
+ok	archive/tar	0.015s
+ok	archive/zip	0.406s
+ok	bufio	0.075s
+`),
+			wantMetadata: `##### Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz`,
+			wantHeader: "##### Testing packages.",
+			wantOut: []byte(`ok	archive/tar	0.015s
+ok	archive/zip	0.406s
+ok	bufio	0.075s
+`),
+		},
+		{
+			name: "metadata missing separator newline",
+			input: []byte(`
+XXXBANNERXXX:Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
+XXXBANNERXXX:Testing packages.
+ok	archive/tar	0.015s
+ok	archive/zip	0.406s
+ok	bufio	0.075s
+`),
+			wantMetadata: `##### Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz`,
+			wantHeader: "##### Testing packages.",
+			wantOut: []byte(`ok	archive/tar	0.015s
+ok	archive/zip	0.406s
+ok	bufio	0.075s
+`),
+		},
+		{
+			name: "metadata missing second banner",
+			input: []byte(`
+XXXBANNERXXX:Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
+`),
+			wantMetadata: "",
+			wantHeader:   "",
+			wantOut: []byte(`
+XXXBANNERXXX:Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
+`),
+		},
+		{
+			name: "metadata missing body",
+			input: []byte(`
+XXXBANNERXXX:Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
+
+XXXBANNERXXX:Testing packages.
+`),
+			wantMetadata: `##### Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz`,
+			wantHeader: "##### Testing packages.",
+			wantOut:    []byte(``),
+		},
+		{
+			name: "metadata missing body and newline",
+			input: []byte(`
+XXXBANNERXXX:Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
+
+XXXBANNERXXX:Testing packages.`),
+			wantMetadata: `##### Test execution environment.
+# GOARCH: amd64
+# CPU: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz`,
+			wantHeader: "##### Testing packages.",
+			wantOut:    []byte(``),
+		},
 	} {
 		t.Run(tc.name, func(t *testing.T) {
-			gotHeader, gotOut := parseOutputAndHeader(tc.input)
+			gotMetadata, gotHeader, gotOut := parseOutputAndHeader(tc.input)
+			if gotMetadata != tc.wantMetadata {
+				t.Errorf("parseOutputAndBanner(%q) got metadata %q want metadata %q", string(tc.input), gotMetadata, tc.wantMetadata)
+			}
 			if gotHeader != tc.wantHeader {
-				t.Errorf("parseOutputAndBanner(%q) got banner %q want banner %q", string(tc.input), gotHeader, tc.wantHeader)
+				t.Errorf("parseOutputAndBanner(%q) got header %q want header %q", string(tc.input), gotHeader, tc.wantHeader)
 			}
 			if string(gotOut) != string(tc.wantOut) {
 				t.Errorf("parseOutputAndBanner(%q) got out %q want out %q", string(tc.input), string(gotOut), string(tc.wantOut))