mesh-delivery-checker: a failure's words are never "PASS"; with no cause, take the panic line (issue 1901)

A try of mesh-controller's status read 'cmd/mesh-controller: PASS': the build
module sent a package failure whose output began with go test's PASS. The
checker now drops go test's summary lines, takes the first panic, fatal error
or signal line as the cause when the build module told none apart (read before
the words are cut), says the tests passed and the program failed after them
when nothing else is left, and cuts a cause to 1 KB so the words keep their
bound (1901/AC5).

modules/mesh-delivery-checker/internal/check/judge.go

@@ -531,23 +531,71 @@ const MaxWords = 4096
 
 // failureWords is a failure's words: its output's last lines up to MaxWords, with the line the build module told apart as
 // the test's error first when the output does not start with it, so the first line of the words is the cause and the
-// status line, which is cut short, names it.
+// status line, which is cut short, names it. **A failure's words are never "PASS" or "ok"** (issue 1901, its third
+// meeting: a package that failed after its tests passed was worded "PASS"): go test's summary lines are dropped, and with
+// no cause told apart (an older build module) the cause is the output's first "panic:", "fatal error:" or "signal:"
+// line, read before the output is cut, or the words say the tests passed and the program failed after them.
 func failureWords(f Failure) string {
-	out := strings.TrimSpace(f.Output)
+	out, passed := dropSummary(strings.TrimSpace(f.Output))
-	if len(out) > MaxWords {
+	cause := strings.TrimSpace(f.Cause)
-		out = out[len(out)-MaxWords:]
+	if cause == "" {
+		cause = causeIn(out)
+	}
+	if cause == "" && out == "" && passed {
+		cause = "the tests passed, then the test program exited with a failure: an os.Exit or a panic in TestMain or after the tests"
+	}
+	if len(cause) > MaxCause {
+		cause = strings.ToValidUTF8(cause[:MaxCause], "") + "..."
+	}
+	if len(out) > MaxWords-len(cause) {
+		out = out[len(out)-(MaxWords-len(cause)):]
 		// Start on a whole line, and a whole character.
 		if i := strings.IndexByte(out, '\n'); i >= 0 {
 			out = "... " + strings.TrimLeft(out[i:], "\n")
 		}
 		out = strings.ToValidUTF8(out, "")
 	}
-	if c := strings.TrimSpace(f.Cause); c != "" && !strings.HasPrefix(firstLine(out), c) {
+	if cause != "" && !strings.HasPrefix(firstLine(out), cause) {
-		out = c + "\n" + out
+		out = strings.TrimRight(cause+"\n"+out, "\n")
 	}
 	return out
 }
 
+// MaxCause is the most a cause in a failure's words holds: one long line (the 1901 review: a cause of a kilobyte could
+// push the words past MaxWords).
+const MaxCause = 1024
+
+// dropSummary drops go test's summary lines from a failure's output ("PASS", "FAIL", "ok <pkg>", "FAIL <pkg>"), and says
+// whether a "PASS" was among them: the package's tests passed before it failed.
+func dropSummary(out string) (string, bool) {
+	passed := false
+	lines := strings.Split(out, "\n")
+	kept := lines[:0]
+	for _, l := range lines {
+		switch t := strings.TrimSpace(l); {
+		case t == "PASS":
+			passed = true
+		case t == "FAIL", strings.HasPrefix(t, "ok "), strings.HasPrefix(t, "ok\t"), strings.HasPrefix(t, "FAIL\t"), strings.HasPrefix(t, "FAIL "):
+		default:
+			kept = append(kept, l)
+		}
+	}
+	return strings.TrimSpace(strings.Join(kept, "\n")), passed
+}
+
+// causeIn is the first "panic:", "fatal error:" or "signal:" line of a failure's output, in that order, or "".
+func causeIn(out string) string {
+	lines := strings.Split(out, "\n")
+	for _, prefix := range []string{"panic: ", "fatal error: ", "signal: "} {
+		for _, l := range lines {
+			if l = strings.TrimSpace(l); strings.HasPrefix(l, prefix) {
+				return l
+			}
+		}
+	}
+	return ""
+}
+
 // firstLine is the first non-empty line of a failure's words.
 func firstLine(s string) string {
 	for _, l := range strings.Split(s, "\n") {

modules/mesh-delivery-checker/internal/check/package_cause_test.go

@@ -0,0 +1,55 @@
+package check
+
+import (
+	"strings"
+	"testing"
+)
+
+// What the build module before this fix sent for two packages that failed after their tests passed (issue 1901, its third
+// meeting: a try of mesh-controller kept "PASS" as its failure's words). Each is that build module's Output for the real
+// `go test -json` of a throwaway package (mesh-catalog modules/mesh-build-go testdata/captured/go-test-json-pkg-*.jsonl):
+// TestMain panicking in a goroutine after m.Run, and TestMain exiting 2 after m.Run.
+const (
+	oldPassThenPanic = "PASS\npanic: the bus closed after the tests: nats: connection closed\ngoroutine 20 [running]:\n" +
+		"example.com/passthenfail.TestMain.func1()\n\t/tmp/fix-1901b/passthenfail/p_test.go:13 +0x25\n" +
+		"created by example.com/passthenfail.TestMain in goroutine 1\n\t/tmp/fix-1901b/passthenfail/p_test.go:13 +0x25\n" +
+		"FAIL\texample.com/passthenfail\t0.005s"
+	oldPassThenExit = "PASS\nFAIL\texample.com/mainexit\t0.004s"
+)
+
+// A failure with no cause told apart never has "PASS" or "ok" as its words: the checker takes the panic line from the
+// output, or says that the tests passed and the program failed after them (1901/AC5).
+func TestAPackageFailureIsNeverWordedPass(t *testing.T) { // 1901/AC5
+	cases := []struct {
+		name, output, want string
+	}{
+		{"panic after the tests", oldPassThenPanic, "panic: the bus closed after the tests: nats: connection closed"},
+		{"exit after the tests", oldPassThenExit, "the tests passed, then the test program exited with a failure"},
+		{"a panic deep in a long output", "PASS\npanic: the seat row vanished\n" + strings.Repeat("goroutine 7 [chan receive]:\n\tsome/frame.go:1 +0x1\n", 300) + "FAIL\tp\t2.0s", "panic: the seat row vanished"},
+	}
+	for _, c := range cases {
+		t.Run(c.name, func(t *testing.T) {
+			v := levelFailure(&target{}, "integration", Tested{Failed: []Failure{{Package: "github.com/novox/mesh-controller/cmd/mesh-controller", Output: c.output}}})
+			for _, l := range strings.Split(v.Failed.Words, "\n") {
+				if l = strings.TrimSpace(l); l == "PASS" || strings.HasPrefix(l, "ok ") || strings.HasPrefix(l, "ok\t") {
+					t.Errorf("1901/AC5: the words keep %q: %q", l, v.Failed.Words)
+				}
+			}
+			if !strings.HasPrefix(v.Failed.Words, c.want) {
+				t.Errorf("1901/AC5: words start %q, want %q", firstLine(v.Failed.Words), c.want)
+			}
+			if got := firstFailed(*v); !strings.Contains(got, c.want) || strings.HasSuffix(got, ": PASS") {
+				t.Errorf("1901/AC5: status = %q", got)
+			}
+		})
+	}
+}
+
+// A cause the build module told apart is cut to a line's bound, so the words keep their bound (the 1901 review's note).
+func TestALongCauseIsCutToALinesBound(t *testing.T) { // 1901/AC5
+	f := Failure{Package: "p", Test: "TestX", Cause: strings.Repeat("c", 5000), Output: "x_test.go:1: something"}
+	v := levelFailure(&target{}, "unit", Tested{Failed: []Failure{f}})
+	if len(v.Failed.Words) > MaxWords+200 {
+		t.Errorf("1901/AC5: words are %d bytes, bound %d", len(v.Failed.Words), MaxWords)
+	}
+}