From 155124b59af47b7bbe0418a586c5e0053697d7e7 Mon Sep 17 00:00:00 2001
From: jochen <jschoubben@gmail.com>
Date: Sun, 25 Oct 2026 15:58:07 +0100
Subject: [PATCH] mesh-build-go: a cause is the runtime's line at column 0, and
 only go's exact summary lines are dropped (issue 1901, review round 1)

An indented log line of another running test that held 'panic:' won over the
real timeout panic, since the lines were trimmed before matching. Go prints
the runtime's lines at column 0; a test's log is indented.
---
 .../mesh-build-go/cmd/mesh-build-go/levels.go | 14 +++++++-----
 .../cmd/mesh-build-go/package_cause_test.go   | 22 +++++++++++++++++++
 2 files changed, 30 insertions(+), 6 deletions(-)

diff --git a/modules/mesh-build-go/cmd/mesh-build-go/levels.go b/modules/mesh-build-go/cmd/mesh-build-go/levels.go
index 27d38434..ea5bc596 100644
--- a/modules/mesh-build-go/cmd/mesh-build-go/levels.go
+++ b/modules/mesh-build-go/cmd/mesh-build-go/levels.go
@@ -192,7 +192,7 @@ func (r *reader) event(ev event) {
 		case "output":
 			// go test's own summary of a package ("PASS", "FAIL", "ok <pkg>", "FAIL <pkg>") is never a failure's
 			// words: a "PASS" before a "FAIL <pkg>" says only that the tests passed and the program failed after them.
-			switch l := strings.TrimSpace(ev.Output); {
+			switch l := strings.TrimRight(ev.Output, "\r\n"); {
 			case l == "PASS":
 				r.passed[ev.Package] = true
 			case summaryLine(l):
@@ -275,22 +275,24 @@ func clip(lines []string, cause string) string {
 	return strings.Join(kept, "\n")
 }
 
-// summaryLine says a line is go test's summary of a package: "PASS", "FAIL", "ok <pkg> <time>", "FAIL <pkg> <time>".
+// summaryLine says a line is go test's summary of a package, in go's exact forms only: "PASS" or "FAIL" alone,
+// "ok  \t<pkg>\t<time>" and "FAIL\t<pkg>\t<time>" (review round 1: a line of the package's own that starts "ok " is kept).
 func summaryLine(l string) bool {
-	return l == "PASS" || l == "FAIL" || strings.HasPrefix(l, "ok ") || strings.HasPrefix(l, "ok\t") || strings.HasPrefix(l, "FAIL\t") || strings.HasPrefix(l, "FAIL ")
+	return l == "PASS" || l == "FAIL" || strings.HasPrefix(l, "ok  \t") || strings.HasPrefix(l, "FAIL\t")
 }
 
 // causeOf is the cause in a failure's output that is not a test's assertion (issue 1901): a race the race detector
 // reported (raceCause); else the first "panic:" line, a timeout's with the tests it names as running; else the first
 // "fatal error:" (the runtime's) or "signal:" line (a test program killed); "" when there is none. It reads every line,
-// so a long goroutine dump after the panic cannot hide it.
+// so a long goroutine dump after the panic cannot hide it. **It matches only lines at column 0**, where go prints the
+// runtime's: a test's indented log line holding the same words is not the cause (review round 1).
 func causeOf(lines []string) string {
 	if race := raceCause(lines); race != "" {
 		return race
 	}
 	for _, prefix := range []string{"panic: ", "fatal error: ", "signal: "} {
 		for i, l := range lines {
-			l = strings.TrimSpace(l)
+			l = strings.TrimRight(l, "\r\n") // at column 0: an indented line is a test's own log, not the runtime's
 			if !strings.HasPrefix(l, prefix) {
 				continue
 			}
@@ -322,7 +324,7 @@ func causeOf(lines []string) string {
 func raceCause(lines []string) string {
 	at := -1
 	for i, l := range lines {
-		if strings.TrimSpace(l) == "WARNING: DATA RACE" {
+		if strings.TrimRight(l, "\r\n") == "WARNING: DATA RACE" { // at column 0, as causeOf
 			at = i
 			break
 		}
diff --git a/modules/mesh-build-go/cmd/mesh-build-go/package_cause_test.go b/modules/mesh-build-go/cmd/mesh-build-go/package_cause_test.go
index 8ba71687..cf002bbe 100644
--- a/modules/mesh-build-go/cmd/mesh-build-go/package_cause_test.go
+++ b/modules/mesh-build-go/cmd/mesh-build-go/package_cause_test.go
@@ -79,3 +79,25 @@ func TestAnAssertionKeepsItsOwnCause(t *testing.T) { // 1901/AC4
 		t.Errorf("1901/AC4: failures = %+v", res.Failed)
 	}
 }
+
+// go prints the runtime's lines ("panic:", "fatal error:", "signal:", "WARNING: DATA RACE") at column 0: a test's own
+// log line that holds the same words is indented, and is not the cause (review round 1). The fixture is the deeptimeout
+// capture with two log lines of the first running test added: a t.Logf and its indented continuation saying "panic:".
+func TestALoggedPanicIsNotTheCause(t *testing.T) { // 1901/AC4
+	raw, err := os.ReadFile("testdata/captured/go-test-json-pkg-deeptimeout.jsonl")
+	if err != nil {
+		t.Fatal(err)
+	}
+	lines := strings.SplitAfter(string(raw), "\n")
+	added := `{"Action":"output","Package":"example.com/deeptimeout","Test":"TestHoldsTheSeat","Output":"    p_test.go:9: the child said:\n"}` + "\n" +
+		`{"Action":"output","Package":"example.com/deeptimeout","Test":"TestHoldsTheSeat","Output":"        panic: child retried and recovered\n"}` + "\n" +
+		`{"Action":"output","Package":"example.com/deeptimeout","Test":"TestHoldsTheSeat","Output":"        WARNING: DATA RACE\n"}` + "\n"
+	out := strings.Join(lines[:10], "") + added + strings.Join(lines[10:], "")
+	res := &TestResult{}
+	rd := newReader(res, ".")
+	rd.read(out)
+	rd.finish()
+	if len(res.Failed) != 1 || !strings.HasPrefix(res.Failed[0].Cause, "panic: test timed out after 2s") {
+		t.Errorf("1901/AC4: failures = %+v, want the timeout's panic as the cause", res.Failed)
+	}
+}